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

[v32.0-alpha] answering quests sometimes really slow #2803

Closed
Helium314 opened this issue Apr 26, 2021 · 89 comments
Closed

[v32.0-alpha] answering quests sometimes really slow #2803

Helium314 opened this issue Apr 26, 2021 · 89 comments
Assignees
Labels

Comments

@Helium314
Copy link
Collaborator

After downloading a large area containing many quests, answering some quests takes very long (in my case this was done automatically after first app start, but also happens when zooming out and starting a manual scan). Especially for building or crossing quests, on my S4 Mini it takes some 30 seconds to for the pin to be removed. In this time I can't open any other quests, SC usage is basically blocked (panning/zooming the map is still possible without noticable slowdowns).
Other quests like opening hours do not have this problem.
Interestingly, answering quests near the southern edge of the scanned area is much faster than in other regions.

When "leaving" this area, i.e. scrolling somewhere far away, manually scanning and answering quests is fast (less than a second). The southern edge of the new area might be a little bit faster, not sure.

Sometimes after doing stuff "somewhere else", anwering quests inside the initial scan area is faster (maybe 10 seconds instead of 30 for the same element), but still slower than outside. I haven't yet found a way of reproducing this.

@Helium314 Helium314 added the bug label Apr 26, 2021
@Helium314 Helium314 changed the title [v32.0-alpha] answering sometimes really slow [v32.0-alpha] answering quests sometimes really slow Apr 26, 2021
@westnordost
Copy link
Member

Can you show the log?

@Helium314
Copy link
Collaborator Author

Helium314 commented Apr 26, 2021

Answered crossing type (slow), opening hours (fast), building type (slow)

OsmQuestController: Created AddWheelchairAccessBusiness for NODE#8118300817
OsmQuestController: Created 1 quests for 1 updated elements in 0.1s
OsmQuestController: Persisted 1 new and removed 1 already resolved quests in 0.0s
QuestController: Solved a AddBuildingType quest: MODIFY "building"="yes" -> "building"="detached"
OsmQuestController: AddHousenumber requires surrounding map data to determine applicability to WAY#846977295
CursorWindow: Window is full: requested allocation 60 bytes, free space 55 bytes, window size 2097152 bytes
CursorWindow: Window is full: requested allocation 60 bytes, free space 35 bytes, window size 2097152 bytes
CursorWindow: Window is full: requested allocation 60 bytes, free space 3 bytes, window size 2097152 bytes
CursorWindow: Window is full: requested allocation 60 bytes, free space 31 bytes, window size 2097152 bytes
CursorWindow: Window is full: requested allocation 4 bytes, free space 0 bytes, window size 2097152 bytes
CursorWindow: Window is full: requested allocation 1 bytes, free space 0 bytes, window size 2097152 bytes
CursorWindow: Window is full: requested allocation 1 bytes, free space 0 bytes, window size 2097152 bytes
CursorWindow: Window is full: requested allocation 60 bytes, free space 39 bytes, window size 2097152 bytes
MapDataController: Fetched 111 elements and geometries in 41204ms
OsmQuestController: Created AddHousenumber for WAY#846977295
OsmQuestController: Created AddBuildingLevels for WAY#846977295
OsmQuestController: Created 2 quests for 1 updated elements in 41.3s
OsmQuestController: Persisted 2 new and removed 1 already resolved quests in 0.0s

@westnordost
Copy link
Member

I took the liberty to edit that log to only show the relevant parts. The most relevant parts are:

AddHousenumber requires surrounding map data to determine applicability to WAY#846977295
Fetched 111 elements and geometries in 41204ms

So, disclaimer: v32.0 is more slow and more demanding on resources. Because this is what happens:

  1. Whenever you solve a quest, it results in an edit being created.
  2. Whenever an edit is created, the edit is applied to the local data set and thus all elements related to that edit are updated
  3. Whenever an element is updated, it is checked if it is now applicable for the quest for each quest type. Usually questType.isApplicableTo(element) is called, which is reasonably fast. However, whenever that method returns null, it means that information about the surrounding elements are necessary to answer that. So what the app then does is to fetch the surrounding area (20m or so around the element) from the database and then check if the updated element is amongst those returned by questType.getApplicableElements(mapData).

The reason why it is fast for AddWheelchairAccessBusiness is because no quest returned null on questType.isApplicableTo(element) but all either true or false. In this case, all returned false except for one quest.

For AddBuildingType, the AddHousenumber quest returned null for that method because it needs information about surrounding geometry. As you see in the log, 111 elements and geometries where fetched from database. On my device, this lookup takes about 100ms. This is already long and I wondered about why it takes so long. 40000ms is outrageous for 111 elements.

The main reason that it takes long for your device seem to be some memory constraints regarding the CursorWindow. I will look into what that means next.

@westnordost
Copy link
Member

westnordost commented Apr 26, 2021

The map data geometry is fetched from the database using a bounding box. There is no index on the min latitude, min longitude, max latitude and max longitude of each geometry in the element geometry table because I am not sure if an index would help on a select statement like SELECT * FROM table WHERE xmin >= 0.1 AND xmax <= 0.2 AND ymin >= 0.1 AND ymax <= 0.2, so I did a test.

I created a little kotlin script that outputs a test.sql that creates a table with entries that also have a "bounding box":

fun main() {

    File("test.sql").printWriter().use { out ->
        out.println("BEGIN TRANSACTION;")
        out.println("""
            CREATE TABLE "test" (
            	"i"	INTEGER NOT NULL,
            	"xmin"	NUMERIC NOT NULL,
            	"ymin"	NUMERIC NOT NULL,
            	"xmax"	NUMERIC NOT NULL,
            	"ymax"	NUMERIC NOT NULL,
            	PRIMARY KEY("i" AUTOINCREMENT)
            );
        """.trimIndent())
        for(i in 0..500000) {
            out.println("INSERT INTO test (xmin,ymin,xmax,ymax) values (${Random.nextDouble()},${Random.nextDouble()},${Random.nextDouble()},${Random.nextDouble()});")
        }
        out.println("COMMIT TRANSACTION;")
    }
}

On my computer, doing a query on a database created from that test.sql file like

SELECT * FROM test WHERE xmin >= 0.1 AND xmax <= 0.2 AND ymin >= 0.1 AND ymax <= 0.2

takes about 100ms. If I add an index like this

CREATE INDEX minmax on test (xmin, xmax, ymin, ymax)

it takes about 50ms. So, an index in SQLite also works with >= etc operators. That's good, so I will add an index.

However, this is likely not the main problem, the main problem seem to be some contraints on the cursor window. Will look into that next.

@Helium314
Copy link
Collaborator Author

Helium314 commented Apr 26, 2021

Thanks for the explanation.

What I wonder: why is this lookup much faster

  • at the southern edge of the map downloaded area (it's definitely not related to the number of nearby elements)
  • when the edit is within a small downloaded area (go somewhere far away, go to max zoom, scan)

@westnordost
Copy link
Member

Maybe the fetching from DB (=creating of the objects) itself is somehow hugely inefficient

@westnordost
Copy link
Member

I pushed the creations of the indexes to master. I'd be interested to know how much this speeds this up for you. (You need to uninstall and reinstall the app.) If possible, it would be great if you used the the exact same element for the test.

@westnordost
Copy link
Member

Did a random test myself. The times are still really slow:

Fetched 241 geometries in 216ms
Fetched 206 nodes in 125ms
Fetched 22 ways in 92ms
Fetched 13 relations in 205ms

@westnordost
Copy link
Member

Did some more detailed performance measuring (after indexing applied) at that location. Of the total time spent:

  • 17% on waiting for the SQL queries to complete
  • 27% solely on deserializing the element tags using Kryo
  • 56% on iterating the SQL result cursor and instantiating the objects

So, SQL efficiency is not really the problem. Or if it is, it's in the iterating the SQL cursor, which can't be made any faster. Most time (83%) is spent in application code: instantiating the data. Of these a third alone is spent on deserializing the element tags.

Since the data classes will be exchanged with pure kotlin ones and the serialization library is exchanged with kotlinx-serialization which is not based on Java Reflection but on the other hand serializes to a less compact format (JSON), the measurements may be different on that branch. Will take another measurement on that branch.

@Helium314
Copy link
Collaborator Author

Here is a log with the latest change:
started the app after re-install, downloaded quests, answered the same 2 quests as before (I think), answer a building type quest near the south edge of downloaded area, download a different dense area, answer building type quest there (the problem is clearly not (only) the number of nearby elements

Log
04-26 15:13:04.886 12261 12261 I plete.test32ne: IncrementDisableThreadFlip blocked for 8.637ms
04-26 15:13:04.887 12261 12284 I plete.test32ne: IncrementDisableThreadFlip blocked for 14.954ms
04-26 15:13:04.941 12261 12261 I TwilightManager: Could not get last known location. This is probably because the app does not have any location permissions. Falling back to hardcoded sunrise/sunset values.
04-26 15:13:04.951 12261 12261 I TwilightManager: Could not get last known location. This is probably because the app does not have any location permissions. Falling back to hardcoded sunrise/sunset values.
04-26 15:13:05.059 12261 12272 I plete.test32ne: Background concurrent copying GC freed 2359(328KB) AllocSpace objects, 0(0B) LOS objects, 24% free, 5MB/7MB, paused 8.179ms total 212.574ms
04-26 15:13:05.308 12261 12261 I plete.test32ne: Rejecting re-init on previously-failed class java.lang.Class<de.westnordost.streetcomplete.view.insets_animation.ImeInsetsAnimationCallback>: java.lang.NoClassDefFoundError: Failed resolution of: Landroid/view/WindowInsetsAnimation$Callback;
04-26 15:13:05.308 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.view.insets_animation.ImeInsetsAnimationCallbackKt.respectSystemInsets(android.view.View, kotlin.jvm.functions.Function5) (ImeInsetsAnimationCallback.kt:-1)
04-26 15:13:05.308 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.map.MapFragment.onViewCreated(android.view.View, android.os.Bundle) (MapFragment.kt:118)
04-26 15:13:05.308 12261 12261 I plete.test32ne:   at void androidx.fragment.app.Fragment.performViewCreated() (Fragment.java:2987)
04-26 15:13:05.308 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.ensureInflatedView() (FragmentStateManager.java:392)
04-26 15:13:05.308 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.moveToExpectedState() (FragmentStateManager.java:281)
04-26 15:13:05.308 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentLayoutInflaterFactory.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentLayoutInflaterFactory.java:140)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater$FactoryMerger.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:186)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:772)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:730)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflate(org.xmlpull.v1.XmlPullParser, android.view.View, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:863)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflateChildren(org.xmlpull.v1.XmlPullParser, android.view.View, android.util.AttributeSet, boolean) (LayoutInflater.java:824)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(org.xmlpull.v1.XmlPullParser, android.view.ViewGroup, boolean) (LayoutInflater.java:515)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup, boolean) (LayoutInflater.java:423)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.Fragment.onCreateView(android.view.LayoutInflater, android.view.ViewGroup, android.os.Bundle) (Fragment.java:1924)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void androidx.fragment.app.Fragment.performCreateView(android.view.LayoutInflater, android.view.ViewGroup, android.os.Bundle) (Fragment.java:2963)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.ensureInflatedView() (FragmentStateManager.java:386)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.moveToExpectedState() (FragmentStateManager.java:281)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentLayoutInflaterFactory.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentLayoutInflaterFactory.java:140)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentController.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentController.java:135)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentActivity.dispatchFragmentsOnCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentActivity.java:319)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentActivity.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentActivity.java:298)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:780)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:730)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflate(org.xmlpull.v1.XmlPullParser, android.view.View, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:863)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflateChildren(org.xmlpull.v1.XmlPullParser, android.view.View, android.util.AttributeSet, boolean) (LayoutInflater.java:824)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(org.xmlpull.v1.XmlPullParser, android.view.ViewGroup, boolean) (LayoutInflater.java:515)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup, boolean) (LayoutInflater.java:423)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup) (LayoutInflater.java:374)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void androidx.appcompat.app.AppCompatDelegateImpl.setContentView(int) (AppCompatDelegateImpl.java:696)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void androidx.appcompat.app.AppCompatActivity.setContentView(int) (AppCompatActivity.java:170)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:100)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.app.Activity.performCreate(android.os.Bundle, android.os.PersistableBundle) (Activity.java:7144)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.app.Activity.performCreate(android.os.Bundle) (Activity.java:7135)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.app.Instrumentation.callActivityOnCreate(android.app.Activity, android.os.Bundle) (Instrumentation.java:1271)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.app.Activity android.app.ActivityThread.performLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.content.Intent) (ActivityThread.java:2931)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.app.Activity android.app.ActivityThread.handleLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.app.servertransaction.PendingTransactionActions, android.content.Intent) (ActivityThread.java:3086)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.app.servertransaction.LaunchActivityItem.execute(android.app.ClientTransactionHandler, android.os.IBinder, android.app.servertransaction.PendingTransactionActions) (LaunchActivityItem.java:78)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.app.servertransaction.TransactionExecutor.executeCallbacks(android.app.servertransaction.ClientTransaction) (TransactionExecutor.java:108)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.app.servertransaction.TransactionExecutor.execute(android.app.servertransaction.ClientTransaction) (TransactionExecutor.java:68)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.app.ActivityThread$H.handleMessage(android.os.Message) (ActivityThread.java:1816)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.os.Handler.dispatchMessage(android.os.Message) (Handler.java:106)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.os.Looper.loop() (Looper.java:193)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void android.app.ActivityThread.main(java.lang.String[]) (ActivityThread.java:6718)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at java.lang.Object java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object[]) (Method.java:-2)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run() (RuntimeInit.java:491)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void com.android.internal.os.ZygoteInit.main(java.lang.String[]) (ZygoteInit.java:858)
04-26 15:13:05.309 12261 12261 I plete.test32ne: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.WindowInsetsAnimation$Callback" on path: DexPathList[[zip file "/data/app/de.westnordost.streetcomplete.test32new-UcMpaVyG7HYnwh97O54_uA==/base.apk"],nativeLibraryDirectories=[/data/app/de.westnordost.streetcomplete.test32new-UcMpaVyG7HYnwh97O54_uA==/lib/arm, /data/app/de.westnordost.streetcomplete.test32new-UcMpaVyG7HYnwh97O54_uA==/base.apk!/lib/armeabi-v7a, /system/lib, /system/vendor/lib]]
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at java.lang.Class dalvik.system.BaseDexClassLoader.findClass(java.lang.String) (BaseDexClassLoader.java:134)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at java.lang.Class java.lang.ClassLoader.loadClass(java.lang.String, boolean) (ClassLoader.java:379)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at java.lang.Class java.lang.ClassLoader.loadClass(java.lang.String) (ClassLoader.java:312)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.view.insets_animation.ImeInsetsAnimationCallbackKt.respectSystemInsets(android.view.View, kotlin.jvm.functions.Function5) (ImeInsetsAnimationCallback.kt:-1)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.map.MapFragment.onViewCreated(android.view.View, android.os.Bundle) (MapFragment.kt:118)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void androidx.fragment.app.Fragment.performViewCreated() (Fragment.java:2987)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.ensureInflatedView() (FragmentStateManager.java:392)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.moveToExpectedState() (FragmentStateManager.java:281)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentLayoutInflaterFactory.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentLayoutInflaterFactory.java:140)
04-26 15:13:05.309 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater$FactoryMerger.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:186)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:772)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:730)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflate(org.xmlpull.v1.XmlPullParser, android.view.View, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:863)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflateChildren(org.xmlpull.v1.XmlPullParser, android.view.View, android.util.AttributeSet, boolean) (LayoutInflater.java:824)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(org.xmlpull.v1.XmlPullParser, android.view.ViewGroup, boolean) (LayoutInflater.java:515)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup, boolean) (LayoutInflater.java:423)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.Fragment.onCreateView(android.view.LayoutInflater, android.view.ViewGroup, android.os.Bundle) (Fragment.java:1924)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void androidx.fragment.app.Fragment.performCreateView(android.view.LayoutInflater, android.view.ViewGroup, android.os.Bundle) (Fragment.java:2963)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.ensureInflatedView() (FragmentStateManager.java:386)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.moveToExpectedState() (FragmentStateManager.java:281)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentLayoutInflaterFactory.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentLayoutInflaterFactory.java:140)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentController.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentController.java:135)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentActivity.dispatchFragmentsOnCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentActivity.java:319)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentActivity.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentActivity.java:298)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:780)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:730)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflate(org.xmlpull.v1.XmlPullParser, android.view.View, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:863)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflateChildren(org.xmlpull.v1.XmlPullParser, android.view.View, android.util.AttributeSet, boolean) (LayoutInflater.java:824)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(org.xmlpull.v1.XmlPullParser, android.view.ViewGroup, boolean) (LayoutInflater.java:515)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup, boolean) (LayoutInflater.java:423)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup) (LayoutInflater.java:374)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void androidx.appcompat.app.AppCompatDelegateImpl.setContentView(int) (AppCompatDelegateImpl.java:696)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void androidx.appcompat.app.AppCompatActivity.setContentView(int) (AppCompatActivity.java:170)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:100)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.app.Activity.performCreate(android.os.Bundle, android.os.PersistableBundle) (Activity.java:7144)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.app.Activity.performCreate(android.os.Bundle) (Activity.java:7135)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.app.Activity android.app.ActivityThread.performLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.content.Intent) (ActivityThread.java:2931)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at android.app.Activity android.app.ActivityThread.handleLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.app.servertransaction.PendingTransactionActions, android.content.Intent) (ActivityThread.java:3086)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.app.servertransaction.LaunchActivityItem.execute(android.app.ClientTransactionHandler, android.os.IBinder, android.app.servertransaction.PendingTransactionActions) (LaunchActivityItem.java:78)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.app.servertransaction.TransactionExecutor.executeCallbacks(android.app.servertransaction.ClientTransaction) (TransactionExecutor.java:108)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.app.servertransaction.TransactionExecutor.execute(android.app.servertransaction.ClientTransaction) (TransactionExecutor.java:68)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.app.ActivityThread$H.handleMessage(android.os.Message) (ActivityThread.java:1816)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.os.Handler.dispatchMessage(android.os.Message) (Handler.java:106)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.os.Looper.loop() (Looper.java:193)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void android.app.ActivityThread.main(java.lang.String[]) (ActivityThread.java:6718)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at java.lang.Object java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object[]) (Method.java:-2)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run() (RuntimeInit.java:491)
04-26 15:13:05.310 12261 12261 I plete.test32ne:   at void com.android.internal.os.ZygoteInit.main(java.lang.String[]) (ZygoteInit.java:858)
04-26 15:13:05.310 12261 12261 I plete.test32ne: 
04-26 15:13:05.312 12261 12261 I plete.test32ne: Rejecting re-init on previously-failed class java.lang.Class<de.westnordost.streetcomplete.view.insets_animation.ImeInsetsAnimationCallback>: java.lang.NoClassDefFoundError: Failed resolution of: Landroid/view/WindowInsetsAnimation$Callback;
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.view.insets_animation.ImeInsetsAnimationCallbackKt.respectSystemInsets(android.view.View, kotlin.jvm.functions.Function5) (ImeInsetsAnimationCallback.kt:-1)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.map.MapFragment.onViewCreated(android.view.View, android.os.Bundle) (MapFragment.kt:118)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void androidx.fragment.app.Fragment.performViewCreated() (Fragment.java:2987)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.ensureInflatedView() (FragmentStateManager.java:392)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.moveToExpectedState() (FragmentStateManager.java:281)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentLayoutInflaterFactory.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentLayoutInflaterFactory.java:140)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater$FactoryMerger.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:186)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:772)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:730)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflate(org.xmlpull.v1.XmlPullParser, android.view.View, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:863)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflateChildren(org.xmlpull.v1.XmlPullParser, android.view.View, android.util.AttributeSet, boolean) (LayoutInflater.java:824)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(org.xmlpull.v1.XmlPullParser, android.view.ViewGroup, boolean) (LayoutInflater.java:515)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup, boolean) (LayoutInflater.java:423)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.Fragment.onCreateView(android.view.LayoutInflater, android.view.ViewGroup, android.os.Bundle) (Fragment.java:1924)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void androidx.fragment.app.Fragment.performCreateView(android.view.LayoutInflater, android.view.ViewGroup, android.os.Bundle) (Fragment.java:2963)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.ensureInflatedView() (FragmentStateManager.java:386)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.moveToExpectedState() (FragmentStateManager.java:281)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentLayoutInflaterFactory.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentLayoutInflaterFactory.java:140)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentController.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentController.java:135)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentActivity.dispatchFragmentsOnCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentActivity.java:319)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentActivity.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentActivity.java:298)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:780)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:730)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflate(org.xmlpull.v1.XmlPullParser, android.view.View, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:863)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflateChildren(org.xmlpull.v1.XmlPullParser, android.view.View, android.util.AttributeSet, boolean) (LayoutInflater.java:824)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(org.xmlpull.v1.XmlPullParser, android.view.ViewGroup, boolean) (LayoutInflater.java:515)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup, boolean) (LayoutInflater.java:423)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup) (LayoutInflater.java:374)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void androidx.appcompat.app.AppCompatDelegateImpl.setContentView(int) (AppCompatDelegateImpl.java:696)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void androidx.appcompat.app.AppCompatActivity.setContentView(int) (AppCompatActivity.java:170)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:100)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.app.Activity.performCreate(android.os.Bundle, android.os.PersistableBundle) (Activity.java:7144)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.app.Activity.performCreate(android.os.Bundle) (Activity.java:7135)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.app.Instrumentation.callActivityOnCreate(android.app.Activity, android.os.Bundle) (Instrumentation.java:1271)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.app.Activity android.app.ActivityThread.performLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.content.Intent) (ActivityThread.java:2931)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at android.app.Activity android.app.ActivityThread.handleLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.app.servertransaction.PendingTransactionActions, android.content.Intent) (ActivityThread.java:3086)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.app.servertransaction.LaunchActivityItem.execute(android.app.ClientTransactionHandler, android.os.IBinder, android.app.servertransaction.PendingTransactionActions) (LaunchActivityItem.java:78)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.app.servertransaction.TransactionExecutor.executeCallbacks(android.app.servertransaction.ClientTransaction) (TransactionExecutor.java:108)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.app.servertransaction.TransactionExecutor.execute(android.app.servertransaction.ClientTransaction) (TransactionExecutor.java:68)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.app.ActivityThread$H.handleMessage(android.os.Message) (ActivityThread.java:1816)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.os.Handler.dispatchMessage(android.os.Message) (Handler.java:106)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.os.Looper.loop() (Looper.java:193)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void android.app.ActivityThread.main(java.lang.String[]) (ActivityThread.java:6718)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at java.lang.Object java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object[]) (Method.java:-2)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run() (RuntimeInit.java:491)
04-26 15:13:05.312 12261 12261 I plete.test32ne:   at void com.android.internal.os.ZygoteInit.main(java.lang.String[]) (ZygoteInit.java:858)
04-26 15:13:05.312 12261 12261 I plete.test32ne: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.WindowInsetsAnimation$Callback" on path: DexPathList[[zip file "/data/app/de.westnordost.streetcomplete.test32new-UcMpaVyG7HYnwh97O54_uA==/base.apk"],nativeLibraryDirectories=[/data/app/de.westnordost.streetcomplete.test32new-UcMpaVyG7HYnwh97O54_uA==/lib/arm, /data/app/de.westnordost.streetcomplete.test32new-UcMpaVyG7HYnwh97O54_uA==/base.apk!/lib/armeabi-v7a, /system/lib, /system/vendor/lib]]
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at java.lang.Class dalvik.system.BaseDexClassLoader.findClass(java.lang.String) (BaseDexClassLoader.java:134)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at java.lang.Class java.lang.ClassLoader.loadClass(java.lang.String, boolean) (ClassLoader.java:379)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at java.lang.Class java.lang.ClassLoader.loadClass(java.lang.String) (ClassLoader.java:312)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.view.insets_animation.ImeInsetsAnimationCallbackKt.respectSystemInsets(android.view.View, kotlin.jvm.functions.Function5) (ImeInsetsAnimationCallback.kt:-1)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.map.MapFragment.onViewCreated(android.view.View, android.os.Bundle) (MapFragment.kt:118)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void androidx.fragment.app.Fragment.performViewCreated() (Fragment.java:2987)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.ensureInflatedView() (FragmentStateManager.java:392)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.moveToExpectedState() (FragmentStateManager.java:281)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentLayoutInflaterFactory.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentLayoutInflaterFactory.java:140)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater$FactoryMerger.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:186)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:772)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:730)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflate(org.xmlpull.v1.XmlPullParser, android.view.View, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:863)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflateChildren(org.xmlpull.v1.XmlPullParser, android.view.View, android.util.AttributeSet, boolean) (LayoutInflater.java:824)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(org.xmlpull.v1.XmlPullParser, android.view.ViewGroup, boolean) (LayoutInflater.java:515)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup, boolean) (LayoutInflater.java:423)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.Fragment.onCreateView(android.view.LayoutInflater, android.view.ViewGroup, android.os.Bundle) (Fragment.java:1924)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void androidx.fragment.app.Fragment.performCreateView(android.view.LayoutInflater, android.view.ViewGroup, android.os.Bundle) (Fragment.java:2963)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.ensureInflatedView() (FragmentStateManager.java:386)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void androidx.fragment.app.FragmentStateManager.moveToExpectedState() (FragmentStateManager.java:281)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentLayoutInflaterFactory.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentLayoutInflaterFactory.java:140)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentController.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentController.java:135)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentActivity.dispatchFragmentsOnCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentActivity.java:319)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View androidx.fragment.app.FragmentActivity.onCreateView(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (FragmentActivity.java:298)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:780)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.createViewFromTag(android.view.View, java.lang.String, android.content.Context, android.util.AttributeSet) (LayoutInflater.java:730)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflate(org.xmlpull.v1.XmlPullParser, android.view.View, android.content.Context, android.util.AttributeSet, boolean) (LayoutInflater.java:863)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.view.LayoutInflater.rInflateChildren(org.xmlpull.v1.XmlPullParser, android.view.View, android.util.AttributeSet, boolean) (LayoutInflater.java:824)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(org.xmlpull.v1.XmlPullParser, android.view.ViewGroup, boolean) (LayoutInflater.java:515)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup, boolean) (LayoutInflater.java:423)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.view.View android.view.LayoutInflater.inflate(int, android.view.ViewGroup) (LayoutInflater.java:374)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void androidx.appcompat.app.AppCompatActivity.setContentView(int) (AppCompatActivity.java:170)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void de.westnordost.streetcomplete.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:100)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.app.Activity.performCreate(android.os.Bundle, android.os.PersistableBundle) (Activity.java:7144)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.app.Activity.performCreate(android.os.Bundle) (Activity.java:7135)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.app.Instrumentation.callActivityOnCreate(android.app.Activity, android.os.Bundle) (Instrumentation.java:1271)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.app.Activity android.app.ActivityThread.performLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.content.Intent) (ActivityThread.java:2931)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at android.app.Activity android.app.ActivityThread.handleLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.app.servertransaction.PendingTransactionActions, android.content.Intent) (ActivityThread.java:3086)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.app.servertransaction.LaunchActivityItem.execute(android.app.ClientTransactionHandler, android.os.IBinder, android.app.servertransaction.PendingTransactionActions) (LaunchActivityItem.java:78)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.app.servertransaction.TransactionExecutor.executeCallbacks(android.app.servertransaction.ClientTransaction) (TransactionExecutor.java:108)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.app.servertransaction.TransactionExecutor.execute(android.app.servertransaction.ClientTransaction) (TransactionExecutor.java:68)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.app.ActivityThread$H.handleMessage(android.os.Message) (ActivityThread.java:1816)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.os.Handler.dispatchMessage(android.os.Message) (Handler.java:106)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.os.Looper.loop() (Looper.java:193)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void android.app.ActivityThread.main(java.lang.String[]) (ActivityThread.java:6718)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at java.lang.Object java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object[]) (Method.java:-2)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run() (RuntimeInit.java:491)
04-26 15:13:05.313 12261 12261 I plete.test32ne:   at void com.android.internal.os.ZygoteInit.main(java.lang.String[]) (ZygoteInit.java:858)
04-26 15:13:05.313 12261 12261 I plete.test32ne: 
04-26 15:13:05.334 12261 12261 D NetworkSecurityConfig: No Network Security Config specified, using platform default
04-26 15:13:05.707 12261 12272 I plete.test32ne: Background concurrent copying GC freed 22169(925KB) AllocSpace objects, 10(3MB) LOS objects, 24% free, 6MB/8MB, paused 8.393ms total 544.971ms
04-26 15:13:05.784 12261 12301 D Tangram : Loading native library took 430ms
04-26 15:13:05.845 12261 12261 I TwilightManager: Could not get last known location. This is probably because the app does not have any location permissions. Falling back to hardcoded sunrise/sunset values.
04-26 15:13:05.900 12261 12261 D OpenGLRenderer: Skia GL Pipeline
04-26 15:13:06.292 12261 12317 I Adreno-EGL: <qeglDrvAPI_eglInitialize:379>: QUALCOMM Build: 10/21/15, 369a2ea, I96aee987eb
04-26 15:13:06.297 12261 12317 I ConfigStore: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasWideColorDisplay retrieved: 0
04-26 15:13:06.297 12261 12317 I ConfigStore: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasHDRDisplay retrieved: 0
04-26 15:13:06.298 12261 12317 I OpenGLRenderer: Initialized EGL, version 1.4
04-26 15:13:06.298 12261 12317 D OpenGLRenderer: Swap behavior 1
04-26 15:13:06.314 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:13:06.326 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:13:06.328 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:13:06.780 12261 12261 W RecyclerView: No adapter attached; skipping layout
04-26 15:13:06.785 12261 12261 D Tangram : Loading native library took 0ms
04-26 15:13:06.803 12261 12261 D Tangram : MapController creation took 17ms
04-26 15:13:06.809 12261 12261 D Tangram : MapController init took 5ms
04-26 15:13:06.917 12261 12261 I Choreographer: Skipped 57 frames!  The application may be doing too much work on its main thread.
04-26 15:13:06.959 12261 12326 W GLSurfaceView: Warning, !readyToDraw() but waiting for draw finished! Early reporting draw finished.
04-26 15:13:07.237 12261 12272 I plete.test32ne: Background concurrent copying GC freed 51096(2MB) AllocSpace objects, 7(836KB) LOS objects, 24% free, 18MB/25MB, paused 274us total 1.167s
04-26 15:13:07.390 12261 12287 I Preloader: Loaded country boundaries in 2.5s
04-26 15:13:07.432 12261 12317 D vndksupport: Loading /vendor/lib/hw/android.hardware.graphics.mapper@2.0-impl.so from current namespace instead of sphal namespace.
04-26 15:13:07.518 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:13:07.551 12261 12317 I OpenGLRenderer: Davey! duration=1592ms; Flags=1, IntendedVsync=36774891418912, Vsync=36775841418931, OldestInputEvent=9223372036854775807, NewestInputEvent=0, HandleInputStart=36775854101496, AnimationStart=36775854132016, PerformTraversalsStart=36775859320480, DrawStart=36775896250135, SyncQueued=36775938765019, SyncStart=36775942519025, IssueDrawCommandsStart=36775945479502, SwapBuffers=36776364524266, FrameCompleted=36776487887627, DequeueBufferDuration=2319000, QueueBufferDuration=2044000, 
04-26 15:13:07.595 12261 12261 I Choreographer: Skipped 40 frames!  The application may be doing too much work on its main thread.
04-26 15:13:07.633 12261 12317 I OpenGLRenderer: Davey! duration=711ms; Flags=0, IntendedVsync=36775857993245, Vsync=36776524659925, OldestInputEvent=9223372036854775807, NewestInputEvent=0, HandleInputStart=36776531806448, AnimationStart=36776531836968, PerformTraversalsStart=36776532172692, DrawStart=36776534400680, SyncQueued=36776535407852, SyncStart=36776535468893, IssueDrawCommandsStart=36776535774096, SwapBuffers=36776565531463, FrameCompleted=36776569590673, DequeueBufferDuration=183000, QueueBufferDuration=305000, 
04-26 15:13:07.787 12261 12326 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:13:07.789 12261 12326 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:13:07.794 12261 12326 D Tangram : TANGRAM map.cpp:877: setup GL
04-26 15:13:07.836 12261 12326 D Tangram : TANGRAM hardware.cpp:60: Driver supports map buffer: 0
04-26 15:13:07.836 12261 12326 D Tangram : TANGRAM hardware.cpp:61: Driver supports vaos: 1
04-26 15:13:07.836 12261 12326 D Tangram : TANGRAM hardware.cpp:62: Driver supports rgb8_rgba8: 1
04-26 15:13:07.836 12261 12326 D Tangram : TANGRAM hardware.cpp:63: Driver supports NPOT texture: 0
04-26 15:13:07.877 12261 12326 D Tangram : TANGRAM hardware.cpp:77: Hardware max texture size 4096
04-26 15:13:07.877 12261 12326 D Tangram : TANGRAM hardware.cpp:78: Hardware max combined texture units 32
04-26 15:13:07.877 12261 12326 D Tangram : TANGRAM map.cpp:210: resize: 540 x 960
04-26 15:13:08.573 12261 12272 I plete.test32ne: Background concurrent copying GC freed 72487(2MB) AllocSpace objects, 14(8MB) LOS objects, 12% free, 55MB/63MB, paused 2.533ms total 1.291s
04-26 15:13:09.692 12261 12282 I plete.test32ne: Waiting for a blocking GC ProfileSaver
04-26 15:13:10.452 12261 12272 I plete.test32ne: Background concurrent copying GC freed 255867(7MB) AllocSpace objects, 3(25MB) LOS objects, 14% free, 48MB/56MB, paused 122us total 1.670s
04-26 15:13:10.452 12261 12282 I plete.test32ne: WaitForGcToComplete blocked ProfileSaver on AddRemoveAppImageSpace for 760.720ms
04-26 15:13:12.710 12261 12272 I plete.test32ne: Background concurrent copying GC freed 327338(9MB) AllocSpace objects, 4(8MB) LOS objects, 15% free, 44MB/52MB, paused 457us total 1.025s
04-26 15:13:14.219 12261 12272 I plete.test32ne: Background concurrent copying GC freed 272950(8MB) AllocSpace objects, 4(256KB) LOS objects, 13% free, 51MB/59MB, paused 183us total 653.349ms
04-26 15:13:15.830 12261 12288 I Preloader: Loaded features dictionary in 10.9s
04-26 15:13:15.832 12261 12292 I Preloader: Preloading data took 11.0s
04-26 15:13:15.853 12261 12288 I Cleaner : Cleaning took 0.0s
04-26 15:13:16.155 12261 12272 I plete.test32ne: Background concurrent copying GC freed 940274(30MB) AllocSpace objects, 13(3MB) LOS objects, 22% free, 27MB/35MB, paused 2.105ms total 866.259ms
04-26 15:14:13.152 12261 12261 I Choreographer: Skipped 3919 frames!  The application may be doing too much work on its main thread.
04-26 15:14:13.170 12261 12317 I OpenGLRenderer: Davey! duration=65348ms; Flags=0, IntendedVsync=36776758175625, Vsync=36842074843598, OldestInputEvent=9223372036854775807, NewestInputEvent=0, HandleInputStart=36842089114950, AnimationStart=36842089145470, PerformTraversalsStart=36842089603276, DrawStart=36842089755878, SyncQueued=36842090213684, SyncStart=36842090244204, IssueDrawCommandsStart=36842090518887, SwapBuffers=36842105077107, FrameCompleted=36842106938850, DequeueBufferDuration=518000, QueueBufferDuration=305000, 
04-26 15:14:13.309 12261 12325 D Tangram : WARNING sceneLoader.cpp:687: Can't find data source streetcomplete_selected_pins for layer streetcomplete_selected_pins
04-26 15:14:13.309 12261 12325 D Tangram : WARNING sceneLoader.cpp:687: Can't find data source streetcomplete_pins for layer streetcomplete_pins
04-26 15:14:13.309 12261 12325 D Tangram : WARNING sceneLoader.cpp:687: Can't find data source streetcomplete_geometry for layer streetcomplete_geometry
04-26 15:14:13.309 12261 12325 D Tangram : WARNING tileManager.cpp:204: add source jawg
04-26 15:14:13.309 12261 12326 D Tangram : TANGRAM scene.cpp:312: Prefetch tiles for View: 540.000000x960.000000 / zoom:2.357552 lon:0.000000 lat:0.000000
04-26 15:14:13.411 12261 12325 E Tangram : Error in font.xml parsing: END_TAG expected (position:START_TAG (empty) <axis tag='wdth' stylevalue='100.0'>@222:51 in java.io.InputStreamReader@55cba9c) 
04-26 15:14:13.438 12261 12325 D Tangram : FontConfig init took 115ms
04-26 15:14:13.464 12261 12325 D Tangram : TANGRAM scene.cpp:427: Fetch texture asset:///map_theme/jawg/images/oneway_arrow@2x.png
04-26 15:14:13.464 12261 12324 D Tangram : TANGRAM scene.cpp:432: Received texture asset:///map_theme/jawg/images/oneway_arrow@2x.png
04-26 15:14:13.465 12261 12324 D Tangram : WARNING texture.cpp:172: OpenGL ES doesn't support texture repeat wrapping for NPOT textures nor mipmap textures
04-26 15:14:13.465 12261 12324 D Tangram : WARNING texture.cpp:173: Falling back to LINEAR Filtering
04-26 15:14:13.465 12261 12325 D Tangram : TANGRAM scene.cpp:427: Fetch texture asset:///map_theme/jawg/images/pin_dot@2x.png
04-26 15:14:13.466 12261 12324 D Tangram : TANGRAM scene.cpp:432: Received texture asset:///map_theme/jawg/images/pin_dot@2x.png
04-26 15:14:13.466 12261 12325 D Tangram : TANGRAM scene.cpp:427: Fetch texture file:///data/user/0/de.westnordost.streetcomplete.test32new/files/pins.png
04-26 15:14:13.472 12261 12324 D Tangram : TANGRAM scene.cpp:432: Received texture file:///data/user/0/de.westnordost.streetcomplete.test32new/files/pins.png
04-26 15:14:13.683 12261 12324 D Tangram : WARNING texture.cpp:172: OpenGL ES doesn't support texture repeat wrapping for NPOT textures nor mipmap textures
04-26 15:14:13.683 12261 12324 D Tangram : WARNING texture.cpp:173: Falling back to LINEAR Filtering
04-26 15:14:13.712 12261 12326 D Tangram : TANGRAM scene.cpp:312: Prefetch tiles for View: 540.000000x960.000000 / zoom:19.000000 lon:16.417970 lat:48.186681
04-26 15:14:13.993 12261 12326 D Tangram : NOTIFY markerManager.cpp:407: Invalid style 
04-26 15:14:21.900 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:14:21.901 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:14:21.933 12261 12326 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:14:21.934 12261 12326 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:14:21.944 12261 12326 D Tangram : TANGRAM map.cpp:210: resize: 540 x 960
04-26 15:14:21.960 12261 12326 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:14:21.961 12261 12326 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:14:21.998 12261 12326 D Tangram : TANGRAM map.cpp:210: resize: 540 x 960
04-26 15:14:23.902 12261 12261 I QuestAutoSyncer: Checking whether to automatically download new quests at 48.1855271,16.4193516
04-26 15:14:23.910 12261 12835 I AutoQuestDownload: Downloading tiny area around user
04-26 15:14:23.931 12261 12834 I Download: Starting download (48.1844011, 16.4190674 -> 48.1880635, 16.4245605)
04-26 15:14:23.979 12261 13118 W MapTilesDownload: Error retrieving tile 16/35757/22730: Canceled
04-26 15:14:23.983 12261 13122 W MapTilesDownload: Error retrieving tile 15/17878/11365: Canceled
04-26 15:14:23.996 12261 13118 W MapTilesDownload: Error retrieving tile 14/8939/5682: Canceled
04-26 15:14:23.997 12261 13122 W MapTilesDownload: Error retrieving tile 13/4469/2841: Canceled
04-26 15:14:24.093 12261 13127 E Download: Unable to download
04-26 15:14:24.233 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:14:24.237 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:14:37.827 12261 12674 E Tangram : Error reading bytes from response body:stream was reset: CANCEL
04-26 15:14:38.609 12261 12674 E Tangram : Error reading bytes from response body:stream was reset: CANCEL
04-26 15:14:40.762 12261 12272 I plete.test32ne: Background concurrent copying GC freed 192922(7MB) AllocSpace objects, 24(1008KB) LOS objects, 20% free, 30MB/38MB, paused 2.319ms total 2.887s
04-26 15:14:41.129 12261 12675 E Tangram : Error reading bytes from response body:stream was reset: CANCEL
04-26 15:14:42.294 12261 12675 E Tangram : Error reading bytes from response body:stream was reset: CANCEL
04-26 15:14:49.308 12261 12261 I QuestAutoSyncer: Checking whether to automatically download new quests at 48.1855271,16.4193516
04-26 15:14:49.310 12261 12287 I AutoQuestDownload: Downloading tiny area around user
04-26 15:14:49.358 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:14:49.359 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:14:49.364 12261 12326 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:14:49.365 12261 12326 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:14:49.368 12261 12326 D Tangram : TANGRAM map.cpp:210: resize: 540 x 960
04-26 15:14:49.409 12261 12287 I Download: Starting download (48.1844011, 16.4190674 -> 48.1880635, 16.4245605)
04-26 15:14:49.455 12261 12326 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:14:49.461 12261 12326 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:14:49.512 12261 13122 V MapTilesDownload: Tile 16/35757/22730 in cache
04-26 15:14:49.513 12261 12326 D Tangram : TANGRAM map.cpp:210: resize: 540 x 960
04-26 15:14:50.437 12261 13820 V MapTilesDownload: Tile 13/4469/2841 downloaded
04-26 15:14:50.465 12261 13122 V MapTilesDownload: Tile 10/558/355 in cache
04-26 15:14:50.512 12261 13818 V MapTilesDownload: Tile 15/17878/11365 downloaded
04-26 15:14:50.525 12261 13819 V MapTilesDownload: Tile 12/2234/1420 downloaded
04-26 15:14:50.805 12261 13118 V MapTilesDownload: Tile 14/8939/5682 downloaded
04-26 15:14:50.875 12261 13819 V MapTilesDownload: Tile 6/34/22 in cache
04-26 15:14:50.912 12261 13820 V MapTilesDownload: Tile 9/279/177 downloaded
04-26 15:14:50.918 12261 13822 V MapTilesDownload: Tile 11/1117/710 downloaded
04-26 15:14:50.956 12261 13122 V MapTilesDownload: Tile 8/139/88 downloaded
04-26 15:14:50.990 12261 13118 V MapTilesDownload: Tile 5/17/11 in cache
04-26 15:14:51.013 12261 13819 V MapTilesDownload: Tile 4/8/5 in cache
04-26 15:14:51.075 12261 13820 V MapTilesDownload: Tile 3/4/2 in cache
04-26 15:14:51.099 12261 13818 V MapTilesDownload: Tile 7/69/44 downloaded
04-26 15:14:51.206 12261 13822 V MapTilesDownload: Tile 2/2/1 downloaded
04-26 15:14:51.255 12261 13122 V MapTilesDownload: Tile 1/1/0 downloaded
04-26 15:14:51.263 12261 13118 V MapTilesDownload: Tile 0/0/0 downloaded
04-26 15:14:51.265 12261 13119 I MapTilesDownload: Downloaded 17 tiles (763kB downloaded, 237kB already cached) in 1.8s
04-26 15:14:52.110 12261 12835 I NotesDownload: Downloaded 1 notes in 2.7s
04-26 15:14:52.217 12261 12835 I NoteController: Persisted 1 and deleted 0 notes in 0.1s
04-26 15:14:52.437 12261 12835 I OsmAvatarsDownload: Downloaded 2 avatar images in 0.2s
04-26 15:14:52.966 12261 12272 I plete.test32ne: Background concurrent copying GC freed 263751(11MB) AllocSpace objects, 19(920KB) LOS objects, 19% free, 33MB/41MB, paused 183us total 2.266s
04-26 15:14:54.676 12261 13127 I MapDataDownload: Downloaded 2493 nodes, 277 ways and 81 relations in 5.3s
04-26 15:14:55.296 12261 12272 I plete.test32ne: Background concurrent copying GC freed 393263(11MB) AllocSpace objects, 17(784KB) LOS objects, 20% free, 30MB/38MB, paused 183us total 1.017s
04-26 15:14:56.478 12261 12272 I plete.test32ne: Background concurrent copying GC freed 213554(5MB) AllocSpace objects, 7(1176KB) LOS objects, 15% free, 45MB/53MB, paused 274us total 1.012s
04-26 15:15:00.032 12261 12272 I plete.test32ne: Background concurrent copying GC freed 226464(7MB) AllocSpace objects, 16(13MB) LOS objects, 18% free, 34MB/42MB, paused 152us total 932.305ms
04-26 15:15:02.926 12261 12272 I plete.test32ne: Background concurrent copying GC freed 157614(6MB) AllocSpace objects, 0(0B) LOS objects, 18% free, 36MB/44MB, paused 152us total 1.197s
04-26 15:15:10.882 12261 13127 I MapDataController: Persisted 2811 and deleted 0 elements and geometries in 16.2s
04-26 15:15:11.109 12261 12288 D OsmQuestController: AddRoadName: Found 0 quests in 45ms
04-26 15:15:11.213 12261 12288 D OsmQuestController: AddOneway: Found 0 quests in 103ms
04-26 15:15:11.506 12261 12288 D OsmQuestController: AddPostboxCollectionTimes: Found 0 quests in 292ms
04-26 15:15:11.646 12261 13119 D OsmQuestController: AddPlaceName: Found 0 quests in 583ms
04-26 15:15:11.652 12261 13119 D OsmQuestController: AddSuspectedOneway: Found 0 quests in 1ms
04-26 15:15:11.913 12261 13119 D OsmQuestController: AddBarrierType: Found 0 quests in 260ms
04-26 15:15:12.237 12261 13119 D OsmQuestController: AddCycleway: Found 0 quests in 323ms
04-26 15:15:12.295 12261 12288 D OsmQuestController: CheckExistence: Found 4 quests in 788ms
04-26 15:15:12.418 12261 13119 D OsmQuestController: AddSidewalk: Found 0 quests in 176ms
04-26 15:15:12.419 12261 13119 D OsmQuestController: AddBusStopRef: Skipped because it is disabled for this country
04-26 15:15:12.460 12261 13119 D OsmQuestController: AddIsBuildingUnderground: Found 0 quests in 40ms
04-26 15:15:12.461 12261 13119 D OsmQuestController: AddHousenumber: Found 0 quests in 0ms
04-26 15:15:12.553 12261 12288 D OsmQuestController: AddBusStopName: Found 0 quests in 257ms
04-26 15:15:12.692 12261 12288 D OsmQuestController: SpecifyShopType: Found 0 quests in 138ms
04-26 15:15:12.723 12261 13119 D OsmQuestController: AddAddressStreet: Found 0 quests in 262ms
04-26 15:15:12.746 12261 13119 D OsmQuestController: MarkCompletedHighwayConstruction: Found 0 quests in 23ms
04-26 15:15:12.776 12261 13119 D OsmQuestController: AddReligionToPlaceOfWorship: Found 0 quests in 24ms
04-26 15:15:12.786 12261 12288 D OsmQuestController: CheckShopType: Found 0 quests in 94ms
04-26 15:15:12.797 12261 13119 D OsmQuestController: AddParkingAccess: Found 0 quests in 20ms
04-26 15:15:12.797 12261 13119 D OsmQuestController: AddRecyclingContainerMaterials: Found 0 quests in 0ms
04-26 15:15:12.811 12261 12288 D OsmQuestController: AddRecyclingType: Found 0 quests in 24ms
04-26 15:15:12.816 12261 13119 D OsmQuestController: AddSport: Found 0 quests in 18ms
04-26 15:15:12.859 12261 13119 D OsmQuestController: AddMaxSpeed: Found 1 quests in 42ms
04-26 15:15:12.865 12261 12288 D OsmQuestController: AddRoadSurface: Found 0 quests in 52ms
04-26 15:15:12.892 12261 12288 D OsmQuestController: AddLanes: Found 1 quests in 26ms
04-26 15:15:13.057 12261 12288 D OsmQuestController: AddRailwayCrossingBarrier: Found 0 quests in 164ms
04-26 15:15:13.072 12261 13119 D OsmQuestController: AddMaxHeight: Found 4 quests in 212ms
04-26 15:15:13.122 12261 13119 D OsmQuestController: AddBikeParkingCapacity: Found 1 quests in 50ms
04-26 15:15:13.131 12261 13119 D OsmQuestController: AddOrchardProduce: Found 0 quests in 5ms
04-26 15:15:13.173 12261 13119 D OsmQuestController: AddBuildingType: Found 6 quests in 40ms
04-26 15:15:13.460 12261 13119 D OsmQuestController: AddProhibitedForPedestrians: Found 0 quests in 286ms
04-26 15:15:13.503 12261 13119 D OsmQuestController: AddCrossingType: Found 1 quests in 42ms
04-26 15:15:13.705 12261 13119 D OsmQuestController: AddCrossingIsland: Found 0 quests in 200ms
04-26 15:15:13.724 12261 13119 D OsmQuestController: AddBuildingLevels: Found 1 quests in 19ms
04-26 15:15:13.733 12261 12288 D OsmQuestController: AddOpeningHours: Found 15 quests in 676ms
04-26 15:15:13.760 12261 12288 D OsmQuestController: AddVegetarian: Found 3 quests in 26ms
04-26 15:15:13.777 12261 13119 D OsmQuestController: AddBusStopShelter: Found 0 quests in 53ms
04-26 15:15:13.793 12261 12288 D OsmQuestController: AddVegan: Found 0 quests in 33ms
04-26 15:15:13.823 12261 12288 D OsmQuestController: AddParkingFee: Found 2 quests in 29ms
04-26 15:15:13.830 12261 13119 D OsmQuestController: AddInternetAccess: Found 2 quests in 53ms
04-26 15:15:13.839 12261 12288 D OsmQuestController: AddMotorcycleParkingCapacity: Found 0 quests in 15ms
04-26 15:15:13.880 12261 12288 D OsmQuestController: AddTracktype: Found 0 quests in 31ms
04-26 15:15:13.930 12261 13119 D OsmQuestController: AddPathSurface: Found 0 quests in 100ms
04-26 15:15:13.956 12261 12288 D OsmQuestController: AddMaxWeight: Found 0 quests in 75ms
04-26 15:15:13.985 12261 12288 D OsmQuestController: AddBikeParkingType: Found 1 quests in 25ms
04-26 15:15:14.013 12261 12288 D OsmQuestController: AddBikeParkingAccess: Found 0 quests in 27ms
04-26 15:15:14.054 12261 12288 D OsmQuestController: AddBikeParkingFee: Found 0 quests in 40ms
04-26 15:15:14.076 12261 12288 D OsmQuestController: AddStepsRamp: Found 0 quests in 20ms
04-26 15:15:14.104 12261 12288 D OsmQuestController: AddWheelchairAccessToilets: Found 0 quests in 27ms
04-26 15:15:14.124 12261 12288 D OsmQuestController: AddPlaygroundAccess: Found 0 quests in 20ms
04-26 15:15:14.125 12261 12272 I plete.test32ne: Background concurrent copying GC freed 541922(12MB) AllocSpace objects, 0(0B) LOS objects, 17% free, 38MB/46MB, paused 1.068ms total 2.070s
04-26 15:15:14.147 12261 13119 D OsmQuestController: AddForestLeafType: Found 0 quests in 216ms
04-26 15:15:14.180 12261 12288 D OsmQuestController: AddWheelchairAccessBusiness: Found 5 quests in 55ms
04-26 15:15:14.188 12261 12288 D OsmQuestController: AddFerryAccessPedestrian: Found 0 quests in 8ms
04-26 15:15:14.190 12261 13119 D OsmQuestController: AddToiletAvailability: Found 3 quests in 42ms
04-26 15:15:14.190 12261 13119 D OsmQuestController: AddAcceptsCash: Skipped because it is disabled for this country
04-26 15:15:14.191 12261 12288 D OsmQuestController: AddFerryAccessMotorVehicle: Found 0 quests in 2ms
04-26 15:15:14.197 12261 13119 D OsmQuestController: DetermineRecyclingGlass: Found 0 quests in 6ms
04-26 15:15:14.206 12261 13119 D OsmQuestController: AddToiletsFee: Found 0 quests in 9ms
04-26 15:15:14.228 12261 13119 D OsmQuestController: AddBabyChangingTable: Found 2 quests in 21ms
04-26 15:15:14.246 12261 13119 D OsmQuestController: AddBikeParkingCover: Found 1 quests in 18ms
04-26 15:15:14.263 12261 12288 D OsmQuestController: AddWayLit: Found 0 quests in 71ms
04-26 15:15:14.274 12261 13119 D OsmQuestController: AddDrinkingWater: Found 0 quests in 27ms
04-26 15:15:14.408 12261 13119 D OsmQuestController: AddTactilePavingKerb: Found 0 quests in 133ms
04-26 15:15:14.418 12261 12288 D OsmQuestController: AddTactilePavingCrosswalk: Found 1 quests in 154ms
04-26 15:15:14.493 12261 12288 D OsmQuestController: AddTrafficSignalsSound: Found 0 quests in 70ms
04-26 15:15:14.511 12261 13119 D OsmQuestController: AddKerbHeight: Found 0 quests in 102ms
04-26 15:15:14.556 12261 12288 D OsmQuestController: AddTrafficSignalsVibration: Found 0 quests in 63ms
04-26 15:15:14.694 12261 12288 D OsmQuestController: AddWheelchairAccessPublicTransport: Found 0 quests in 137ms
04-26 15:15:14.797 12261 12288 D OsmQuestController: AddWheelchairAccessOutside: Found 0 quests in 103ms
04-26 15:15:14.938 12261 12288 D OsmQuestController: AddTactilePavingBusStop: Found 0 quests in 141ms
04-26 15:15:14.942 12261 12288 D OsmQuestController: AddBridgeStructure: Found 0 quests in 3ms
04-26 15:15:14.952 12261 12288 D OsmQuestController: AddReligionToWaysideShrine: Found 0 quests in 10ms
04-26 15:15:14.973 12261 12288 D OsmQuestController: AddCyclewaySegregation: Found 0 quests in 14ms
04-26 15:15:14.987 12261 12288 D OsmQuestController: MarkCompletedBuildingConstruction: Found 0 quests in 5ms
04-26 15:15:14.996 12261 12288 D OsmQuestController: AddGeneralFee: Found 0 quests in 9ms
04-26 15:15:15.013 12261 12288 D OsmQuestController: AddSelfServiceLaundry: Found 0 quests in 16ms
04-26 15:15:15.021 12261 12288 D OsmQuestController: AddStepsIncline: Found 0 quests in 6ms
04-26 15:15:15.042 12261 13119 D OsmQuestController: AddRoofShape: Found 0 quests in 531ms
04-26 15:15:15.044 12261 12288 D OsmQuestController: AddHandrail: Found 0 quests in 23ms
04-26 15:15:15.047 12261 13119 D OsmQuestController: AddStepCount: Found 0 quests in 4ms
04-26 15:15:15.055 12261 12288 D OsmQuestController: AddInformationToTourism: Found 0 quests in 10ms
04-26 15:15:15.058 12261 13119 D OsmQuestController: AddAtmOperator: Found 1 quests in 11ms
04-26 15:15:15.062 12261 13119 D OsmQuestController: AddChargingStationOperator: Found 0 quests in 4ms
04-26 15:15:15.065 12261 12288 D OsmQuestController: AddChargingStationCapacity: Found 0 quests in 9ms
04-26 15:15:15.087 12261 12288 D OsmQuestController: AddKosher: Found 3 quests in 21ms
04-26 15:15:15.124 12261 13119 D OsmQuestController: AddClothingBinOperator: Found 0 quests in 61ms
04-26 15:15:15.131 12261 13119 D OsmQuestController: AddPitchSurface: Found 0 quests in 7ms
04-26 15:15:15.142 12261 13119 D OsmQuestController: AddPitchLit: Found 0 quests in 10ms
04-26 15:15:15.148 12261 13119 D OsmQuestController: AddIsDefibrillatorIndoor: Found 2 quests in 6ms
04-26 15:15:15.164 12261 12288 D OsmQuestController: AddStileType: Found 0 quests in 76ms
04-26 15:15:15.187 12261 12288 D OsmQuestController: AddCyclewayPartSurface: Found 0 quests in 23ms
04-26 15:15:15.198 12261 12288 D OsmQuestController: AddFootwayPartSurface: Found 0 quests in 8ms
04-26 15:15:15.205 12261 12288 D OsmQuestController: AddMotorcycleParkingCover: Found 0 quests in 7ms
04-26 15:15:15.211 12261 12288 D OsmQuestController: AddFireHydrantType: Found 0 quests in 5ms
04-26 15:15:15.212 12261 13119 D OsmQuestController: AddSummitRegister: Found 0 quests in 64ms
04-26 15:15:15.219 12261 12288 D OsmQuestController: AddParkingType: Found 0 quests in 7ms
04-26 15:15:15.221 12261 13119 D OsmQuestController: AddPostboxRef: Found 0 quests in 7ms
04-26 15:15:15.229 12261 12288 D OsmQuestController: AddWheelchairAccessToiletsPart: Found 0 quests in 10ms
04-26 15:15:15.232 12261 12288 D OsmQuestController: AddPoliceType: Skipped because it is disabled for this country
04-26 15:15:15.232 12261 13119 D OsmQuestController: AddBoardType: Found 0 quests in 10ms
04-26 15:15:15.240 12261 12288 D OsmQuestController: AddPowerPolesMaterial: Found 0 quests in 7ms
04-26 15:15:15.241 12261 13119 D OsmQuestController: AddCarWashType: Found 0 quests in 4ms
04-26 15:15:15.247 12261 13119 D OsmQuestController: AddBenchBackrest: Found 3 quests in 5ms
04-26 15:15:15.262 12261 13119 D OsmQuestController: AddTrafficSignalsButton: Found 0 quests in 14ms
04-26 15:15:15.262 12261 12288 D OsmQuestController: AddBenchStatusOnBusStop: Found 0 quests in 22ms
04-26 15:15:15.263 12261 12288 D OsmQuestController: AddPostboxRoyalCypher: Skipped because it is disabled for this country
04-26 15:15:15.278 12261 13127 I OsmQuestController: Created 63 quests for bbox in 4.2s
04-26 15:15:15.311 12261 13127 I OsmQuestController: Persisted 63 new and removed 0 already resolved quests in 0.0s
04-26 15:15:15.937 12261 12288 I Download: Finished download (48.1844011, 16.4190674 -> 48.1880635, 16.4245605) in 26.5s
04-26 15:15:15.939 12261 12288 I QuestAutoSyncer: Checking whether to automatically download new quests at 48.1855096,16.4193801
04-26 15:15:15.947 12261 13127 I AutoQuestDownload: Downloading in radius of 915 meters around user
04-26 15:15:15.968 12261 12288 I Download: Starting download (48.1770756, 16.4025879 -> 48.1953874, 16.4355469)
04-26 15:15:16.047 12261 13122 V MapTilesDownload: Tile 16/35755/22728 downloaded
04-26 15:15:16.109 12261 13822 V MapTilesDownload: Tile 16/35756/22728 downloaded
04-26 15:15:16.114 12261 13818 V MapTilesDownload: Tile 16/35757/22728 downloaded
04-26 15:15:16.123 12261 13820 V MapTilesDownload: Tile 16/35758/22728 downloaded
04-26 15:15:16.129 12261 13118 V MapTilesDownload: Tile 16/35754/22728 downloaded
04-26 15:15:16.191 12261 13819 V MapTilesDownload: Tile 16/35754/22729 downloaded
04-26 15:15:16.206 12261 13122 V MapTilesDownload: Tile 16/35759/22728 downloaded
04-26 15:15:16.229 12261 13822 V MapTilesDownload: Tile 16/35755/22729 downloaded
04-26 15:15:16.241 12261 13818 V MapTilesDownload: Tile 16/35756/22729 downloaded
04-26 15:15:16.303 12261 13900 V MapTilesDownload: Tile 16/35757/22729 downloaded
04-26 15:15:16.324 12261 13820 V MapTilesDownload: Tile 16/35758/22729 downloaded
04-26 15:15:16.343 12261 13818 V MapTilesDownload: Tile 16/35756/22730 in cache
04-26 15:15:16.356 12261 13819 V MapTilesDownload: Tile 16/35759/22729 downloaded
04-26 15:15:16.369 12261 13122 V MapTilesDownload: Tile 16/35754/22730 downloaded
04-26 15:15:16.379 12261 13900 V MapTilesDownload: Tile 16/35757/22730 in cache
04-26 15:15:16.420 12261 13822 V MapTilesDownload: Tile 16/35755/22730 downloaded
04-26 15:15:16.458 12261 13900 V MapTilesDownload: Tile 16/35756/22731 in cache
04-26 15:15:16.489 12261 13822 V MapTilesDownload: Tile 16/35757/22731 in cache
04-26 15:15:16.558 12261 13127 I NotesDownload: Downloaded 18 notes in 0.6s
04-26 15:15:16.593 12261 13127 I NoteController: Persisted 17 and deleted 0 notes in 0.0s
04-26 15:15:17.023 12261 12272 I plete.test32ne: Background concurrent copying GC freed 449312(13MB) AllocSpace objects, 18(1408KB) LOS objects, 19% free, 33MB/41MB, paused 152us total 1.464s
04-26 15:15:18.526 12261 13820 V MapTilesDownload: Tile 16/35758/22730 downloaded
04-26 15:15:18.544 12261 13900 V MapTilesDownload: Tile 16/35758/22731 downloaded
04-26 15:15:18.592 12261 13819 V MapTilesDownload: Tile 16/35759/22730 downloaded
04-26 15:15:18.603 12261 13818 V MapTilesDownload: Tile 16/35755/22731 downloaded
04-26 15:15:18.616 12261 13122 V MapTilesDownload: Tile 16/35754/22731 downloaded
04-26 15:15:18.639 12261 13822 V MapTilesDownload: Tile 16/35759/22731 downloaded
04-26 15:15:18.690 12261 13900 V MapTilesDownload: Tile 16/35756/22732 downloaded
04-26 15:15:18.739 12261 13819 V MapTilesDownload: Tile 16/35755/22732 downloaded
04-26 15:15:18.746 12261 13818 V MapTilesDownload: Tile 16/35757/22732 downloaded
04-26 15:15:18.791 12261 13820 V MapTilesDownload: Tile 16/35754/22732 downloaded
04-26 15:15:18.808 12261 13122 V MapTilesDownload: Tile 16/35759/22732 downloaded
04-26 15:15:18.870 12261 13822 V MapTilesDownload: Tile 16/35758/22732 downloaded
04-26 15:15:18.890 12261 13122 V MapTilesDownload: Tile 15/17878/11365 in cache
04-26 15:15:18.926 12261 13900 V MapTilesDownload: Tile 15/17877/11364 downloaded
04-26 15:15:18.973 12261 13818 V MapTilesDownload: Tile 15/17879/11364 downloaded
04-26 15:15:18.983 12261 13820 V MapTilesDownload: Tile 15/17877/11365 downloaded
04-26 15:15:18.985 12261 13819 V MapTilesDownload: Tile 15/17878/11364 downloaded
04-26 15:15:19.037 12261 13818 V MapTilesDownload: Tile 14/8939/5682 in cache
04-26 15:15:19.038 12261 13822 V MapTilesDownload: Tile 15/17879/11365 downloaded
04-26 15:15:19.086 12261 13122 V MapTilesDownload: Tile 15/17877/11366 downloaded
04-26 15:15:19.154 12261 13819 V MapTilesDownload: Tile 15/17879/11366 downloaded
04-26 15:15:19.187 12261 13900 V MapTilesDownload: Tile 14/8938/5682 downloaded
04-26 15:15:19.223 12261 13819 V MapTilesDownload: Tile 12/2234/1420 in cache
04-26 15:15:19.258 12261 13122 V MapTilesDownload: Tile 13/4469/2841 in cache
04-26 15:15:19.262 12261 13820 V MapTilesDownload: Tile 15/17878/11366 downloaded
04-26 15:15:19.297 12261 13118 V MapTilesDownload: Tile 9/279/177 in cache
04-26 15:15:19.303 12261 13900 V MapTilesDownload: Tile 11/1117/710 in cache
04-26 15:15:19.328 12261 13819 V MapTilesDownload: Tile 10/558/355 in cache
04-26 15:15:19.361 12261 13118 V MapTilesDownload: Tile 4/8/5 in cache
04-26 15:15:19.363 12261 13820 V MapTilesDownload: Tile 8/139/88 in cache
04-26 15:15:19.378 12261 13822 V MapTilesDownload: Tile 14/8939/5683 downloaded
04-26 15:15:19.435 12261 13118 V MapTilesDownload: Tile 3/4/2 in cache
04-26 15:15:19.464 12261 13122 V MapTilesDownload: Tile 7/69/44 in cache
04-26 15:15:19.469 12261 13819 V MapTilesDownload: Tile 5/17/11 in cache
04-26 15:15:19.479 12261 13820 V MapTilesDownload: Tile 6/34/22 in cache
04-26 15:15:19.482 12261 13818 V MapTilesDownload: Tile 14/8938/5683 downloaded
04-26 15:15:19.497 12261 13122 V MapTilesDownload: Tile 1/1/0 in cache
04-26 15:15:19.502 12261 13822 V MapTilesDownload: Tile 2/2/1 in cache
04-26 15:15:19.509 12261 13118 V MapTilesDownload: Tile 0/0/0 in cache
04-26 15:15:19.511 12261 12834 I MapTilesDownload: Downloaded 57 tiles (780kB downloaded, 1052kB already cached) in 3.5s
04-26 15:15:20.074 12261 13127 D OsmAvatarsDownload: Downloaded file: /data/user/0/de.westnordost.streetcomplete.test32new/cache/osm_user_avatars/10932154
04-26 15:15:20.759 12261 12272 I plete.test32ne: Background concurrent copying GC freed 241532(9MB) AllocSpace objects, 45(1812KB) LOS objects, 18% free, 36MB/44MB, paused 183us total 1.007s
04-26 15:15:20.862 12261 13127 D OsmAvatarsDownload: Downloaded file: /data/user/0/de.westnordost.streetcomplete.test32new/cache/osm_user_avatars/28910
04-26 15:15:20.968 12261 13127 I OsmAvatarsDownload: Downloaded 10 avatar images in 4.4s
04-26 15:15:22.742 12261 12272 I plete.test32ne: Background concurrent copying GC freed 555884(13MB) AllocSpace objects, 11(216KB) LOS objects, 18% free, 36MB/44MB, paused 152us total 1.016s
04-26 15:15:24.626 12261 12272 I plete.test32ne: Background concurrent copying GC freed 517273(11MB) AllocSpace objects, 0(0B) LOS objects, 16% free, 39MB/47MB, paused 213us total 1.094s
04-26 15:15:26.789 12261 12272 I plete.test32ne: Background concurrent copying GC freed 522432(11MB) AllocSpace objects, 0(0B) LOS objects, 16% free, 41MB/49MB, paused 152us total 1.334s
04-26 15:15:29.336 12261 12272 I plete.test32ne: Background concurrent copying GC freed 380092(8MB) AllocSpace objects, 0(0B) LOS objects, 14% free, 45MB/53MB, paused 1.220ms total 1.453s
04-26 15:15:32.370 12261 12272 I plete.test32ne: Background concurrent copying GC freed 368607(9MB) AllocSpace objects, 0(0B) LOS objects, 13% free, 49MB/57MB, paused 824us total 1.596s
04-26 15:15:35.511 12261 12272 I plete.test32ne: Background concurrent copying GC freed 384444(9MB) AllocSpace objects, 0(0B) LOS objects, 13% free, 53MB/61MB, paused 122us total 1.755s
04-26 15:15:37.809 12261 12287 I MapDataDownload: Downloaded 39173 nodes, 5561 ways and 459 relations in 21.8s
04-26 15:15:38.622 12261 12272 I plete.test32ne: Background concurrent copying GC freed 394825(9MB) AllocSpace objects, 0(0B) LOS objects, 9% free, 77MB/85MB, paused 152us total 1.710s
04-26 15:15:40.743 12261 12272 I plete.test32ne: Background concurrent copying GC freed 678749(18MB) AllocSpace objects, 9(4MB) LOS objects, 6% free, 116MB/124MB, paused 1.159ms total 2.035s
04-26 15:15:44.446 12261 12272 I plete.test32ne: Background concurrent copying GC freed 263242(7MB) AllocSpace objects, 7(46MB) LOS objects, 8% free, 88MB/96MB, paused 305us total 1.819s
04-26 15:15:47.379 12261 12282 I plete.test32ne: Waiting for a blocking GC ProfileSaver
04-26 15:15:48.518 12261 12272 I plete.test32ne: Background concurrent copying GC freed 407421(8MB) AllocSpace objects, 13(26MB) LOS objects, 8% free, 90MB/98MB, paused 2.411ms total 1.955s
04-26 15:15:48.518 12261 12282 I plete.test32ne: WaitForGcToComplete blocked ProfileSaver on HeapTrim for 1.138s
04-26 15:15:50.955 12261 12272 I plete.test32ne: Background concurrent copying GC freed 1143838(32MB) AllocSpace objects, 0(0B) LOS objects, 8% free, 83MB/91MB, paused 244us total 1.904s
04-26 15:16:12.036 12261 12272 I plete.test32ne: Background concurrent copying GC freed 526552(18MB) AllocSpace objects, 3(60KB) LOS objects, 9% free, 73MB/81MB, paused 152us total 2.126s
04-26 15:16:17.809 12261 12272 I plete.test32ne: Background concurrent copying GC freed 487035(16MB) AllocSpace objects, 1(16KB) LOS objects, 6% free, 110MB/118MB, paused 5.829ms total 1.796s
04-26 15:16:28.721 12261 12282 I plete.test32ne: Waiting for a blocking GC ProfileSaver
04-26 15:16:29.837 12261 12272 I plete.test32ne: Background concurrent copying GC freed 815296(52MB) AllocSpace objects, 10(936KB) LOS objects, 10% free, 67MB/75MB, paused 152us total 1.829s
04-26 15:16:29.838 12261 12282 I plete.test32ne: WaitForGcToComplete blocked ProfileSaver on HeapTrim for 1.116s
04-26 15:16:36.394 12261 12272 I plete.test32ne: Background concurrent copying GC freed 339560(10MB) AllocSpace objects, 0(0B) LOS objects, 10% free, 69MB/77MB, paused 213us total 1.735s
04-26 15:16:41.842 12261 12272 I plete.test32ne: Background concurrent copying GC freed 129223(7MB) AllocSpace objects, 2(72KB) LOS objects, 8% free, 91MB/99MB, paused 152us total 2.226s
04-26 15:16:57.510 12261 12272 I plete.test32ne: Background concurrent copying GC freed 302684(11MB) AllocSpace objects, 0(0B) LOS objects, 8% free, 89MB/97MB, paused 366us total 2.966s
04-26 15:17:11.605 12261 12272 I plete.test32ne: Background concurrent copying GC freed 373125(8MB) AllocSpace objects, 0(0B) LOS objects, 8% free, 91MB/99MB, paused 1.159ms total 2.513s
04-26 15:17:24.930 12261 12272 I plete.test32ne: Background concurrent copying GC freed 337600(7MB) AllocSpace objects, 0(0B) LOS objects, 7% free, 93MB/101MB, paused 2.929ms total 2.709s
04-26 15:17:37.403 12261 12287 I MapDataController: Persisted 45077 and deleted 0 elements and geometries in 119.6s
04-26 15:17:38.172 12261 13127 D OsmQuestController: AddRoadName: Found 0 quests in 478ms
04-26 15:17:38.521 12261 13127 D OsmQuestController: AddOneway: Found 0 quests in 347ms
04-26 15:17:38.769 12261 13127 D OsmQuestController: AddPostboxCollectionTimes: Found 1 quests in 247ms
04-26 15:17:38.991 12261 14410 D OsmQuestController: AddPlaceName: Found 8 quests in 1259ms
04-26 15:17:38.998 12261 14410 D OsmQuestController: AddSuspectedOneway: Found 0 quests in 0ms
04-26 15:17:39.217 12261 14410 D OsmQuestController: AddBarrierType: Found 0 quests in 219ms
04-26 15:17:40.258 12261 13127 D OsmQuestController: CheckExistence: Found 29 quests in 1488ms
04-26 15:17:40.405 12261 14410 D OsmQuestController: AddCycleway: Found 10 quests in 1187ms
04-26 15:17:40.868 12261 14410 D OsmQuestController: AddBusStopName: Found 0 quests in 455ms
04-26 15:17:40.868 12261 14410 D OsmQuestController: AddBusStopRef: Skipped because it is disabled for this country
04-26 15:17:40.934 12261 14410 D OsmQuestController: AddIsBuildingUnderground: Found 1 quests in 65ms
04-26 15:17:40.935 12261 14410 D OsmQuestController: AddHousenumber: Found 0 quests in 0ms
04-26 15:17:41.095 12261 13127 D OsmQuestController: AddSidewalk: Found 27 quests in 835ms
04-26 15:17:41.285 12261 13127 D OsmQuestController: SpecifyShopType: Found 1 quests in 190ms
04-26 15:17:41.335 12261 14410 D OsmQuestController: AddAddressStreet: Found 26 quests in 396ms
04-26 15:17:41.352 12261 14410 D OsmQuestController: MarkCompletedHighwayConstruction: Found 3 quests in 17ms
04-26 15:17:41.397 12261 12272 I plete.test32ne: Background concurrent copying GC freed 1523974(32MB) AllocSpace objects, 0(0B) LOS objects, 6% free, 111MB/119MB, paused 274us total 3.878s
04-26 15:17:41.474 12261 13127 D OsmQuestController: CheckShopType: Found 1 quests in 189ms
04-26 15:17:41.519 12261 14410 D OsmQuestController: AddReligionToPlaceOfWorship: Found 0 quests in 166ms
04-26 15:17:41.585 12261 13127 D OsmQuestController: AddParkingAccess: Found 8 quests in 110ms
04-26 15:17:41.585 12261 13127 D OsmQuestController: AddRecyclingContainerMaterials: Found 0 quests in 0ms
04-26 15:17:41.633 12261 14410 D OsmQuestController: AddRecyclingType: Found 1 quests in 110ms
04-26 15:17:41.785 12261 13127 D OsmQuestController: AddSport: Found 1 quests in 200ms
04-26 15:17:41.934 12261 14410 D OsmQuestController: AddRoadSurface: Found 12 quests in 300ms
04-26 15:17:41.977 12261 13127 D OsmQuestController: AddMaxSpeed: Found 7 quests in 191ms
04-26 15:17:42.218 12261 13127 D OsmQuestController: AddLanes: Found 31 quests in 235ms
04-26 15:17:42.484 12261 13127 D OsmQuestController: AddRailwayCrossingBarrier: Found 1 quests in 266ms
04-26 15:17:44.643 12261 13127 D OsmQuestController: AddOpeningHours: Found 121 quests in 2158ms
04-26 15:17:44.849 12261 13127 D OsmQuestController: AddBikeParkingCapacity: Found 9 quests in 205ms
04-26 15:17:44.869 12261 13127 D OsmQuestController: AddOrchardProduce: Found 0 quests in 19ms
04-26 15:17:45.018 12261 13127 D OsmQuestController: AddBuildingType: Found 746 quests in 142ms
04-26 15:17:45.739 12261 12272 I plete.test32ne: Background concurrent copying GC freed 1670201(49MB) AllocSpace objects, 0(0B) LOS objects, 6% free, 117MB/125MB, paused 152us total 4.065s
04-26 15:17:46.618 12261 14410 D OsmQuestController: AddMaxHeight: Found 66 quests in 4684ms
04-26 15:17:46.757 12261 13127 D OsmQuestController: AddProhibitedForPedestrians: Found 0 quests in 1738ms
04-26 15:17:46.991 12261 13127 D OsmQuestController: AddCrossingIsland: Found 25 quests in 233ms
04-26 15:17:47.007 12261 14410 D OsmQuestController: AddCrossingType: Found 9 quests in 389ms
04-26 15:17:47.214 12261 13127 D OsmQuestController: AddBuildingLevels: Found 241 quests in 223ms
04-26 15:17:47.484 12261 14410 D OsmQuestController: AddBusStopShelter: Found 0 quests in 476ms
04-26 15:17:47.548 12261 13127 D OsmQuestController: AddVegetarian: Found 45 quests in 333ms
04-26 15:17:47.959 12261 14410 D OsmQuestController: AddVegan: Found 13 quests in 470ms
04-26 15:17:47.963 12261 13127 D OsmQuestController: AddInternetAccess: Found 10 quests in 414ms
04-26 15:17:48.155 12261 14410 D OsmQuestController: AddParkingFee: Found 8 quests in 195ms
04-26 15:17:48.193 12261 13127 D OsmQuestController: AddMotorcycleParkingCapacity: Found 0 quests in 229ms
04-26 15:17:48.235 12261 13127 D OsmQuestController: AddTracktype: Found 4 quests in 35ms
04-26 15:17:48.461 12261 13127 D OsmQuestController: AddMaxWeight: Found 0 quests in 225ms
04-26 15:17:48.551 12261 14410 D OsmQuestController: AddPathSurface: Found 197 quests in 395ms
04-26 15:17:48.789 12261 14410 D OsmQuestController: AddBikeParkingType: Found 2 quests in 237ms
04-26 15:17:49.069 12261 14410 D OsmQuestController: AddBikeParkingAccess: Found 0 quests in 280ms
04-26 15:17:49.102 12261 13127 D OsmQuestController: AddForestLeafType: Found 2 quests in 640ms
04-26 15:17:49.138 12261 13127 D OsmQuestController: AddStepsRamp: Found 45 quests in 35ms
04-26 15:17:49.261 12261 14410 D OsmQuestController: AddBikeParkingFee: Found 0 quests in 191ms
04-26 15:17:49.301 12261 13127 D OsmQuestController: AddWheelchairAccessToilets: Found 4 quests in 163ms
04-26 15:17:49.417 12261 14410 D OsmQuestController: AddPlaygroundAccess: Found 5 quests in 155ms
04-26 15:17:49.944 12261 14410 D OsmQuestController: AddToiletAvailability: Found 3 quests in 526ms
04-26 15:17:49.966 12261 14410 D OsmQuestController: AddFerryAccessPedestrian: Found 0 quests in 21ms
04-26 15:17:50.005 12261 14410 D OsmQuestController: AddFerryAccessMotorVehicle: Found 0 quests in 38ms
04-26 15:17:50.013 12261 14410 D OsmQuestController: AddAcceptsCash: Skipped because it is disabled for this country
04-26 15:17:50.114 12261 13127 D OsmQuestController: AddWheelchairAccessBusiness: Found 89 quests in 812ms
04-26 15:17:50.155 12261 14410 D OsmQuestController: DetermineRecyclingGlass: Found 0 quests in 142ms
04-26 15:17:50.290 12261 14410 D OsmQuestController: AddToiletsFee: Found 5 quests in 135ms
04-26 15:17:50.903 12261 14410 D OsmQuestController: AddBabyChangingTable: Found 15 quests in 612ms
04-26 15:17:50.959 12261 13127 D OsmQuestController: AddWayLit: Found 108 quests in 845ms
04-26 15:17:51.260 12261 14410 D OsmQuestController: AddBikeParkingCover: Found 5 quests in 356ms
04-26 15:17:51.321 12261 13127 D OsmQuestController: AddDrinkingWater: Found 0 quests in 361ms
04-26 15:17:51.816 12261 14410 D OsmQuestController: AddTactilePavingCrosswalk: Found 17 quests in 555ms
04-26 15:17:52.787 12261 13127 D OsmQuestController: AddTactilePavingKerb: Found 0 quests in 1466ms
04-26 15:17:52.810 12261 14410 D OsmQuestController: AddKerbHeight: Found 0 quests in 994ms
04-26 15:17:52.987 12261 13127 D OsmQuestController: AddTrafficSignalsSound: Found 15 quests in 200ms
04-26 15:17:52.991 12261 14410 D OsmQuestController: AddTrafficSignalsVibration: Found 52 quests in 180ms
04-26 15:17:53.372 12261 13127 D OsmQuestController: AddRoofShape: Found 138 quests in 384ms
04-26 15:17:53.418 12261 14410 D OsmQuestController: AddWheelchairAccessPublicTransport: Found 0 quests in 427ms
04-26 15:17:53.584 12261 13127 D OsmQuestController: AddWheelchairAccessOutside: Found 0 quests in 212ms
04-26 15:17:53.607 12261 13127 D OsmQuestController: AddBridgeStructure: Found 7 quests in 22ms
04-26 15:17:53.805 12261 14410 D OsmQuestController: AddTactilePavingBusStop: Found 5 quests in 386ms
04-26 15:17:53.919 12261 14410 D OsmQuestController: AddCyclewaySegregation: Found 2 quests in 114ms
04-26 15:17:53.920 12261 13127 D OsmQuestController: AddReligionToWaysideShrine: Found 0 quests in 308ms
04-26 15:17:53.941 12261 14410 D OsmQuestController: MarkCompletedBuildingConstruction: Found 2 quests in 22ms
04-26 15:17:54.122 12261 14410 D OsmQuestController: AddSelfServiceLaundry: Found 0 quests in 180ms
04-26 15:17:54.150 12261 14410 D OsmQuestController: AddStepsIncline: Found 23 quests in 28ms
04-26 15:17:54.191 12261 14410 D OsmQuestController: AddHandrail: Found 21 quests in 41ms
04-26 15:17:54.251 12261 14410 D OsmQuestController: AddStepCount: Found 49 quests in 60ms
04-26 15:17:54.268 12261 13127 D OsmQuestController: AddGeneralFee: Found 0 quests in 348ms
04-26 15:17:54.419 12261 13127 D OsmQuestController: AddAtmOperator: Found 7 quests in 151ms
04-26 15:17:54.463 12261 14410 D OsmQuestController: AddInformationToTourism: Found 0 quests in 212ms
04-26 15:17:54.619 12261 13127 D OsmQuestController: AddChargingStationCapacity: Found 9 quests in 200ms
04-26 15:17:54.656 12261 14410 D OsmQuestController: AddChargingStationOperator: Found 0 quests in 193ms
04-26 15:17:54.774 12261 13127 D OsmQuestController: AddClothingBinOperator: Found 1 quests in 155ms
04-26 15:17:54.919 12261 13127 D OsmQuestController: AddStileType: Found 0 quests in 137ms
04-26 15:17:54.985 12261 13127 D OsmQuestController: AddPitchSurface: Found 15 quests in 64ms
04-26 15:17:55.006 12261 12272 I plete.test32ne: Background concurrent copying GC freed 1952452(59MB) AllocSpace objects, 0(0B) LOS objects, 6% free, 123MB/131MB, paused 244us total 208.283ms
04-26 15:17:55.028 12261 13127 D OsmQuestController: AddPitchLit: Found 31 quests in 43ms
04-26 15:17:55.048 12261 14410 D OsmQuestController: AddKosher: Found 70 quests in 392ms
04-26 15:17:55.129 12261 14410 D OsmQuestController: AddSummitRegister: Found 0 quests in 81ms
04-26 15:17:55.132 12261 13127 D OsmQuestController: AddIsDefibrillatorIndoor: Found 10 quests in 104ms
04-26 15:17:55.218 12261 13127 D OsmQuestController: AddFootwayPartSurface: Found 1 quests in 86ms
04-26 15:17:55.303 12261 14410 D OsmQuestController: AddCyclewayPartSurface: Found 1 quests in 171ms
04-26 15:17:55.338 12261 13127 D OsmQuestController: AddMotorcycleParkingCover: Found 0 quests in 118ms
04-26 15:17:55.485 12261 14410 D OsmQuestController: AddFireHydrantType: Found 0 quests in 182ms
04-26 15:17:55.596 12261 13127 D OsmQuestController: AddParkingType: Found 4 quests in 258ms
04-26 15:17:55.769 12261 14410 D OsmQuestController: AddPostboxRef: Found 0 quests in 284ms
04-26 15:17:55.934 12261 13127 D OsmQuestController: AddWheelchairAccessToiletsPart: Found 0 quests in 338ms
04-26 15:17:55.935 12261 13127 D OsmQuestController: AddPoliceType: Skipped because it is disabled for this country
04-26 15:17:56.098 12261 14410 D OsmQuestController: AddBoardType: Found 14 quests in 328ms
04-26 15:17:56.239 12261 13127 D OsmQuestController: AddPowerPolesMaterial: Found 0 quests in 304ms
04-26 15:17:56.285 12261 14410 D OsmQuestController: AddCarWashType: Found 2 quests in 185ms
04-26 15:17:56.454 12261 14410 D OsmQuestController: AddBenchBackrest: Found 18 quests in 169ms
04-26 15:17:56.647 12261 13127 D OsmQuestController: AddBenchStatusOnBusStop: Found 57 quests in 407ms
04-26 15:17:56.648 12261 13127 D OsmQuestController: AddPostboxRoyalCypher: Skipped because it is disabled for this country
04-26 15:17:56.649 12261 14410 D OsmQuestController: AddTrafficSignalsButton: Found 3 quests in 195ms
04-26 15:17:56.655 12261 12287 I OsmQuestController: Created 2519 quests for bbox in 19.0s
04-26 15:17:57.736 12261 12287 I OsmQuestController: Persisted 2519 new and removed 0 already resolved quests in 1.1s
04-26 15:17:58.451 12261 12272 I plete.test32ne: Background concurrent copying GC freed 1958634(59MB) AllocSpace objects, 0(0B) LOS objects, 8% free, 87MB/95MB, paused 1.617ms total 3.054s
04-26 15:18:02.255 12261 12272 I plete.test32ne: Background concurrent copying GC freed 820318(25MB) AllocSpace objects, 4(5MB) LOS objects, 9% free, 73MB/81MB, paused 335us total 2.353s
04-26 15:18:05.304 12261 12272 I plete.test32ne: Background concurrent copying GC freed 482457(16MB) AllocSpace objects, 0(0B) LOS objects, 9% free, 74MB/82MB, paused 732us total 1.904s
04-26 15:18:07.424 12261 12282 I plete.test32ne: Waiting for a blocking GC ProfileSaver
04-26 15:18:08.281 12261 14410 I Download: Finished download (48.1770756, 16.4025879 -> 48.1953874, 16.4355469) in 172.3s
04-26 15:18:08.283 12261 14410 I QuestAutoSyncer: Checking whether to automatically download new quests at 48.1855096,16.4193801
04-26 15:18:08.299 12261 12287 I AutoQuestDownload: All downloaded in radius of 915 meters around user
04-26 15:18:08.502 12261 12272 I plete.test32ne: Background concurrent copying GC freed 492319(17MB) AllocSpace objects, 0(0B) LOS objects, 10% free, 71MB/79MB, paused 152us total 1.992s
04-26 15:18:08.502 12261 12282 I plete.test32ne: WaitForGcToComplete blocked ProfileSaver on HeapTrim for 1.077s
04-26 15:18:21.519 12261 13812 W plete.test32ne: Long monitor contention with owner GLThread 943 (12326) at int com.mapzen.tangram.NativeMap.render(float)(NativeMap.java:-2) waiters=0 in boolean com.mapzen.tangram.NativeMap.markerSetVisible(long, boolean) for 157ms
04-26 15:18:26.954 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:18:26.956 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:18:27.899 12261 14410 D QuestController: Solved a AddBuildingType quest: MODIFY "building"="yes" -> "building"="detached"
04-26 15:18:27.928 12261 12317 D OpenGLRenderer: endAllActiveAnimators on 0x94465e00 (RippleDrawable) with handle 0x923257a0
04-26 15:18:28.015 12261 12287 D OsmQuestController: AddHousenumber requires surrounding map data to determine applicability to WAY#846977295
04-26 15:18:30.927 12261 12287 W CursorWindow: Window is full: requested allocation 60 bytes, free space 47 bytes, window size 2097152 bytes
04-26 15:18:36.184 12261 12287 W CursorWindow: Window is full: requested allocation 60 bytes, free space 55 bytes, window size 2097152 bytes
04-26 15:18:37.172 12261 12272 I plete.test32ne: Background concurrent copying GC freed 1225959(35MB) AllocSpace objects, 8(288KB) LOS objects, 15% free, 44MB/52MB, paused 183us total 968.808ms
04-26 15:18:40.412 12261 12287 W CursorWindow: Window is full: requested allocation 60 bytes, free space 3 bytes, window size 2097152 bytes
04-26 15:18:44.602 12261 12287 W CursorWindow: Window is full: requested allocation 60 bytes, free space 47 bytes, window size 2097152 bytes
04-26 15:18:48.741 12261 12287 W CursorWindow: Window is full: requested allocation 60 bytes, free space 39 bytes, window size 2097152 bytes
04-26 15:18:53.147 12261 12287 W CursorWindow: Window is full: requested allocation 60 bytes, free space 19 bytes, window size 2097152 bytes
04-26 15:18:55.275 12261 12272 I plete.test32ne: Background concurrent copying GC freed 704429(18MB) AllocSpace objects, 0(0B) LOS objects, 18% free, 34MB/42MB, paused 4.883ms total 1.168s
04-26 15:18:57.790 12261 12287 W CursorWindow: Window is full: requested allocation 60 bytes, free space 27 bytes, window size 2097152 bytes
04-26 15:19:02.388 12261 12287 W CursorWindow: Window is full: requested allocation 60 bytes, free space 7 bytes, window size 2097152 bytes
04-26 15:19:07.288 12261 12287 W CursorWindow: Window is full: requested allocation 60 bytes, free space 19 bytes, window size 2097152 bytes
04-26 15:19:11.088 12261 12287 I MapDataController: Fetched 138 elements and geometries in 43062ms
04-26 15:19:11.246 12261 14410 D OsmQuestController: Created AddHousenumber for WAY#846977295
04-26 15:19:11.246 12261 14410 D OsmQuestController: Created AddBuildingLevels for WAY#846977295
04-26 15:19:11.247 12261 14410 I OsmQuestController: Created 2 quests for 1 updated elements in 43.3s
04-26 15:19:11.250 12261 14410 I OsmQuestController: Persisted 2 new and removed 1 already resolved quests in 0.0s
04-26 15:19:12.367 12261 12272 I plete.test32ne: Background concurrent copying GC freed 376257(13MB) AllocSpace objects, 0(0B) LOS objects, 20% free, 30MB/38MB, paused 122us total 1.089s
04-26 15:19:16.150 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:19:16.151 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:19:17.078 12261 14590 D QuestController: Solved a AddCrossingType quest: ADD "crossing"="marked"
04-26 15:19:17.080 12261 12317 D OpenGLRenderer: endAllActiveAnimators on 0x8d103380 (RippleDrawable) with handle 0xabaa84a0
04-26 15:19:17.183 12261 12287 D OsmQuestController: AddCrossingIsland requires surrounding map data to determine applicability to NODE#706464955
04-26 15:19:17.216 12261 14410 D OsmQuestController: AddTactilePavingCrosswalk requires surrounding map data to determine applicability to NODE#706464955
04-26 15:19:19.470 12261 14665 W CursorWindow: Window is full: requested allocation 60 bytes, free space 47 bytes, window size 2097152 bytes
04-26 15:19:24.679 12261 14665 W CursorWindow: Window is full: requested allocation 60 bytes, free space 55 bytes, window size 2097152 bytes
04-26 15:19:27.272 12261 12272 I plete.test32ne: Background concurrent copying GC freed 223190(6MB) AllocSpace objects, 6(244KB) LOS objects, 20% free, 31MB/39MB, paused 396us total 1.097s
04-26 15:19:28.853 12261 14665 W CursorWindow: Window is full: requested allocation 60 bytes, free space 3 bytes, window size 2097152 bytes
04-26 15:19:33.042 12261 14665 W CursorWindow: Window is full: requested allocation 60 bytes, free space 47 bytes, window size 2097152 bytes
04-26 15:19:37.266 12261 14665 W CursorWindow: Window is full: requested allocation 60 bytes, free space 39 bytes, window size 2097152 bytes
04-26 15:19:41.810 12261 14665 W CursorWindow: Window is full: requested allocation 60 bytes, free space 19 bytes, window size 2097152 bytes
04-26 15:19:46.445 12261 14665 W CursorWindow: Window is full: requested allocation 60 bytes, free space 27 bytes, window size 2097152 bytes
04-26 15:19:47.561 12261 12272 I plete.test32ne: Background concurrent copying GC freed 206209(5MB) AllocSpace objects, 0(0B) LOS objects, 18% free, 34MB/42MB, paused 122us total 1.093s
04-26 15:19:51.130 12261 14665 W CursorWindow: Window is full: requested allocation 4 bytes, free space 0 bytes, window size 2097152 bytes
04-26 15:19:55.874 12261 14665 W CursorWindow: Window is full: requested allocation 60 bytes, free space 7 bytes, window size 2097152 bytes
04-26 15:20:00.494 12261 14665 I MapDataController: Fetched 134 elements and geometries in 43310ms
04-26 15:20:00.495 12261 13127 W plete.test32ne: Long monitor contention with owner DefaultDispatcher-worker-6 (14665) at java.util.HashMap$Node java.util.HashMap.getNode(int, java.lang.Object)(HashMap.java:568) waiters=0 in java.util.List de.westnordost.streetcomplete.data.osm.edits.MapDataWithEditsSource.getGeometries(java.util.Collection) for 3.227s
04-26 15:20:00.502 12261 14410 W plete.test32ne: Long monitor contention with owner DefaultDispatcher-worker-6 (14665) at long android.database.sqlite.SQLiteConnection.nativeExecuteForCursorWindow(long, long, long, int, int, boolean)(SQLiteConnection.java:-2) waiters=0 in java.lang.Object kotlin.SynchronizedLazyImpl.getValue() for 43.285s
04-26 15:20:00.511 12261 14590 D OsmQuestController: Created AddCrossingIsland for NODE#706464955
04-26 15:20:00.511 12261 14590 D OsmQuestController: Created AddTactilePavingCrosswalk for NODE#706464955
04-26 15:20:00.512 12261 14590 I OsmQuestController: Created 2 quests for 1 updated elements in 43.4s
04-26 15:20:00.785 12261 14664 W plete.test32ne: Long monitor contention with owner DefaultDispatcher-worker-6 (14665) at java.util.HashMap$Node java.util.HashMap.getNode(int, java.lang.Object)(HashMap.java:568) waiters=1 in java.util.List de.westnordost.streetcomplete.data.osm.edits.MapDataWithEditsSource.getGeometries(java.util.Collection) for 534ms
04-26 15:20:00.788 12261 14590 I OsmQuestController: Persisted 2 new and removed 1 already resolved quests in 0.3s
04-26 15:20:02.630 12261 12272 I plete.test32ne: Background concurrent copying GC freed 189159(5MB) AllocSpace objects, 11(388KB) LOS objects, 15% free, 42MB/50MB, paused 122us total 2.216s
04-26 15:20:11.240 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:20:11.242 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:20:11.874 12261 14590 D QuestController: Solved a AddBuildingType quest: MODIFY "building"="yes" -> "building"="detached"
04-26 15:20:11.907 12261 12317 D OpenGLRenderer: endAllActiveAnimators on 0x91224980 (RippleDrawable) with handle 0x94e3de90
04-26 15:20:11.983 12261 14664 D OsmQuestController: AddHousenumber requires surrounding map data to determine applicability to WAY#276458683
04-26 15:20:12.265 12261 14664 I MapDataController: Fetched 52 elements and geometries in 282ms
04-26 15:20:12.300 12261 14590 D OsmQuestController: Created AddHousenumber for WAY#276458683
04-26 15:20:12.300 12261 14590 D OsmQuestController: Created AddBuildingLevels for WAY#276458683
04-26 15:20:12.301 12261 14590 I OsmQuestController: Created 2 quests for 1 updated elements in 0.3s
04-26 15:20:12.311 12261 14590 I OsmQuestController: Persisted 2 new and removed 1 already resolved quests in 0.0s
04-26 15:20:12.779 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:20:12.780 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:20:13.867 12261 12317 D OpenGLRenderer: endAllActiveAnimators on 0x8d5c5980 (RippleDrawable) with handle 0x911ef4a0
04-26 15:20:19.899 12261 12272 I plete.test32ne: Background concurrent copying GC freed 552048(20MB) AllocSpace objects, 15(544KB) LOS objects, 20% free, 31MB/39MB, paused 6.531ms total 1.319s
04-26 15:20:25.491 12261 14778 E Tangram : Error reading bytes from response body:stream was reset: CANCEL
04-26 15:20:25.647 12261 14776 E Tangram : Error reading bytes from response body:stream was reset: CANCEL
04-26 15:20:30.564 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:20:30.565 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:20:31.424 12261 12287 I Download: Starting download (48.2100321, 16.3641357 -> 48.2136926, 16.3696289)
04-26 15:20:31.589 12261 15006 V MapTilesDownload: Tile 14/8936/5680 in cache
04-26 15:20:31.590 12261 15008 V MapTilesDownload: Tile 15/17873/11361 in cache
04-26 15:20:31.596 12261 15003 V MapTilesDownload: Tile 16/35747/22723 in cache
04-26 15:20:31.600 12261 15009 V MapTilesDownload: Tile 12/2234/1420 in cache
04-26 15:20:31.639 12261 15009 V MapTilesDownload: Tile 8/139/88 in cache
04-26 15:20:31.649 12261 15006 V MapTilesDownload: Tile 11/1117/710 in cache
04-26 15:20:31.661 12261 15012 V MapTilesDownload: Tile 10/558/355 in cache
04-26 15:20:31.673 12261 15013 V MapTilesDownload: Tile 9/279/177 in cache
04-26 15:20:31.678 12261 15003 V MapTilesDownload: Tile 7/69/44 in cache
04-26 15:20:31.691 12261 15009 V MapTilesDownload: Tile 6/34/22 in cache
04-26 15:20:31.735 12261 15006 V MapTilesDownload: Tile 5/17/11 in cache
04-26 15:20:31.737 12261 15009 V MapTilesDownload: Tile 1/1/0 in cache
04-26 15:20:31.747 12261 15003 V MapTilesDownload: Tile 3/4/2 in cache
04-26 15:20:31.763 12261 15012 V MapTilesDownload: Tile 4/8/5 in cache
04-26 15:20:31.782 12261 15008 V MapTilesDownload: Tile 0/0/0 in cache
04-26 15:20:31.788 12261 15013 V MapTilesDownload: Tile 2/2/1 in cache
04-26 15:20:31.830 12261 14786 I NotesDownload: Downloaded 8 notes in 0.4s
04-26 15:20:31.897 12261 14786 I NoteController: Persisted 8 and deleted 0 notes in 0.1s
04-26 15:20:31.909 12261 15007 V MapTilesDownload: Tile 13/4468/2840 downloaded
04-26 15:20:31.911 12261 15005 I MapTilesDownload: Downloaded 17 tiles (102kB downloaded, 1004kB already cached) in 0.5s
04-26 15:20:32.061 12261 14786 I OsmAvatarsDownload: Downloaded 3 avatar images in 0.2s
04-26 15:20:32.862 12261 12272 I plete.test32ne: Background concurrent copying GC freed 204385(9MB) AllocSpace objects, 32(1928KB) LOS objects, 19% free, 33MB/41MB, paused 1.098ms total 1.196s
04-26 15:20:33.164 12261 14590 I MapDataDownload: Downloaded 3834 nodes, 426 ways and 95 relations in 1.7s
04-26 15:20:36.063 12261 12272 I plete.test32ne: Background concurrent copying GC freed 390196(10MB) AllocSpace objects, 18(688KB) LOS objects, 18% free, 34MB/42MB, paused 244us total 982.542ms
04-26 15:20:37.348 12261 14590 I MapDataController: Persisted 4351 and deleted 3 elements and geometries in 4.2s
04-26 15:20:37.390 12261 15005 D OsmQuestController: AddRoadName: Found 0 quests in 6ms
04-26 15:20:37.411 12261 15005 D OsmQuestController: AddOneway: Found 0 quests in 21ms
04-26 15:20:37.425 12261 15005 D OsmQuestController: AddPostboxCollectionTimes: Found 3 quests in 13ms
04-26 15:20:37.475 12261 14786 D OsmQuestController: AddPlaceName: Found 3 quests in 92ms
04-26 15:20:37.475 12261 14786 D OsmQuestController: AddSuspectedOneway: Found 0 quests in 0ms
04-26 15:20:37.489 12261 14786 D OsmQuestController: AddBarrierType: Found 0 quests in 13ms
04-26 15:20:37.541 12261 14786 D OsmQuestController: AddCycleway: Found 0 quests in 52ms
04-26 15:20:37.542 12261 15005 D OsmQuestController: CheckExistence: Found 8 quests in 117ms
04-26 15:20:37.566 12261 15005 D OsmQuestController: AddBusStopName: Found 0 quests in 24ms
04-26 15:20:37.566 12261 15005 D OsmQuestController: AddBusStopRef: Skipped because it is disabled for this country
04-26 15:20:37.570 12261 15005 D OsmQuestController: AddIsBuildingUnderground: Found 1 quests in 2ms
04-26 15:20:37.570 12261 15005 D OsmQuestController: AddHousenumber: Found 0 quests in 0ms
04-26 15:20:37.570 12261 14786 D OsmQuestController: AddSidewalk: Found 19 quests in 29ms
04-26 15:20:37.580 12261 14786 D OsmQuestController: SpecifyShopType: Found 1 quests in 10ms
04-26 15:20:37.587 12261 15005 D OsmQuestController: AddAddressStreet: Found 0 quests in 17ms
04-26 15:20:37.589 12261 15005 D OsmQuestController: MarkCompletedHighwayConstruction: Found 0 quests in 2ms
04-26 15:20:37.593 12261 14786 D OsmQuestController: CheckShopType: Found 0 quests in 13ms
04-26 15:20:37.606 12261 14786 D OsmQuestController: AddParkingAccess: Found 0 quests in 13ms
04-26 15:20:37.607 12261 15005 D OsmQuestController: AddReligionToPlaceOfWorship: Found 0 quests in 17ms
04-26 15:20:37.607 12261 14786 D OsmQuestController: AddRecyclingContainerMaterials: Found 0 quests in 0ms
04-26 15:20:37.614 12261 14786 D OsmQuestController: AddSport: Found 0 quests in 7ms
04-26 15:20:37.614 12261 15005 D OsmQuestController: AddRecyclingType: Found 0 quests in 7ms
04-26 15:20:37.628 12261 15005 D OsmQuestController: AddMaxSpeed: Found 0 quests in 13ms
04-26 15:20:37.648 12261 14786 D OsmQuestController: AddRoadSurface: Found 24 quests in 34ms
04-26 15:20:37.675 12261 14786 D OsmQuestController: AddLanes: Found 0 quests in 26ms
04-26 15:20:37.690 12261 15005 D OsmQuestController: AddMaxHeight: Found 2 quests in 62ms
04-26 15:20:37.728 12261 14786 D OsmQuestController: AddRailwayCrossingBarrier: Found 0 quests in 53ms
04-26 15:20:37.765 12261 14786 D OsmQuestController: AddBikeParkingCapacity: Found 2 quests in 37ms
04-26 15:20:37.774 12261 14786 D OsmQuestController: AddOrchardProduce: Found 0 quests in 9ms
04-26 15:20:37.781 12261 14786 D OsmQuestController: AddBuildingType: Found 103 quests in 6ms
04-26 15:20:37.874 12261 14786 D OsmQuestController: AddProhibitedForPedestrians: Found 0 quests in 93ms
04-26 15:20:37.925 12261 14786 D OsmQuestController: AddCrossingType: Found 4 quests in 51ms
04-26 15:20:37.949 12261 14786 D OsmQuestController: AddCrossingIsland: Found 4 quests in 24ms
04-26 15:20:37.973 12261 14786 D OsmQuestController: AddBuildingLevels: Found 4 quests in 23ms
04-26 15:20:38.048 12261 14786 D OsmQuestController: AddBusStopShelter: Found 1 quests in 75ms
04-26 15:20:38.107 12261 14786 D OsmQuestController: AddVegetarian: Found 38 quests in 58ms
04-26 15:20:38.199 12261 14786 D OsmQuestController: AddVegan: Found 1 quests in 87ms
04-26 15:20:38.270 12261 14786 D OsmQuestController: AddInternetAccess: Found 9 quests in 70ms
04-26 15:20:38.305 12261 14786 D OsmQuestController: AddParkingFee: Found 1 quests in 34ms
04-26 15:20:38.329 12261 15005 D OsmQuestController: AddOpeningHours: Found 104 quests in 638ms
04-26 15:20:38.344 12261 15005 D OsmQuestController: AddPathSurface: Found 28 quests in 14ms
04-26 15:20:38.346 12261 15005 D OsmQuestController: AddTracktype: Found 0 quests in 2ms
04-26 15:20:38.353 12261 14786 D OsmQuestController: AddMotorcycleParkingCapacity: Found 0 quests in 48ms
04-26 15:20:38.357 12261 15005 D OsmQuestController: AddMaxWeight: Found 1 quests in 11ms
04-26 15:20:38.374 12261 14786 D OsmQuestController: AddForestLeafType: Found 0 quests in 21ms
04-26 15:20:38.386 12261 15005 D OsmQuestController: AddBikeParkingType: Found 7 quests in 28ms
04-26 15:20:38.406 12261 14786 D OsmQuestController: AddBikeParkingAccess: Found 0 quests in 31ms
04-26 15:20:38.409 12261 14786 D OsmQuestController: AddStepsRamp: Found 4 quests in 2ms
04-26 15:20:38.410 12261 15005 D OsmQuestController: AddBikeParkingFee: Found 0 quests in 20ms
04-26 15:20:38.441 12261 14786 D OsmQuestController: AddWheelchairAccessToilets: Found 0 quests in 32ms
04-26 15:20:38.444 12261 15005 D OsmQuestController: AddPlaygroundAccess: Found 0 quests in 33ms
04-26 15:20:38.531 12261 15005 D OsmQuestController: AddToiletAvailability: Found 1 quests in 86ms
04-26 15:20:38.547 12261 15005 D OsmQuestController: AddFerryAccessPedestrian: Found 0 quests in 16ms
04-26 15:20:38.549 12261 15005 D OsmQuestController: AddFerryAccessMotorVehicle: Found 0 quests in 2ms
04-26 15:20:38.553 12261 15005 D OsmQuestController: AddAcceptsCash: Skipped because it is disabled for this country
04-26 15:20:38.597 12261 15005 D OsmQuestController: DetermineRecyclingGlass: Found 0 quests in 43ms
04-26 15:20:38.613 12261 14786 D OsmQuestController: AddWheelchairAccessBusiness: Found 93 quests in 172ms
04-26 15:20:38.661 12261 14786 D OsmQuestController: AddToiletsFee: Found 2 quests in 48ms
04-26 15:20:38.669 12261 15005 D OsmQuestController: AddWayLit: Found 38 quests in 71ms
04-26 15:20:38.712 12261 15005 D OsmQuestController: AddBikeParkingCover: Found 2 quests in 42ms
04-26 15:20:38.748 12261 14786 D OsmQuestController: AddBabyChangingTable: Found 2 quests in 87ms
04-26 15:20:38.748 12261 15005 D OsmQuestController: AddDrinkingWater: Found 0 quests in 36ms
04-26 15:20:38.808 12261 14786 D OsmQuestController: AddTactilePavingCrosswalk: Found 12 quests in 60ms
04-26 15:20:38.847 12261 15005 D OsmQuestController: AddTactilePavingKerb: Found 0 quests in 98ms
04-26 15:20:38.863 12261 14786 D OsmQuestController: AddKerbHeight: Found 0 quests in 55ms
04-26 15:20:38.874 12261 15005 D OsmQuestController: AddTrafficSignalsSound: Found 1 quests in 26ms
04-26 15:20:38.894 12261 14786 D OsmQuestController: AddTrafficSignalsVibration: Found 1 quests in 31ms
04-26 15:20:38.898 12261 15005 D OsmQuestController: AddRoofShape: Found 2 quests in 23ms
04-26 15:20:38.929 12261 15005 D OsmQuestController: AddWheelchairAccessOutside: Found 0 quests in 31ms
04-26 15:20:38.977 12261 14786 D OsmQuestController: AddWheelchairAccessPublicTransport: Found 0 quests in 82ms
04-26 15:20:38.980 12261 14786 D OsmQuestController: AddBridgeStructure: Found 0 quests in 2ms
04-26 15:20:38.989 12261 15005 D OsmQuestController: AddTactilePavingBusStop: Found 3 quests in 60ms
04-26 15:20:39.000 12261 15005 D OsmQuestController: AddCyclewaySegregation: Found 0 quests in 11ms
04-26 15:20:39.004 12261 15005 D OsmQuestController: MarkCompletedBuildingConstruction: Found 0 quests in 2ms
04-26 15:20:39.006 12261 14786 D OsmQuestController: AddReligionToWaysideShrine: Found 0 quests in 25ms
04-26 15:20:39.029 12261 14786 D OsmQuestController: AddSelfServiceLaundry: Found 0 quests in 23ms
04-26 15:20:39.031 12261 14786 D OsmQuestController: AddStepsIncline: Found 0 quests in 1ms
04-26 15:20:39.042 12261 15005 D OsmQuestController: AddGeneralFee: Found 2 quests in 37ms
04-26 15:20:39.043 12261 14786 D OsmQuestController: AddHandrail: Found 2 quests in 12ms
04-26 15:20:39.045 12261 15005 D OsmQuestController: AddStepCount: Found 1 quests in 3ms
04-26 15:20:39.065 12261 14786 D OsmQuestController: AddInformationToTourism: Found 0 quests in 22ms
04-26 15:20:39.072 12261 15005 D OsmQuestController: AddAtmOperator: Found 0 quests in 27ms
04-26 15:20:39.097 12261 14786 D OsmQuestController: AddChargingStationCapacity: Found 1 quests in 32ms
04-26 15:20:39.100 12261 15005 D OsmQuestController: AddChargingStationOperator: Found 0 quests in 24ms
04-26 15:20:39.112 12261 14786 D OsmQuestController: AddClothingBinOperator: Found 0 quests in 15ms
04-26 15:20:39.128 12261 14786 D OsmQuestController: AddStileType: Found 0 quests in 16ms
04-26 15:20:39.131 12261 14786 D OsmQuestController: AddPitchSurface: Found 0 quests in 2ms
04-26 15:20:39.137 12261 14786 D OsmQuestController: AddPitchLit: Found 0 quests in 6ms
04-26 15:20:39.157 12261 14786 D OsmQuestController: AddIsDefibrillatorIndoor: Found 0 quests in 19ms
04-26 15:20:39.169 12261 15005 D OsmQuestController: AddKosher: Found 41 quests in 67ms
04-26 15:20:39.174 12261 14786 D OsmQuestController: AddSummitRegister: Found 0 quests in 17ms
04-26 15:20:39.181 12261 15005 D OsmQuestController: AddCyclewayPartSurface: Found 0 quests in 12ms
04-26 15:20:39.187 12261 14786 D OsmQuestController: AddFootwayPartSurface: Found 0 quests in 12ms
04-26 15:20:39.199 12261 15005 D OsmQuestController: AddMotorcycleParkingCover: Found 0 quests in 18ms
04-26 15:20:39.212 12261 14786 D OsmQuestController: AddFireHydrantType: Found 0 quests in 24ms
04-26 15:20:39.227 12261 14786 D OsmQuestController: AddPostboxRef: Found 0 quests in 14ms
04-26 15:20:39.230 12261 15005 D OsmQuestController: AddParkingType: Found 0 quests in 27ms
04-26 15:20:39.245 12261 15005 D OsmQuestController: AddBoardType: Found 0 quests in 14ms
04-26 15:20:39.245 12261 15005 D OsmQuestController: AddPoliceType: Skipped because it is disabled for this country
04-26 15:20:39.254 12261 14786 D OsmQuestController: AddWheelchairAccessToiletsPart: Found 0 quests in 22ms
04-26 15:20:39.260 12261 15005 D OsmQuestController: AddPowerPolesMaterial: Found 0 quests in 15ms
04-26 15:20:39.275 12261 14786 D OsmQuestController: AddCarWashType: Found 0 quests in 21ms
04-26 15:20:39.289 12261 15005 D OsmQuestController: AddBenchStatusOnBusStop: Found 1 quests in 29ms
04-26 15:20:39.290 12261 14786 D OsmQuestController: AddBenchBackrest: Found 5 quests in 15ms
04-26 15:20:39.290 12261 14786 D OsmQuestController: AddPostboxRoyalCypher: Skipped because it is disabled for this country
04-26 15:20:39.304 12261 15005 D OsmQuestController: AddTrafficSignalsButton: Found 1 quests in 15ms
04-26 15:20:39.306 12261 14590 I OsmQuestController: Created 583 quests for bbox in 1.9s
04-26 15:20:39.438 12261 14590 I OsmQuestController: Persisted 583 new and removed 0 already resolved quests in 0.1s
04-26 15:20:39.532 12261 12272 I plete.test32ne: Background concurrent copying GC freed 300388(12MB) AllocSpace objects, 1(20KB) LOS objects, 14% free, 48MB/56MB, paused 152us total 1.891s
04-26 15:20:41.428 12261 15005 I Download: Finished download (48.2100321, 16.3641357 -> 48.2136926, 16.3696289) in 10.0s
04-26 15:20:41.430 12261 15005 I QuestAutoSyncer: Checking whether to automatically download new quests at 48.1855096,16.4193801
04-26 15:20:41.441 12261 15005 I AutoQuestDownload: All downloaded in radius of 908 meters around user
04-26 15:20:41.672 12261 12272 I plete.test32ne: Background concurrent copying GC freed 668616(22MB) AllocSpace objects, 134(2MB) LOS objects, 19% free, 33MB/41MB, paused 274us total 992.156ms
04-26 15:20:50.826 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:20:50.828 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:20:51.620 12261 15005 D QuestController: Solved a AddBuildingType quest: MODIFY "building"="yes" -> "building"="detached"
04-26 15:20:51.714 12261 14786 D OsmQuestController: AddHousenumber requires surrounding map data to determine applicability to WAY#185548131
04-26 15:20:51.877 12261 14786 I MapDataController: Fetched 96 elements and geometries in 163ms
04-26 15:20:51.888 12261 15005 D OsmQuestController: Created AddBuildingLevels for WAY#185548131
04-26 15:20:51.888 12261 15005 I OsmQuestController: Created 1 quests for 1 updated elements in 0.2s
04-26 15:20:52.050 12261 15005 I OsmQuestController: Persisted 1 new and removed 1 already resolved quests in 0.2s
04-26 15:20:56.280 12261 12261 I QuestAutoSyncer: Checking whether to automatically download new quests at 48.1855096,16.4193801
04-26 15:20:56.315 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:20:56.317 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:20:56.323 12261 12326 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:20:56.324 12261 12326 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:20:56.325 12261 12326 D Tangram : TANGRAM map.cpp:210: resize: 540 x 960
04-26 15:20:56.331 12261 15005 I AutoQuestDownload: All downloaded in radius of 908 meters around user
04-26 15:20:56.395 12261 12326 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:20:56.397 12261 12326 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:20:56.401 12261 12326 D Tangram : TANGRAM map.cpp:210: resize: 540 x 960
04-26 15:20:56.899 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:20:56.900 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:20:57.834 12261 12261 W RecyclerView: No adapter attached; skipping layout
04-26 15:21:01.108 12261 12261 I QuestAutoSyncer: Checking whether to automatically download new quests at 48.1855140,16.4193844
04-26 15:21:01.118 12261 15005 I AutoQuestDownload: All downloaded in radius of 908 meters around user
04-26 15:21:01.654 12261 12317 W Adreno-EGL: <qeglDrvAPI_eglGetConfigAttrib:607>: EGL_BAD_ATTRIBUTE
04-26 15:21:01.655 12261 12317 D vndksupport: Loading /vendor/lib/hw/gralloc.msm8960.so from current namespace instead of sphal namespace.
04-26 15:21:03.770 12261 12261 W RecyclerView: No adapter attached; skipping layout
04-26 15:21:08.510   466   489 I libprocessgroup: Successfully killed process cgroup uid 10150 pid 12261 in 179ms
04-26 15:21:08.514   216   216 I Zygote  : Process 12261 exited due to signal (9)

@westnordost
Copy link
Member

so, no difference

@westnordost westnordost self-assigned this Apr 26, 2021
@westnordost
Copy link
Member

I have been doing performance testings all day long, but it is really hard because the times measured are quite elusive.

For example, if I do one and the same thing - answer that a house is a detached (this one: https://www.openstreetmap.org/way/58502870#map=19/53.54687/9.99737) (then undo), then answer that again etc, the times measured vary from 300ms to 90ms at one and the same location. Though, what is consistent is that the first fetching takes longest, the second is shorter and then usually on the third call, it's consistently down to 90ms.
And it is the same for the current master branch and the kotlinx-serialization branch (pure kotlin data classes + replaced Kryo serialization library with kotlinx-serialization-json)

I also checked if the Cursor.get*(columnName: String) methods used by the db wrapper class are maybe slow because they always have to string-compare the columnName and then iterate the array of column names in the result, but no, the SQLiteCursor properly caches the colum names in a map.

@westnordost westnordost added the help wanted help by contributors is appreciated; might be a good first contribution for first-timers label Apr 26, 2021
@westnordost
Copy link
Member

Also, the times measured on what is taking long are always constant, in the sense that if the call takes 300ms, everything
(SQLite query, instantiation or deserialization) takes longer and if the call takes 90ms, everything is faster. 😠

@westnordost westnordost removed their assignment Apr 26, 2021
@westnordost
Copy link
Member

So I am out of ideas. 80ms is good, 300ms is... okay. 40000ms is unusable. Though that particular explosion of time it takes to fetch a few hundred elements from the database seems to be only reproducible on your device.

I mean, when quests are displayed, a couple of thousand quests are fetched from the database - that doesn't seem to be a problem on your device? Or is your device trying to fetch this data from database for 5 minutes and during that time, any other larger database operation will also take such an amount of time?

Anyway, I fear to advance with this issue, I rely on your help. You yourself must measure the operation to find what particular element of it takes this much time.

@matkoniecz
Copy link
Member

Though that particular explosion of time it takes to fetch a few hundred elements from the database seems to be only reproducible on your device.

Something similar happened to me when I started testing new version (freeze of app for several seconds on download), then failed to appear again. So I decided to blame phone for being Xiaomi-quality.

I initially got scared that new code is causing massive slowdowns then it failed to appear ever again.

@westnordost
Copy link
Member

hmmm 😟

@Helium314
Copy link
Collaborator Author

Helium314 commented Apr 27, 2021

Anyway, I fear to advance with this issue, I rely on your help. You yourself must measure the operation to find what particular element of it takes this much time.

Well, definitely the DB size that is important, as (so far) it only happens if I download many elements at once.
Do you (or anyone else) get any of these "Window is full" messages after creating a 25+ MB DB at initial download?

I'm currently trying to split the download into smaller areas, hoping that it might cause geographically close elements to be "closer" in the DB (might be obviously useless; I have no clue how such a DB is organized internally and simply imagine a huge spreadsheet)

@Helium314
Copy link
Collaborator Author

Helium314 commented Apr 27, 2021

Hmm, this is not really helping.
I tried splitting the bbox into four here, which massively increased download time.
There is some improvement when answering the building type quest, but 33 instead of 43 sec is still way too much.

@westnordost
Copy link
Member

westnordost commented Apr 27, 2021 via email

@Helium314
Copy link
Collaborator Author

Splitting the download into 16 parts decreases the fetch time to 5 sec, but only fetches 50 elements instead of 100+ (not sure how relevant this is, the number is different every time).
So organizing the DB "the right way" should help. But on how to do this, I have no idea.

@westnordost
Copy link
Member

What download? This ticket is about that answering quests is really slow, isn't it? That has nothing to do with the download.

@westnordost
Copy link
Member

not sure how relevant this is, the number is different every time

This is extremely relevant though, as this might point to another bug. Maybe log the BBOX the fetch is being made for.

@westnordost
Copy link
Member

As said, please don't blindly try around such tings, first step should be what part of the process is the one thing that takes long. Then we can optimize.

@Helium314
Copy link
Collaborator Author

What download? This ticket is about that answering quests is really slow, isn't it? That has nothing to do with the download.

As written above: this problem appears inside large areas downloaded at once (in a single download). Not for any specific element. If I only download a tiny area at full zoom, answering the quest for the same element is done in about a second.
So in some sense it HAS to do with the download (or my current impression: how the downloaded data is put into the DB)

@Helium314
Copy link
Collaborator Author

retry after reboot: 39.6 sec

@westnordost
Copy link
Member

Okay, let's not pursue that further. IMO it does not make a big difference whether to store it as a byte or as a string like "WAY"

@westnordost
Copy link
Member

westnordost commented Apr 30, 2021

on the fetch-by-bbox branch I changed the method how the bbox is fetched (= mimic OSM API).

Do you want to try it out?

There is still something to do, but I first wanted to check if it makes any difference.

What's left to do if this works out:

  • could fetch the geometry of fetched elements on demand only. Leads to ~half the number of DB fetches
  • bbox needs to have a (larger) padding as suggested
  • maybe don't use ElementKey where it is not necessary

Also, the performance problem currently regarding the huge relations should also lead to very very slow download too, because also all geometry in the bbox a new download happens is fetched from DB (so also those huge relations). This change also addresses that.

@Helium314
Copy link
Collaborator Author

Using fetch-by-bbox fetches 17 elements in 150ms for the same house, so definitely a difference.

@westnordost
Copy link
Member

westnordost commented May 1, 2021 via email

@Helium314
Copy link
Collaborator Author

Those 17 (instead of 100+) elements probably don't contain any of those huge relations...

@westnordost
Copy link
Member

Though 17 sound too little. JOSM fetches 29

@westnordost
Copy link
Member

Just as a side note, that particular area is really problematic because there are so many huuuuuuge relations. Download of that area for me was like:

Downloaded 33185 nodes, 4774 ways and 420 relations in 48.4s
Persisted 38263 and deleted 0 elements and geometries in 66.3s
Created 2129 quests for bbox in 8.4s

And that is nothing this app can do anything about. Relations are included in the download result. It would be possible to throw away relations that are huge route relations after download. That would decrease the time used to persist and later also to query the data back from the db.
On the other hand, the app then becomes unable to do anything with (such) relations. I.e. at least the AddSummitRegister quest will stop working.

@westnordost
Copy link
Member

westnordost commented May 1, 2021

The data returned is http://overpass-turbo.eu/s/16Rk

(
 node(id:7903379312,6931015492,6931015506,7903379311,6931015493,7903379310,6164794952,7903379309,5517629213,6931015503,6164794948,8615285130,6164794958);
  way(id:658305257,740277030,740277033,846977295);
);

out geom;

So that looks correct to me. It takes 172ms on the emulator.

@westnordost
Copy link
Member

westnordost commented May 1, 2021

And if I look for elements in a larger bbox (bbox of house + 40m radius), we already got some pretty large relations in the result:

http://overpass-turbo.eu/s/16Rn

(
  node(id:6931015491,1442012927,6931015490,1442012936,706464955,7903379303,7903379312,6931015492,86092999,6931015506,3707323101,7903379311,6931015493,7903379310,6931015505,6164794942,6164794944,6164794943,6164794949,6164794950,6164794951,6164794952,7903379309,5517629213,6931015503,6164794948,8615285130,6164794958,8455112892,6931015517,7903379306,7903379307,7903379305,6164794959,6164794957);
way(id:10276560,54442135,130986630,131448465,131477211,133764170,147444468,316469812,366748359,658305256,658305257,740277030,740277033,740277034,846977295,860465114,885876130,885876131);
rel(id:1991416,1991442,6249864,6249865,6249868,6249870,7917315,7917320);
  
);

out geom;

This takes 1211ms on my emulator.
You want to try how much that effects your speed? I changed line 158 in OsmQuestController to
val paddedBounds = geometry.getBounds().enlargedBy(ApplicationConstants.QUEST_FILTER_PADDING * 2)
(added *2)

This time can likely be halved when doing that performance improvement mentioned earlier.

@westnordost
Copy link
Member

So anyway, if you solved a quest over at Südosttangente where all the international bus routes run through, the performance problem would be back.

So maybe the better solution (or the one that be done additionally) is to really exclude all relations except a few chosen ones to be persisted. The effects of this would be that the summit register quest needs to be deleted. It is not a big sacrifice IMO.

Could it have any other negative effects? For example when a road is split, potentially all relations the way runs through needs to be updated. If the relations are not available offline, the split would be done "wrong". Well, I think not, because the local split is not connected with the "actual split" that is done when uploading the split. When uploading the split, the algorithm actually queries "give me all relations that reference this way" directly from the OSM API and works with that.

@matkoniecz which are the relation types that should be kept?

@matkoniecz
Copy link
Member

The effects of this would be that the summit register quest needs to be deleted. It is not a big sacrifice IMO.

Definitely worth other improvements and avoiding insane performance issues. And maybe it can get back somehow.

The only issue is that it can be potentially triggering some problems in achievement counter, maybe in settings (but it is not the first removed/renamed quest, so...).

@matkoniecz which are the relation types that should be kept?

What about fetching all relation, but without recursive fetching of their elements?

Otherwise associatedStreet is needed but fetching just elements in bbox is fine and ferry quests may want ferry routes - but long ones are discarded anyway, and short ones are unlikely to be mapped as relations...

@westnordost
Copy link
Member

westnordost commented May 1, 2021

What about fetching all relation, but without recursive fetching of their elements?

That was never done. It is the fetching of huge relations alone that is creating these problems.

@westnordost
Copy link
Member

Or maybe a negative list? In that negative list, there should be at least network, water, superroute, boundary, route, route_master, waterway.

@smichel17
Copy link
Member

maybe it can get back somehow

What about a small amount of denormalizing? For relations in the DB, also store the number of (known) members, and queries can add a filter to exclude relations of a certain size. Then the summit quest (and any similar quests in the future) could run async in the background, without this restriction (so they may take a while to appear, but that's fine).

@Helium314
Copy link
Collaborator Author

You want to try how much that effects your speed? I changed line 158 in OsmQuestController to
val paddedBounds = geometry.getBounds().enlargedBy(ApplicationConstants.QUEST_FILTER_PADDING * 2)
(added *2)

2 tests, for "that house" and a crossing next to bus terminal, below A23

old fetch-by-bbox (download all relations): 17 elements in 138 ms, 113 elements in 44500 ms
old fetch-by-bbox with double padding: 61 elements in 586 ms, 205 elements in 52572 ms
current fetch-by-bbox: 17 elements in 128 ms, 36 elements in 185 ms
current fetch-by-bbox with double padding: 53 elements in 577 ms, 112 elements in 320 ms
current master: 39 elements in 216 ms, 62 elements in 258 ms
current master with double padding: 71 elements in 663 ms, 137 elements in 355 ms

Regarding routes:
@smichel17's suggestion sounds reasonable, then hiking and ferry routes could be allowed in the DB.

Alternatively, how about not discarding hiking/ferry routes at all? Or only those with more than 1000 members?
I looked a bit around near several peaks, and if there is a huge hiking route usually there is a shorter one as well (at least for all the peaks I checked).

@matkoniecz
Copy link
Member

Or only those with more than 1000 members?

Is it possible to discard sch relations without ever fetching them? ( "It is the fetching of huge relations alone that is creating these problems." #2803 (comment) )

@westnordost
Copy link
Member

Thank you for the tests, @Helium314

These two are important:

current fetch-by-bbox with double padding: 53 elements in 577 ms, 112 elements in 320 ms
current master: 39 elements in 216 ms, 62 elements in 258 ms

So, both discard route etc relations. The fetch-by-bbox branch must mitigate that one problem I talked about, which is why a double-padding (or similar) would make sense. With that double padding, it is clear that there is not really any advantage of the approach in the fetch-by-bbox branch, so that can be discarded.
The selected solution is then: just discard those relations.

@westnordost
Copy link
Member

Ok, I also changed two more things:

  • performance improvement for quest filter syntax: An expression like amenity ~ restaurant|cafe|fuel|fast_food is now not translated into a regex anymore, but translated into a check in a set of strings. A regex like this is not slow, but a containment check with a set is near instantaneous, O(1). I didn't do very extensive testing but it seemed to have decreased the time of creating quests on download from ~4s to ~2.5s in once instance
  • adapted the quest auto syncer to work with scored map data element density rather than quest density. that means, if you are in an area that is very densely mapped (cities,...), it downloads in a smaller rectangle than if you are in the open in less densely mapped areas.

@westnordost
Copy link
Member

Fetched 37 elements and geometries in 51ms

for "our house" here. I hereby declare this performance problem solved

@westnordost westnordost removed the help wanted help by contributors is appreciated; might be a good first contribution for first-timers label May 2, 2021
@westnordost
Copy link
Member

And released an alpha version! I hope all the issues have been purged now. But I am not so confident about that, so please continue to report any problem here! :-)

@smichel17
Copy link
Member

This is no longer important, but for reference…

Additionally after having read a bit about CursorWindow

Ack, I had meant to link this article that I found while reading about it, which is from 2017, but I assume still applies: https://medium.com/androiddevelopers/large-database-queries-on-android-cb043ae626e8

In my understanding CursorWindow: Window is full means that the results of the query don't fit into the 2 MB CursorWindow (huge relations!), so another query has to be done (and for some reason this is horribly slow).

This was also my take-away from the article, and that the cursor windows may overlap (when you move to a position, it starts filling the window before that position, not at the position). Also that you can adjust that behavior and the cursor size on api 28+, but earlier than that the only way to optimize is a custom implementation.

@westnordost
Copy link
Member

But tis does not occur for StreetComplete. Even a relation with 1000000 members would not trigger that it does not fit into one CursorWindow because each relation member is one row in the database table.

@Helium314
Copy link
Collaborator Author

Only the problem that one row doesn't fit into the CursorWindow can't occur.

But the problem is that the entire set of results (mostly rows of the relation members table) is larger than the CursorWindow.
This is made worse by the CursorWindow containing 33% old data that were already read, so after "CursorWindow is full" only 1.3 MB of new data are fetched from the DB.

Additional useful link/answer: https://stackoverflow.com/questions/20094421/cursor-window-window-is-full/52505989#52505989
In here it is stated that this is normal DB operation. But why does it take several seconds until the next message / load from DB?
If the slow part is only processing the 1.3 MB of new data, then maybe enum.valueOf is that slow (#2803 (comment))
Or maybe all returned rows are processed, including the 1/3 old ones? But I doubt that...

I actually wanted to increase the CursorWindow size (possible on Android 9+) to test how this affects speed, but I don't understand how to actually do this.

@westnordost
Copy link
Member

But why does it take several seconds until the next message / load from DB?

Maybe the RAM is not enough and there is some swapping going on? Otherwise, no idea.

@smichel17
Copy link
Member

smichel17 commented May 6, 2021

I actually wanted to increase the CursorWindow size (possible on Android 9+) to test how this affects speed, but I don't understand how to actually do this.

I have not done it myself, but it looks something like this:

  • Wherever we want to run the query (I guess in our AndroidDatabase.kt), create a SQLiteQueryBuilder.
  • Use its setCursorFactory method to set a custom factory.
  • The custom factory should return a regular SQLiteCursor, but call setFillWindowForwardOnly and setWindow to change the window.
  • The new window should be a regular CursorWindow, but constructed with the version that takes a window size as the argument.

It seems like this still requires replacing the cursor window after the first query has already been run (ie, refreshing the cursor using the new window), but if it was filling up several times then this should still be an improvement.

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

No branches or pull requests

4 participants