Open bbhtt opened 2 years ago
zhanghai
commented
2 years ago This is likely related to the fix for #603, where the underlying abstraction of DocumentsProvider is changed to wait for all files to be loaded, so that file viewing and operations can show all the files.The crash you observed is indeed a bug in v1.4.0 that I observed shortly after release on Crashlytics and it has been fixed in c3e327f. I'm not sure about the slowness though.
zhanghai
commented
2 years ago The deobfuscated stacktrace is (you can also retrace since I uploaded the mapping.txt to GitHub Releases):
03-18 11:30:35.052 20181 20181 W System.err: java8.nio.file.FileSystemException: /: java.lang.InterruptedException
03-18 11:30:35.052 20181 20181 W System.err: at me.zhanghai.android.files.provider.content.resolver.ResolverException.toFileSystemException$default(ResolverException.java:0)
03-18 11:30:35.052 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.java:0)
03-18 11:30:35.052 20181 20181 W System.err: at java8.nio.file.Files.newDirectoryStream(Files.java:0)
03-18 11:30:35.052 20181 20181 W System.err: at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:5)
03-18 11:30:35.053 20181 20181 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.java:0)
03-18 11:30:35.053 20181 20181 W System.err: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-18 11:30:35.053 20181 20181 W System.err: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-18 11:30:35.053 20181 20181 W System.err: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-18 11:30:35.053 20181 20181 W System.err: at java.lang.Thread.run(Thread.java:919)
03-18 11:30:35.053 20181 20181 W System.err: Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-18 11:30:35.053 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.java:0)
03-18 11:30:35.053 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.java:0)
03-18 11:30:35.053 20181 20181 W System.err: at me.zhanghai.android.files.provider.content.resolver.ResolverException.toFileSystemException$default(ResolverException.java:27)
03-18 11:30:35.053 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.java:27)
03-18 11:30:35.053 20181 20181 W System.err: ... 7 more
03-18 11:30:35.053 20181 20181 W System.err: Caused by: java.lang.InterruptedException
03-18 11:30:35.053 20181 20181 W System.err: at kotlinx.coroutines.BlockingCoroutine.joinBlocking(BlockingCoroutine.java:0)
03-18 11:30:35.053 20181 20181 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(BuildersKt__Builders.kt:0)
03-18 11:30:35.053 20181 20181 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking(Builders.kt:0)
03-18 11:30:35.053 20181 20181 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(BuildersKt__Builders.kt:0)
03-18 11:30:35.053 20181 20181 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking$default(Builders.kt:0)
03-18 11:30:35.053 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.java:0)
03-18 11:30:35.053 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.java:0)
03-18 11:30:35.053 20181 20181 W System.err: ... 8 more
03-18 11:30:39.688 20181 20181 W System.err: java8.nio.file.FileSystemException: /MSC: java.lang.InterruptedException
03-18 11:30:39.688 20181 20181 W System.err: at me.zhanghai.android.files.provider.content.resolver.ResolverException.toFileSystemException$default(ResolverException.java:0)
03-18 11:30:39.688 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.java:0)
03-18 11:30:39.688 20181 20181 W System.err: at java8.nio.file.Files.newDirectoryStream(Files.java:0)
03-18 11:30:39.688 20181 20181 W System.err: at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:5)
03-18 11:30:39.688 20181 20181 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.java:0)
03-18 11:30:39.688 20181 20181 W System.err: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-18 11:30:39.688 20181 20181 W System.err: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-18 11:30:39.688 20181 20181 W System.err: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-18 11:30:39.688 20181 20181 W System.err: at java.lang.Thread.run(Thread.java:919)
03-18 11:30:39.688 20181 20181 W System.err: Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-18 11:30:39.688 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.java:0)
03-18 11:30:39.688 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.java:0)
03-18 11:30:39.688 20181 20181 W System.err: at me.zhanghai.android.files.provider.content.resolver.ResolverException.toFileSystemException$default(ResolverException.java:27)
03-18 11:30:39.688 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.java:27)
03-18 11:30:39.688 20181 20181 W System.err: ... 7 more
03-18 11:30:39.688 20181 20181 W System.err: Caused by: java.lang.InterruptedException
03-18 11:30:39.688 20181 20181 W System.err: at kotlinx.coroutines.BlockingCoroutine.joinBlocking(BlockingCoroutine.java:0)
03-18 11:30:39.688 20181 20181 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(BuildersKt__Builders.kt:0)
03-18 11:30:39.688 20181 20181 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking(Builders.kt:0)
03-18 11:30:39.688 20181 20181 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(BuildersKt__Builders.kt:0)
03-18 11:30:39.688 20181 20181 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking$default(Builders.kt:0)
03-18 11:30:39.688 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.java:0)
03-18 11:30:39.688 20181 20181 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.java:0)
03-18 11:30:39.688 20181 20181 W System.err: ... 8 moreThe InterruptedException is thrown when the thread is interrupted, at https://github.com/Kotlin/kotlinx.coroutines/blob/3574c2feca23c3e8a1ad00b5bf92e2bf04d95060/kotlinx-coroutines-core/jvm/src/Builders.kt#L84
So the thread was set to be interrupted. This happens when you navigate away from a folder that's still loading, to stop wait for a result. However, there's still no information about why it is slow... What I can say is only that the app will stop crashing with the next release.
yan12125
commented
2 years ago Hi, I'm having the same issue with 1.4.0 & WebDAV backed by DAVx5. With git-master (e766549a24c2951dbfcc176c9c3ba9716b8e9b4f), there are no more toasts about exceptions, but I can still see InterruptedException in logcat from time to time. Here are logs from both DAVx5 and Material Files: (domain name and filenames redacted)
03-19 14:44:29.557 2784 2784 Zygote D fork-- pid: 31031
03-19 14:44:29.561 3273 3301 ActivityManager I Start proc 31031:at.bitfire.davdroid/u0a214 for activity at.bitfire.davdroid/.ui.AccountsActivity
03-19 14:44:29.563 31031 31031 Zygote D fork++
03-19 14:44:29.595 31031 31031 itfire.davdroi E Not starting debugger since process cannot load the jdwp agent.
03-19 14:44:29.685 31031 31031 itfire.davdroi W Accessing hidden field Ljava/util/Collections$SynchronizedCollection;->mutex:Ljava/lang/Object; (dark greylist, reflection)
03-19 14:44:29.686 31031 31031 itfire.davdroi W Accessing hidden method Ljava/util/Collections$SynchronizedSet;-><init>(Ljava/util/Set;Ljava/lang/Object;)V (dark greylist, reflection)
03-19 14:44:29.686 31031 31031 itfire.davdroi W Accessing hidden method Ljava/util/Collections$SynchronizedCollection;-><init>(Ljava/util/Collection;Ljava/lang/Object;)V (dark greylist, reflection)
03-19 14:44:29.690 31031 31031 davx5 I Verbose logging: true; to file: false
03-19 14:44:29.745 31031 31031 davx5 D [settings.SettingsManager] Loading settings providers from 2 factories
03-19 14:44:29.749 31031 31031 davx5 D [settings.SettingsManager] Changed settings are handled by at.bitfire.davdroid.settings.SharedPreferencesProvider@2baf2a0
03-19 14:44:29.750 31031 31031 davx5 D [settings.SettingsManager] Looking up setting preferred_theme
03-19 14:44:29.750 31031 31031 davx5 D [settings.SettingsManager] SharedPreferencesProvider: preferred_theme = null
03-19 14:44:29.750 31031 31031 davx5 D [settings.SettingsManager] DefaultsProvider: preferred_theme = null
03-19 14:44:29.751 31031 31031 davx5 D [settings.SettingsManager] Looked up setting preferred_theme -> no result
03-19 14:44:29.755 31031 31050 davx5 D [settings.SettingsManager] Looking up setting preferred_tasks_provider
03-19 14:44:29.755 31031 31050 davx5 D [settings.SettingsManager] SharedPreferencesProvider: preferred_tasks_provider = null
03-19 14:44:29.755 31031 31050 davx5 D [settings.SettingsManager] DefaultsProvider: preferred_tasks_provider = null
03-19 14:44:29.755 31031 31050 davx5 D [settings.SettingsManager] Looked up setting preferred_tasks_provider -> no result
03-19 14:44:29.756 31031 31050 davx5 I [TasksWatcher] App launched or other package (un)installed; current tasks provider = TasksOrg
03-19 14:44:29.758 31031 31050 davx5 D [settings.SettingsManager] Looking up setting preferred_tasks_provider
03-19 14:44:29.759 31031 31050 davx5 D [settings.SettingsManager] SharedPreferencesProvider: preferred_tasks_provider = null
03-19 14:44:29.759 31031 31050 davx5 D [settings.SettingsManager] DefaultsProvider: preferred_tasks_provider = null
03-19 14:44:29.759 31031 31050 davx5 D [settings.SettingsManager] Looked up setting preferred_tasks_provider -> no result
03-19 14:44:29.759 31031 31031 itfire.davdroi W Accessing hidden method Landroid/content/res/Resources$Theme;->rebase()V (dark greylist, linking)
03-19 14:44:29.760 31031 31050 davx5 D [StorageLowReceiver] Listening for device storage low/OK broadcasts
03-19 14:44:29.761 31031 31050 davx5 D [settings.SettingsManager] Looking up setting preferred_tasks_provider
03-19 14:44:29.761 31031 31050 davx5 D [settings.SettingsManager] SharedPreferencesProvider: preferred_tasks_provider = null
03-19 14:44:29.761 31031 31050 davx5 D [settings.SettingsManager] DefaultsProvider: preferred_tasks_provider = null
03-19 14:44:29.761 31031 31050 davx5 D [settings.SettingsManager] Looked up setting preferred_tasks_provider -> no result
03-19 14:44:29.763 31031 31050 davx5 D [settings.AccountSettings] Account yen has version 12, current version: 12
03-19 14:44:29.771 31031 31050 davx5 D [settings.SettingsManager] Looking up setting foreground_service
03-19 14:44:29.771 31031 31050 davx5 D [settings.SettingsManager] SharedPreferencesProvider: foreground_service = false
03-19 14:44:29.771 31031 31050 davx5 D [settings.SettingsManager] Looked up setting foreground_service -> false
03-19 14:44:29.777 31031 31052 davx5 D [ui.intro.IntroActivity] Registered intro fragment class at.bitfire.davdroid.ui.intro.WelcomeFragment$Factory
03-19 14:44:29.777 31031 31052 davx5 D [ui.intro.IntroActivity] Registered intro fragment class at.bitfire.davdroid.ui.intro.TasksFragmentFactory
03-19 14:44:29.777 31031 31052 davx5 D [ui.intro.IntroActivity] Registered intro fragment class at.bitfire.davdroid.ui.intro.PermissionsFragmentFactory
03-19 14:44:29.778 31031 31052 davx5 D [ui.intro.IntroActivity] Registered intro fragment class at.bitfire.davdroid.ui.intro.BatteryOptimizationsFragment$Factory
03-19 14:44:29.778 31031 31052 davx5 D [ui.intro.IntroActivity] Registered intro fragment class at.bitfire.davdroid.ui.intro.OpenSourceFragment$Factory
03-19 14:44:29.778 31031 31052 davx5 D [ui.intro.IntroActivity] Intro fragment at.bitfire.davdroid.ui.intro.WelcomeFragment$Factory@5d70be2: showMode=SHOW_NOT_ALONE
03-19 14:44:29.778 31031 31052 davx5 D [settings.SettingsManager] Looking up setting preferred_tasks_provider
03-19 14:44:29.778 31031 31052 davx5 D [settings.SettingsManager] SharedPreferencesProvider: preferred_tasks_provider = null
03-19 14:44:29.778 31031 31052 davx5 D [settings.SettingsManager] DefaultsProvider: preferred_tasks_provider = null
03-19 14:44:29.779 31031 31052 davx5 D [settings.SettingsManager] Looked up setting preferred_tasks_provider -> no result
03-19 14:44:29.779 31031 31052 davx5 D [ui.intro.IntroActivity] Intro fragment at.bitfire.davdroid.ui.intro.TasksFragmentFactory@4fb1b73: showMode=DONT_SHOW
03-19 14:44:29.780 31031 31052 davx5 D [ui.intro.IntroActivity] Intro fragment at.bitfire.davdroid.ui.intro.PermissionsFragmentFactory@f39ea30: showMode=DONT_SHOW
03-19 14:44:29.782 31031 31052 davx5 D [ui.intro.IntroActivity] Intro fragment at.bitfire.davdroid.ui.intro.BatteryOptimizationsFragment$Factory@22386a9: showMode=DONT_SHOW
03-19 14:44:29.782 31031 31052 davx5 D [settings.SettingsManager] Looking up setting time_nextDonationPopup
03-19 14:44:29.782 31031 31052 davx5 D [settings.SettingsManager] SharedPreferencesProvider: time_nextDonationPopup = 1653033870019
03-19 14:44:29.782 31031 31052 davx5 D [settings.SettingsManager] Looked up setting time_nextDonationPopup -> 1653033870019
03-19 14:44:29.783 31031 31052 davx5 D [ui.intro.IntroActivity] Intro fragment at.bitfire.davdroid.ui.intro.OpenSourceFragment$Factory@bde042e: showMode=DONT_SHOW
03-19 14:44:29.784 31031 31031 Perf I Connecting to perf service.
03-19 14:44:29.801 31031 31031 OpenGLRenderer D Skia GL Pipeline
03-19 14:44:29.849 31031 31031 davx5 D [settings.SettingsManager] Looking up setting preferred_tasks_provider
03-19 14:44:29.849 31031 31031 davx5 D [settings.SettingsManager] SharedPreferencesProvider: preferred_tasks_provider = null
03-19 14:44:29.849 31031 31031 davx5 D [settings.SettingsManager] DefaultsProvider: preferred_tasks_provider = null
03-19 14:44:29.849 31031 31031 davx5 D [settings.SettingsManager] Looked up setting preferred_tasks_provider -> no result
03-19 14:44:29.869 31031 31055 Adreno I QUALCOMM build : 242851d, I8bbe87bca5
03-19 14:44:29.869 31031 31055 Adreno I Build Date : 12/25/18
03-19 14:44:29.869 31031 31055 Adreno I OpenGL ES Shader Compiler Version: EV031.25.03.02
03-19 14:44:29.869 31031 31055 Adreno I Local Branch : mybranche9086c2a-0744-f10d-b22e-1458d0b52ae8
03-19 14:44:29.869 31031 31055 Adreno I Remote Branch : quic/gfx-adreno.lnx.1.0.r49-rel
03-19 14:44:29.869 31031 31055 Adreno I Remote Branch : NONE
03-19 14:44:29.869 31031 31055 Adreno I Reconstruct Branch : NOTHING
03-19 14:44:29.869 31031 31055 Adreno I Build Config : S L 6.0.7 AArch64
03-19 14:44:29.869 31031 31055 vndksupport D Loading /vendor/lib64/hw/gralloc.msm8998.so from current namespace instead of sphal namespace.
03-19 14:44:29.871 31031 31055 Adreno I PFP: 0x005ff112, ME: 0x005ff066
03-19 14:44:29.876 31031 31055 ConfigStore I android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasWideColorDisplay retrieved: 0
03-19 14:44:29.876 31031 31055 ConfigStore I android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasHDRDisplay retrieved: 0
03-19 14:44:29.877 31031 31055 OpenGLRenderer I Initialized EGL, version 1.4
03-19 14:44:29.877 31031 31055 OpenGLRenderer D Swap behavior 2
03-19 14:44:29.894 31031 31055 vndksupport D Loading /vendor/lib64/hw/android.hardware.graphics.mapper@2.0-impl.so from current namespace instead of sphal namespace.
03-19 14:44:29.896 31031 31055 vndksupport D Loading /vendor/lib64/hw/gralloc.msm8998.so from current namespace instead of sphal namespace.
03-19 14:44:29.915 3273 8604 InputMethodManager.. D Switching to client at.bitfire.davdroid(31031), IME=com.google.android.apps.inputmethod.zhuyin/.ZhuyinInputMethodService
03-19 14:44:29.915 3273 8604 InputMethodManager.. I Enable input method client, cs=ClientState{1b0219a uid 10214 pid 31031}
03-19 14:44:34.212 3273 9961 InputMethodManager.. I Disable input method client, cs=ClientState{1b0219a uid 10214 pid 31031}
03-19 14:44:35.655 29224 29224 StaticLayout W maxLineHeight should not be -1. maxLines:1 lineCount:1
03-19 14:44:35.665 31031 31064 davx5 D [webdav.DavDocumentsProvider] WebDAV queryDocument 1 _display_name
03-19 14:44:35.666 31031 31064 davx5 D [webdav.DavDocumentsProvider] queryDocument(1) = Bundle[{_display_name=, mime_type=vnd.android.filename6/directory, last_modified=1647535531000, flags=460, document_id=1}]
03-19 14:44:35.782 3273 5355 InputMethodManager.. D Switching to client me.zhanghai.android.files(29224), IME=com.google.android.apps.inputmethod.zhuyin/.ZhuyinInputMethodService
03-19 14:44:35.782 3273 5355 InputMethodManager.. I Enable input method client, cs=ClientState{28bcf03 uid 10243 pid 29224}
03-19 14:44:37.716 31031 31064 davx5 D [webdav.DavDocumentsProvider] WebDAV queryDocument 1 mime_type
03-19 14:44:37.723 31031 31044 davx5 D [webdav.DavDocumentsProvider] WebDAV queryChildDocuments 1 null null
03-19 14:44:37.731 31031 31045 davx5 D [webdav.DavDocumentsProvider] WebDAV queryDocument 1 _display_name
03-19 14:44:37.732 31031 31064 davx5 D [webdav.DavDocumentsProvider] queryDocument(1) = Bundle[{_display_name=, mime_type=vnd.android.filename6/directory, last_modified=1647535531000, flags=460, document_id=1}]
03-19 14:44:37.740 31031 31045 davx5 D [webdav.DavDocumentsProvider] queryDocument(1) = Bundle[{_display_name=, mime_type=vnd.android.filename6/directory, last_modified=1647535531000, flags=460, document_id=1}]
03-19 14:44:37.747 31031 31064 davx5 D [webdav.DavDocumentsProvider] WebDAV queryChildDocuments 1 null null
03-19 14:44:37.752 31031 31077 davx5 I [HttpClient] Will set "User-Agent: DAVx5/4.1.1-ose (2022/02/04; dav4jvm; okhttp/4.9.1) Android/9" for further requests
03-19 14:44:37.753 31031 31077 davx5 D [settings.SettingsManager] Looking up setting override_proxy
03-19 14:44:37.753 31031 31077 davx5 D [settings.SettingsManager] SharedPreferencesProvider: override_proxy = false
03-19 14:44:37.754 31031 31077 davx5 D [settings.SettingsManager] Looked up setting override_proxy -> false
03-19 14:44:37.754 31031 31077 davx5 D [settings.SettingsManager] Looking up setting distrust_system_certs
03-19 14:44:37.755 31031 31077 davx5 D [settings.SettingsManager] SharedPreferencesProvider: distrust_system_certs = false
03-19 14:44:37.755 31031 31077 davx5 D [settings.SettingsManager] Looked up setting distrust_system_certs -> false
03-19 14:44:37.756 31031 31077 NetworkSecurityCon.. D Using Network Security Config from resource network_security_config debugBuild: false
03-19 14:44:37.775 31031 31031 NativeCrypto V Registering org/conscrypt/NativeCrypto's 288 native methods...
03-19 14:44:37.787 31031 31031 cert4android I Using Conscrypt/2.5.2 for TLS
03-19 14:44:37.799 31031 31031 cert4android I Enabled protocols: TLSv1, TLSv1.1, TLSv1.2, TLSv1.3
03-19 14:44:37.799 31031 31031 cert4android I Enabled ciphers: TLS_AES_128_GCM_SHA256, TLS_AES_256_GCM_SHA384, TLS_CHACHA20_POLY1305_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_256_GCM_SHA384, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV
03-19 14:44:37.800 31031 31031 cert4android I [CustomCertService] CustomCertService created
03-19 14:44:37.801 31031 31031 cert4android I [CustomCertService] No key store for trusted certifcates (yet); creating in-memory key store.
03-19 14:44:37.818 31031 31043 itfire.davdroi I Background concurrent copying GC freed 77079(4MB) AllocSpace objects, 18(1788KB) LOS objects, 60% free, 3MB/9MB, paused 262us total 100.690ms
03-19 14:44:38.099 31031 31077 com.google.crypto... I Provider GmsCore_OpenSSL not available
03-19 14:44:38.125 31031 31077 libc D [NET] dns_sku:0
03-19 14:44:38.126 31031 31077 libc D [NET] android_getaddrinfo_proxy get netid:0
03-19 14:44:38.521 31031 31077 libc D [NET] android_getaddrinfo_proxy-, success
03-19 14:44:38.593 31031 31077 davx5 V [HttpClient] --> PROPFIND https://my-domain/ h2
03-19 14:44:38.594 31031 31077 davx5 V [HttpClient] Depth: 1
03-19 14:44:38.595 31031 31077 davx5 V [HttpClient] User-Agent: DAVx5/4.1.1-ose (2022/02/04; dav4jvm; okhttp/4.9.1) Android/9
03-19 14:44:38.595 31031 31077 davx5 V [HttpClient] Accept-Language: zh-TW, zh;q=0.7, *;q=0.5
03-19 14:44:38.595 31031 31077 davx5 V [HttpClient] Content-Type: application/xml; charset=utf-8
03-19 14:44:38.596 31031 31077 davx5 V [HttpClient] Content-Length: 335
03-19 14:44:38.596 31031 31077 davx5 V [HttpClient] Host: my-domain
03-19 14:44:38.597 31031 31077 davx5 V [HttpClient] Connection: Keep-Alive
03-19 14:44:38.598 31031 31077 davx5 V [HttpClient] Accept-Encoding: gzip
03-19 14:44:38.598 31031 31077 davx5 V [HttpClient] --> END PROPFIND
03-19 14:44:38.603 31031 31077 dav4jvm D [at.bitfire.dav4jvm.BasicDigestAuthHandler] Trying Basic auth preemptively
03-19 14:44:38.603 31031 31077 dav4jvm D [at.bitfire.dav4jvm.BasicDigestAuthHandler] Adding Basic authorization header for https://my-domain/
03-19 14:44:39.217 31031 31077 davx5 V [HttpClient] <-- 207 https://my-domain/ (617ms)
03-19 14:44:39.218 31031 31077 davx5 V [HttpClient] server: nginx/1.20.2
03-19 14:44:39.219 31031 31077 davx5 V [HttpClient] date: Sat, 19 Mar 2022 06:44:39 GMT
03-19 14:44:39.219 31031 31077 davx5 V [HttpClient] content-type: text/xml; charset=utf-8
03-19 14:44:39.220 31031 31077 davx5 V [HttpClient] referrer-policy: no-referrer
03-19 14:44:39.220 31031 31077 davx5 V [HttpClient] strict-transport-security: max-age=63072000; includeSubdomains
03-19 14:44:39.221 31031 31077 davx5 V [HttpClient] x-content-type-options: nosniff
03-19 14:44:39.222 31031 31077 davx5 V [HttpClient] x-download-options: noopen
03-19 14:44:39.222 31031 31077 davx5 V [HttpClient] x-frame-options: SAMEORIGIN
03-19 14:44:39.223 31031 31077 davx5 V [HttpClient] x-permitted-cross-domain-policies: none
03-19 14:44:39.223 31031 31077 davx5 V [HttpClient] x-robots-tag: none
03-19 14:44:39.224 31031 31077 davx5 V [HttpClient] x-xss-protection: 1; mode=block
03-19 14:44:39.225 31031 31077 davx5 V [HttpClient] <-- END HTTP
03-19 14:44:39.232 31031 31077 dav4jvm I [at.bitfire.dav4jvm.PropertyRegistry] Registering DAV property factories
03-19 14:44:39.233 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.AddMember$Factory for DAV::add-member
03-19 14:44:39.233 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.AddressbookDescription$Factory for urn:ietf:params:xml:ns:carddav:addressbook-description
03-19 14:44:39.234 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.AddressbookHomeSet$Factory for urn:ietf:params:xml:ns:carddav:addressbook-home-set
03-19 14:44:39.235 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.AddressData$Factory for urn:ietf:params:xml:ns:carddav:address-data
03-19 14:44:39.237 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.CalendarColor$Factory for http://apple.com/ns/ical/:calendar-color
03-19 14:44:39.237 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.CalendarData$Factory for urn:ietf:params:xml:ns:caldav:calendar-data
03-19 14:44:39.238 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.CalendarDescription$Factory for urn:ietf:params:xml:ns:caldav:calendar-description
03-19 14:44:39.238 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.CalendarHomeSet$Factory for urn:ietf:params:xml:ns:caldav:calendar-home-set
03-19 14:44:39.239 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.CalendarProxyReadFor$Factory for http://calendarserver.org/ns/:calendar-proxy-read-for
03-19 14:44:39.240 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.CalendarProxyWriteFor$Factory for http://calendarserver.org/ns/:calendar-proxy-write-for
03-19 14:44:39.240 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.CalendarTimezone$Factory for urn:ietf:params:xml:ns:caldav:calendar-timezone
03-19 14:44:39.241 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.CalendarUserAddressSet$Factory for urn:ietf:params:xml:ns:caldav:calendar-user-address-set
03-19 14:44:39.241 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.CreationDate$Factory for DAV::creationdate
03-19 14:44:39.242 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.CurrentUserPrincipal$Factory for DAV::current-user-principal
03-19 14:44:39.243 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.CurrentUserPrivilegeSet$Factory for DAV::current-user-privilege-set
03-19 14:44:39.243 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.DisplayName$Factory for DAV::displayname
03-19 14:44:39.243 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.GetContentLength$Factory for DAV::getcontentlength
03-19 14:44:39.244 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.GetContentType$Factory for DAV::getcontenttype
03-19 14:44:39.245 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.GetCTag$Factory for http://calendarserver.org/ns/:getctag
03-19 14:44:39.245 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.GetETag$Factory for DAV::getetag
03-19 14:44:39.245 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.GetLastModified$Factory for DAV::getlastmodified
03-19 14:44:39.246 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.GroupMembership$Factory for DAV::group-membership
03-19 14:44:39.247 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.Owner$Factory for DAV::owner
03-19 14:44:39.247 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.QuotaAvailableBytes$Factory for DAV::quota-available-bytes
03-19 14:44:39.248 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.QuotaUsedBytes$Factory for DAV::quota-used-bytes
03-19 14:44:39.248 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.ResourceType$Factory for DAV::resourcetype
03-19 14:44:39.249 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.ScheduleTag$Factory for urn:ietf:params:xml:ns:caldav:schedule-tag
03-19 14:44:39.249 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.Source$Factory for http://calendarserver.org/ns/:source
03-19 14:44:39.250 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.SupportedAddressData$Factory for urn:ietf:params:xml:ns:carddav:supported-address-data
03-19 14:44:39.250 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.SupportedCalendarComponentSet$Factory for urn:ietf:params:xml:ns:caldav:supported-calendar-component-set
03-19 14:44:39.251 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.SupportedCalendarData$Factory for urn:ietf:params:xml:ns:caldav:supported-calendar-data
03-19 14:44:39.251 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.SupportedReportSet$Factory for DAV::supported-report-set
03-19 14:44:39.252 31031 31077 dav4jvm D [at.bitfire.dav4jvm.PropertyRegistry] Registering at.bitfire.dav4jvm.property.SyncToken$Factory for DAV::sync-token
03-19 14:44:39.258 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:39.259 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:39.259 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:39.261 31031 31077 davx5 D [webdav.DavDocumentsProvider] SELF Response(requestedUrl=https://my-domain/, href=https://my-domain/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=null), GetLastModified(lastModified=1647535531000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:39.265 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:39.265 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:39.266 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:39.267 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename9/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename9), GetLastModified(lastModified=1550083727000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:39.268 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:39.269 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:39.270 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename1, status=null, propstat=[PropStat(properties=[[], DisplayName(displayName=filename1), GetContentType(type=application/octet-stream), GetContentLength(contentLength=36), GetLastModified(lastModified=1617953977000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:39.271 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:39.271 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:39.272 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:39.272 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename5/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename5), GetLastModified(lastModified=1646202001000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:39.273 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:39.274 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:39.274 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:39.275 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename7/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename7), GetLastModified(lastModified=1646038141000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:39.277 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:39.278 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:39.278 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:39.279 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename4/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename4), GetLastModified(lastModified=1644355880000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:39.280 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:39.280 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:39.280 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:39.281 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename2/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename2), GetLastModified(lastModified=1645468212000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:39.281 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:39.282 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:39.282 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:39.283 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename8/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename8), GetLastModified(lastModified=1619143128000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:39.283 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:39.284 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:39.284 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:39.284 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename3/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename3), GetLastModified(lastModified=1638398313000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:39.285 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:39.285 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:39.285 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:39.286 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename6/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename6), GetLastModified(lastModified=1647503361000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:39.288 31031 31031 cert4android I [CustomCertService] CustomCertService destroyed
03-19 14:44:39.290 31031 31077 davx5 D [model.DaoTools] Syncing tables
03-19 14:44:39.290 31031 31077 davx5 D PARAMETER #0 = [WebDavDocument(id=2, mountId=1, parentId=1, name=filename1, isDirectory=false, displayName=filename1, mimeType=application/octet-stream, eTag=null, lastModified=1617953977000, size=36, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=3, mountId=1, parentId=1, name=filename2, isDirectory=true, displayName=filename2, mimeType=null, eTag=null, lastModified=1645468212000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=4, mountId=1, parentId=1, name=filename3, isDirectory=true, displayName=filename3, mimeType=null, eTag=null, lastModified=1638398313000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=5, mountId=1, parentId=1, name=filename4, isDirectory=true, displayName=filename4, mimeType=null, eTag=null, lastModified=1644355880000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=6, mountId=1, parentId=1, name=filename5, isDirectory=true, displayName=filename5, mimeType=null, eTag=null, lastModified=1646202001000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=7, mountId=1, parentId=1, name=filename6, isDirectory=true, displayName=filename6, mimeType=null, eTag=null, lastModified=1647503361000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=8, mountId=1, parentId=1, name=filename7, isDirectory=true, displayName=filename7, mimeType=null, eTag=null, lastModified=1646038141000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=9, mountId=1, parentId=1, name=filename8, isDirectory=true, displayName=filename8, mimeType=null, eTag=null, lastModified=1619143128000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=10, mountId=1, parentId=1, name=filename9, isDirectory=true, displayName=filename9, mimeType=null, eTag=null, lastModified=1550083727000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null)]
03-19 14:44:39.290 31031 31077 davx5 D PARAMETER #1 = {filename1=WebDavDocument(id=0, mountId=1, parentId=1, name=filename1, isDirectory=false, displayName=filename1, mimeType=application/octet-stream, eTag=null, lastModified=1617953977000, size=36, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename2=WebDavDocument(id=0, mountId=1, parentId=1, name=filename2, isDirectory=true, displayName=filename2, mimeType=null, eTag=null, lastModified=1645468212000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename3=WebDavDocument(id=0, mountId=1, parentId=1, name=filename3, isDirectory=true,
03-19 14:44:39.290 31031 31077 davx5 D displayName=filename3, mimeType=null, eTag=null, lastModified=1638398313000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename4=WebDavDocument(id=0, mountId=1, parentId=1, name=filename4, isDirectory=true, displayName=filename4, mimeType=null, eTag=null, lastModified=1644355880000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename5=WebDavDocument(id=0, mountId=1, parentId=1, name=filename5, isDirectory=true, displayName=filename5, mimeType=null, eTag=null, lastModified=1646202001000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename6=WebDavDocument(id=0, mountId=1, parentId=1, name=filename6, isDirectory=true, displayName=filename6, mimeType=null, eTag=null, lastModified=1647503361000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename7=WebDavDocument(id=0, mountId=1, parentId=1, name=filename7, isDirectory=true, displayName=filename7, mimeType=null, eTag=null, lastModified=1646038141000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename8=WebDavDocument(id=0, mountId=1, parentId=1, name=filename8, isDirectory=true, displayName=filename8, mimeType=null, eTag=null, lastModified=1619143128000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename9=WebDavDocument(id=0, mountId=1, parentId=1, name=filename9, isDirectory=true, displayName=filename9, mimeType=null, eTag=null, lastModified=1550083727000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null)}
03-19 14:44:39.291 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename1, _display_name=filename1, mime_type=application/octet-stream, last_modified=1617953977000, _size=36, flags=454, document_id=2}]
03-19 14:44:39.292 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename2, _display_name=filename2, mime_type=vnd.android.filename6/directory, last_modified=1645468212000, flags=460, document_id=3}]
03-19 14:44:39.292 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename3, _display_name=filename3, mime_type=vnd.android.filename6/directory, last_modified=1638398313000, flags=460, document_id=4}]
03-19 14:44:39.292 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename4, _display_name=filename4, mime_type=vnd.android.filename6/directory, last_modified=1644355880000, flags=460, document_id=5}]
03-19 14:44:39.292 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename5, _display_name=filename5, mime_type=vnd.android.filename6/directory, last_modified=1646202001000, flags=460, document_id=6}]
03-19 14:44:39.293 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename6, _display_name=filename6, mime_type=vnd.android.filename6/directory, last_modified=1647503361000, flags=460, document_id=7}]
03-19 14:44:39.293 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename7, _display_name=filename7, mime_type=vnd.android.filename6/directory, last_modified=1646038141000, flags=460, document_id=8}]
03-19 14:44:39.293 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename8, _display_name=filename8, mime_type=vnd.android.filename6/directory, last_modified=1619143128000, flags=460, document_id=9}]
03-19 14:44:39.293 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename9, _display_name=filename9, mime_type=vnd.android.filename6/directory, last_modified=1550083727000, flags=460, document_id=10}]
03-19 14:44:39.300 31031 31064 davx5 D [webdav.DavDocumentsProvider] WebDAV queryChildDocuments 1 null null
03-19 14:44:39.303 31031 31044 davx5 D [webdav.DavDocumentsProvider] WebDAV queryChildDocuments 1 null null
03-19 14:44:39.308 31031 31077 davx5 D [settings.SettingsManager] Looking up setting override_proxy
03-19 14:44:39.309 31031 31077 davx5 D [settings.SettingsManager] SharedPreferencesProvider: override_proxy = false
03-19 14:44:39.309 31031 31077 davx5 D [settings.SettingsManager] Looked up setting override_proxy -> false
03-19 14:44:39.309 31031 31077 davx5 D [settings.SettingsManager] Looking up setting distrust_system_certs
03-19 14:44:39.309 31031 31077 davx5 D [settings.SettingsManager] SharedPreferencesProvider: distrust_system_certs = false
03-19 14:44:39.309 31031 31077 davx5 D [settings.SettingsManager] Looked up setting distrust_system_certs -> false
03-19 14:44:39.312 31031 31031 cert4android I [CustomCertService] CustomCertService created
03-19 14:44:39.313 31031 31031 cert4android I [CustomCertService] No key store for trusted certifcates (yet); creating in-memory key store.
03-19 14:44:39.320 29224 29224 System.err W java8.nio.file.FileSystemException: /: java.lang.InterruptedException
03-19 14:44:39.320 29224 29224 System.err W at me.zhanghai.android.files.provider.filename6.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:264)
03-19 14:44:39.321 29224 29224 System.err W at java8.nio.file.Files.newDirectoryStream(Files.java:457)
03-19 14:44:39.321 29224 29224 System.err W at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:152)
03-19 14:44:39.321 29224 29224 System.err W at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.kt:42)
03-19 14:44:39.321 29224 29224 System.err W at me.zhanghai.android.files.filelist.FileListLiveData.$r8$lambda$zAlkFlJrlhzk0ZkhSD7tgqwgsQc(Unknown Source:0)
03-19 14:44:39.321 29224 29224 System.err W at me.zhanghai.android.files.filelist.FileListLiveData$$ExternalSyntheticLambda0.call(Unknown Source:2)
03-19 14:44:39.321 29224 29224 System.err W at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-19 14:44:39.321 29224 29224 System.err W at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-19 14:44:39.321 29224 29224 System.err W at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-19 14:44:39.321 29224 29224 System.err W at java.lang.Thread.run(Thread.java:764)
03-19 14:44:39.321 29224 29224 System.err W Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-19 14:44:39.321 29224 29224 System.err W at me.zhanghai.android.files.provider.filename6.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:604)
03-19 14:44:39.321 29224 29224 System.err W at me.zhanghai.android.files.provider.filename6.resolver.DocumentResolver.queryChildren(DocumentResolver.kt:400)
03-19 14:44:39.321 29224 29224 System.err W at me.zhanghai.android.files.provider.filename6.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:262)
03-19 14:44:39.321 29224 29224 System.err W ... 9 more
03-19 14:44:39.321 29224 29224 System.err W Caused by: java.lang.InterruptedException
03-19 14:44:39.321 29224 29224 System.err W at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:84)
03-19 14:44:39.321 29224 29224 System.err W at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
03-19 14:44:39.321 29224 29224 System.err W at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source:1)
03-19 14:44:39.321 29224 29224 System.err W at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
03-19 14:44:39.321 29224 29224 System.err W at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source:1)
03-19 14:44:39.321 29224 29224 System.err W at me.zhanghai.android.files.provider.filename6.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:585)
03-19 14:44:39.321 29224 29224 System.err W ... 11 more
03-19 14:44:39.658 31031 31077 davx5 V [HttpClient] --> PROPFIND https://my-domain/ h2
03-19 14:44:39.658 31031 31077 davx5 V [HttpClient] Depth: 1
03-19 14:44:39.659 31031 31077 davx5 V [HttpClient] User-Agent: DAVx5/4.1.1-ose (2022/02/04; dav4jvm; okhttp/4.9.1) Android/9
03-19 14:44:39.660 31031 31077 davx5 V [HttpClient] Accept-Language: zh-TW, zh;q=0.7, *;q=0.5
03-19 14:44:39.660 31031 31077 davx5 V [HttpClient] Content-Type: application/xml; charset=utf-8
03-19 14:44:39.661 31031 31077 davx5 V [HttpClient] Content-Length: 335
03-19 14:44:39.661 31031 31077 davx5 V [HttpClient] Host: my-domain
03-19 14:44:39.662 31031 31077 davx5 V [HttpClient] Connection: Keep-Alive
03-19 14:44:39.662 31031 31077 davx5 V [HttpClient] Accept-Encoding: gzip
03-19 14:44:39.663 31031 31077 davx5 V [HttpClient] --> END PROPFIND
03-19 14:44:39.664 31031 31077 dav4jvm D [at.bitfire.dav4jvm.BasicDigestAuthHandler] Trying Basic auth preemptively
03-19 14:44:39.664 31031 31077 dav4jvm D [at.bitfire.dav4jvm.BasicDigestAuthHandler] Adding Basic authorization header for https://my-domain/
03-19 14:44:40.343 31031 31077 davx5 V [HttpClient] <-- 207 https://my-domain/ (678ms)
03-19 14:44:40.344 31031 31077 davx5 V [HttpClient] server: nginx/1.20.2
03-19 14:44:40.345 31031 31077 davx5 V [HttpClient] date: Sat, 19 Mar 2022 06:44:40 GMT
03-19 14:44:40.346 31031 31077 davx5 V [HttpClient] content-type: text/xml; charset=utf-8
03-19 14:44:40.346 31031 31077 davx5 V [HttpClient] referrer-policy: no-referrer
03-19 14:44:40.347 31031 31077 davx5 V [HttpClient] strict-transport-security: max-age=63072000; includeSubdomains
03-19 14:44:40.348 31031 31077 davx5 V [HttpClient] x-content-type-options: nosniff
03-19 14:44:40.349 31031 31077 davx5 V [HttpClient] x-download-options: noopen
03-19 14:44:40.350 31031 31077 davx5 V [HttpClient] x-frame-options: SAMEORIGIN
03-19 14:44:40.350 31031 31077 davx5 V [HttpClient] x-permitted-cross-domain-policies: none
03-19 14:44:40.351 31031 31077 davx5 V [HttpClient] x-robots-tag: none
03-19 14:44:40.352 31031 31077 davx5 V [HttpClient] x-xss-protection: 1; mode=block
03-19 14:44:40.353 31031 31077 davx5 V [HttpClient] <-- END HTTP
03-19 14:44:40.356 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:40.357 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:40.357 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:40.358 31031 31077 davx5 D [webdav.DavDocumentsProvider] SELF Response(requestedUrl=https://my-domain/, href=https://my-domain/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=null), GetLastModified(lastModified=1647535531000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:40.362 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:40.363 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:40.363 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:40.365 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename9/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename9), GetLastModified(lastModified=1550083727000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:40.366 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:40.367 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:40.368 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename1, status=null, propstat=[PropStat(properties=[[], DisplayName(displayName=filename1), GetContentType(type=application/octet-stream), GetContentLength(contentLength=36), GetLastModified(lastModified=1617953977000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:40.369 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:40.370 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:40.371 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:40.372 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename5/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename5), GetLastModified(lastModified=1646202001000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:40.373 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:40.374 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:40.374 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:40.375 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename7/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename7), GetLastModified(lastModified=1646038141000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:40.377 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:40.377 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:40.378 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:40.379 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename4/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename4), GetLastModified(lastModified=1644355880000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:40.380 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:40.380 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:40.381 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:40.382 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename2/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename2), GetLastModified(lastModified=1645468212000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:40.383 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:40.384 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:40.384 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:40.385 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename8/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename8), GetLastModified(lastModified=1619143128000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:40.387 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:40.387 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:40.388 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:40.389 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename3/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename3), GetLastModified(lastModified=1638398313000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:40.390 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::getcontentlength
03-19 14:44:40.391 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-available-bytes
03-19 14:44:40.391 31031 31077 dav4jvm D [at.bitfire.dav4jvm.Property] Ignoring unknown property DAV::quota-used-bytes
03-19 14:44:40.392 31031 31077 davx5 D [webdav.DavDocumentsProvider] MEMBER Response(requestedUrl=https://my-domain/, href=https://my-domain/filename6/, status=null, propstat=[PropStat(properties=[[DAV::collection], DisplayName(displayName=filename6), GetLastModified(lastModified=1647503361000)], status=HTTP/1.1 200 OK, error=null), PropStat(properties=[CurrentUserPrivilegeSet(mayRead=false, mayWriteProperties=false, mayWriteContent=false, mayBind=false, mayUnbind=false), GetContentType(type=null)], status=HTTP/1.1 404 Not Found, error=null)], error=null, newLocation=null)
03-19 14:44:40.395 31031 31031 cert4android I [CustomCertService] CustomCertService destroyed
03-19 14:44:40.398 31031 31077 davx5 D [model.DaoTools] Syncing tables
03-19 14:44:40.398 31031 31077 davx5 D PARAMETER #0 = [WebDavDocument(id=2, mountId=1, parentId=1, name=filename1, isDirectory=false, displayName=filename1, mimeType=application/octet-stream, eTag=null, lastModified=1617953977000, size=36, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=3, mountId=1, parentId=1, name=filename2, isDirectory=true, displayName=filename2, mimeType=null, eTag=null, lastModified=1645468212000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=4, mountId=1, parentId=1, name=filename3, isDirectory=true, displayName=filename3, mimeType=null, eTag=null, lastModified=1638398313000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=5, mountId=1, parentId=1, name=filename4, isDirectory=true, displayName=filename4, mimeType=null, eTag=null, lastModified=1644355880000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=6, mountId=1, parentId=1, name=filename5, isDirectory=true, displayName=filename5, mimeType=null, eTag=null, lastModified=1646202001000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=7, mountId=1, parentId=1, name=filename6, isDirectory=true, displayName=filename6, mimeType=null, eTag=null, lastModified=1647503361000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=8, mountId=1, parentId=1, name=filename7, isDirectory=true, displayName=filename7, mimeType=null, eTag=null, lastModified=1646038141000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=9, mountId=1, parentId=1, name=filename8, isDirectory=true, displayName=filename8, mimeType=null, eTag=null, lastModified=1619143128000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), WebDavDocument(id=10, mountId=1, parentId=1, name=filename9, isDirectory=true, displayName=filename9, mimeType=null, eTag=null, lastModified=1550083727000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null)]
03-19 14:44:40.398 31031 31077 davx5 D PARAMETER #1 = {filename1=WebDavDocument(id=0, mountId=1, parentId=1, name=filename1, isDirectory=false, displayName=filename1, mimeType=application/octet-stream, eTag=null, lastModified=1617953977000, size=36, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename2=WebDavDocument(id=0, mountId=1, parentId=1, name=filename2, isDirectory=true, displayName=filename2, mimeType=null, eTag=null, lastModified=1645468212000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename3=WebDavDocument(id=0, mountId=1, parentId=1, name=filename3, isDirectory=true,
03-19 14:44:40.398 31031 31077 davx5 D displayName=filename3, mimeType=null, eTag=null, lastModified=1638398313000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename4=WebDavDocument(id=0, mountId=1, parentId=1, name=filename4, isDirectory=true, displayName=filename4, mimeType=null, eTag=null, lastModified=1644355880000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename5=WebDavDocument(id=0, mountId=1, parentId=1, name=filename5, isDirectory=true, displayName=filename5, mimeType=null, eTag=null, lastModified=1646202001000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename6=WebDavDocument(id=0, mountId=1, parentId=1, name=filename6, isDirectory=true, displayName=filename6, mimeType=null, eTag=null, lastModified=1647503361000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename7=WebDavDocument(id=0, mountId=1, parentId=1, name=filename7, isDirectory=true, displayName=filename7, mimeType=null, eTag=null, lastModified=1646038141000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename8=WebDavDocument(id=0, mountId=1, parentId=1, name=filename8, isDirectory=true, displayName=filename8, mimeType=null, eTag=null, lastModified=1619143128000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null), filename9=WebDavDocument(id=0, mountId=1, parentId=1, name=filename9, isDirectory=true, displayName=filename9, mimeType=null, eTag=null, lastModified=1550083727000, size=null, mayBind=null, mayUnbind=null, mayWriteContent=null, quotaAvailable=null, quotaUsed=null)}
03-19 14:44:40.400 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename1, _display_name=filename1, mime_type=application/octet-stream, last_modified=1617953977000, _size=36, flags=454, document_id=2}]
03-19 14:44:40.400 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename2, _display_name=filename2, mime_type=vnd.android.filename6/directory, last_modified=1645468212000, flags=460, document_id=3}]
03-19 14:44:40.401 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename3, _display_name=filename3, mime_type=vnd.android.filename6/directory, last_modified=1638398313000, flags=460, document_id=4}]
03-19 14:44:40.401 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename4, _display_name=filename4, mime_type=vnd.android.filename6/directory, last_modified=1644355880000, flags=460, document_id=5}]
03-19 14:44:40.401 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename5, _display_name=filename5, mime_type=vnd.android.filename6/directory, last_modified=1646202001000, flags=460, document_id=6}]
03-19 14:44:40.402 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename6, _display_name=filename6, mime_type=vnd.android.filename6/directory, last_modified=1647503361000, flags=460, document_id=7}]
03-19 14:44:40.402 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename7, _display_name=filename7, mime_type=vnd.android.filename6/directory, last_modified=1646038141000, flags=460, document_id=8}]
03-19 14:44:40.402 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename8, _display_name=filename8, mime_type=vnd.android.filename6/directory, last_modified=1619143128000, flags=460, document_id=9}]
03-19 14:44:40.403 31031 31077 davx5 D [webdav.DavDocumentsProvider] Found child: Bundle[{summary=filename9, _display_name=filename9, mime_type=vnd.android.filename6/directory, last_modified=1550083727000, flags=460, document_id=10}]
03-19 14:44:40.412 31031 31045 davx5 D [webdav.DavDocumentsProvider] WebDAV queryChildDocuments 1 null nullthere's still no information about why it is slow
From logs above, there are WebDAV requests after InterruptedException. Maybe Material Files did not wait long enough for DAVx5?
superiums
commented
2 years ago How to add a webdav access ? i'm also using 1.4.0 but there'are sftp and smb servers only.
yan12125
commented
2 years ago I configured DAVx5 and followed steps about Material Files here: https://github.com/bitfireAT/davx5-ose/discussions/10, but as mentioned above, there are issues around interaction between DAVx5 and Material Files.
superiums
commented
2 years ago thanks very much. i will try it.
zhanghai
commented
2 years ago I think I have found the root cause of this regression (loading never finishes) in addition to the crash fix at https://github.com/zhanghai/MaterialFiles/issues/711#issuecomment-1072111037 .
Android DocumentsProvider has a DocumentsContract.EXTRA_LOADING extra that can be set on a returned Cursor object, and the convention is that the provider need to notify the caller that the loading has finished after the loading cursor is returned. However since IPC is inherently async, by then time the caller registers for change notification, the notification may have already been fired, resulting in the caller randomly waiting indefinitely for it.
So this is kind of broken in its design and I have to work around it... (Note that not even DocumentsUI is handling this properly - it just times out.)
zhanghai
commented
2 years ago Hi @yan12125
I spotted a potential issue with the design of DocumentsProvider and added a workaround in master (6256e71). Could you test if it fixes the issue with DAVx5? I can't easily test it because I don't use WebDAV at all.
I'll be waiting for your response so that I may fix this in the patch release v1.4.1 which I'm planning to release this weekend.
(Note for myself: DavDocumentsProvider, SeafileProvider)
yan12125
commented
2 years ago Thanks a lot for the update! It seems there are fewer exceptions with 6256e71ff6bb492b7b9eec8ab428d5d0c32dc589, but still some. I got 3 InterruptedExceptions after walking around different folders in my webdav share; two of them happened after all DAVx5 requests are logged, and one of them is in the middle of DAVx5 request logs.
Here are logs for the exception happened in the middle of DAVx5 requests: (folder names redacted)
03-26 23:07:04.216 25111 25111 System.err W java8.nio.file.FileSystemException: /foo/bar: java.lang.InterruptedException
03-26 23:07:04.216 25111 25111 System.err W at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:264)
03-26 23:07:04.216 25111 25111 System.err W at java8.nio.file.Files.newDirectoryStream(Files.java:457)
03-26 23:07:04.216 25111 25111 System.err W at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:152)
03-26 23:07:04.217 25111 25111 System.err W at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.kt:42)
03-26 23:07:04.217 25111 25111 System.err W at me.zhanghai.android.files.filelist.FileListLiveData.$r8$lambda$zAlkFlJrlhzk0ZkhSD7tgqwgsQc(Unknown Source:0)
03-26 23:07:04.217 25111 25111 System.err W at me.zhanghai.android.files.filelist.FileListLiveData$$ExternalSyntheticLambda0.call(Unknown Source:2)
03-26 23:07:04.217 25111 25111 System.err W at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-26 23:07:04.217 25111 25111 System.err W at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-26 23:07:04.217 25111 25111 System.err W at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-26 23:07:04.217 25111 25111 System.err W at java.lang.Thread.run(Thread.java:764)
03-26 23:07:04.217 25111 25111 System.err W Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-26 23:07:04.217 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryUntilNotLoading(DocumentResolver.kt:606)
03-26 23:07:04.217 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.query(DocumentResolver.kt:563)
03-26 23:07:04.218 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.kt:400)
03-26 23:07:04.218 25111 25111 System.err W at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:262)
03-26 23:07:04.218 25111 25111 System.err W ... 9 more
03-26 23:07:04.218 25111 25111 System.err W Caused by: java.lang.InterruptedException
03-26 23:07:04.218 25111 25111 System.err W at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1350)
03-26 23:07:04.218 25111 25111 System.err W at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:278)
03-26 23:07:04.218 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryUntilNotLoading(DocumentResolver.kt:592)
03-26 23:07:04.218 25111 25111 System.err W ... 12 moreHere are logs for two exception happened after DAVx5 logs:
03-26 23:05:53.889 25111 25111 System.err W java8.nio.file.FileSystemException: /: java.lang.InterruptedException
03-26 23:05:53.889 25111 25111 System.err W at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:264)
03-26 23:05:53.889 25111 25111 System.err W at java8.nio.file.Files.newDirectoryStream(Files.java:457)
03-26 23:05:53.889 25111 25111 System.err W at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:152)
03-26 23:05:53.889 25111 25111 System.err W at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.kt:42)
03-26 23:05:53.890 25111 25111 System.err W at me.zhanghai.android.files.filelist.FileListLiveData.$r8$lambda$zAlkFlJrlhzk0ZkhSD7tgqwgsQc(Unknown Source:0)
03-26 23:05:53.890 25111 25111 System.err W at me.zhanghai.android.files.filelist.FileListLiveData$$ExternalSyntheticLambda0.call(Unknown Source:2)
03-26 23:05:53.890 25111 25111 System.err W at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-26 23:05:53.890 25111 25111 System.err W at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-26 23:05:53.890 25111 25111 System.err W at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-26 23:05:53.890 25111 25111 System.err W at java.lang.Thread.run(Thread.java:764)
03-26 23:05:53.890 25111 25111 System.err W Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-26 23:05:53.890 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryUntilNotLoading(DocumentResolver.kt:606)
03-26 23:05:53.890 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.query(DocumentResolver.kt:563)
03-26 23:05:53.891 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.kt:400)
03-26 23:05:53.891 25111 25111 System.err W at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:262)
03-26 23:05:53.891 25111 25111 System.err W ... 9 more
03-26 23:05:53.891 25111 25111 System.err W Caused by: java.lang.InterruptedException
03-26 23:05:53.891 25111 25111 System.err W at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1326)
03-26 23:05:53.891 25111 25111 System.err W at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:232)
03-26 23:05:53.891 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryUntilNotLoading(DocumentResolver.kt:604)
03-26 23:05:53.891 25111 25111 System.err W ... 12 more
03-26 23:07:33.111 25111 25111 System.err W java8.nio.file.FileSystemException: /foo: java.lang.InterruptedException
03-26 23:07:33.111 25111 25111 System.err W at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:264)
03-26 23:07:33.111 25111 25111 System.err W at java8.nio.file.Files.newDirectoryStream(Files.java:457)
03-26 23:07:33.111 25111 25111 System.err W at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:152)
03-26 23:07:33.111 25111 25111 System.err W at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.kt:42)
03-26 23:07:33.111 25111 25111 System.err W at me.zhanghai.android.files.filelist.FileListLiveData.$r8$lambda$zAlkFlJrlhzk0ZkhSD7tgqwgsQc(Unknown Source:0)
03-26 23:07:33.111 25111 25111 System.err W at me.zhanghai.android.files.filelist.FileListLiveData$$ExternalSyntheticLambda0.call(Unknown Source:2)
03-26 23:07:33.111 25111 25111 System.err W at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-26 23:07:33.111 25111 25111 System.err W at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-26 23:07:33.111 25111 25111 System.err W at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-26 23:07:33.112 25111 25111 System.err W at java.lang.Thread.run(Thread.java:764)
03-26 23:07:33.112 25111 25111 System.err W Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-26 23:07:33.112 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryUntilNotLoading(DocumentResolver.kt:606)
03-26 23:07:33.112 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.query(DocumentResolver.kt:563)
03-26 23:07:33.112 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.kt:400)
03-26 23:07:33.112 25111 25111 System.err W at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:262)
03-26 23:07:33.112 25111 25111 System.err W ... 9 more
03-26 23:07:33.112 25111 25111 System.err W Caused by: java.lang.InterruptedException
03-26 23:07:33.112 25111 25111 System.err W at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1326)
03-26 23:07:33.113 25111 25111 System.err W at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:232)
03-26 23:07:33.113 25111 25111 System.err W at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryUntilNotLoading(DocumentResolver.kt:604)
03-26 23:07:33.113 25111 25111 System.err W ... 12 more
bbhtt
commented
2 years ago Hello, I did a debug build on master (6256e71ff6bb492b7b9eec8ab428d5d0c32dc589)
I can still see the java8.nio.file.FileSystemException error in adb while trying to access the WebDAV mount. Also the folders still open pretty slowly (I can see the spinner). But the crash seems to be fixed.
03-26 20:51:38.337 17723 17723 W System.err: java8.nio.file.FileSystemException: /MSC: java.lang.InterruptedException
03-26 20:51:38.337 17723 17723 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:264)
03-26 20:51:38.338 17723 17723 W System.err: at java8.nio.file.Files.newDirectoryStream(Files.java:457)
03-26 20:51:38.338 17723 17723 W System.err: at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:152)
03-26 20:51:38.338 17723 17723 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.kt:42)
03-26 20:51:38.338 17723 17723 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.$r8$lambda$zAlkFlJrlhzk0ZkhSD7tgqwgsQc(Unknown Source:0)
03-26 20:51:38.338 17723 17723 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData$$ExternalSyntheticLambda0.call(Unknown Source:2)
03-26 20:51:38.338 17723 17723 W System.err: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-26 20:51:38.338 17723 17723 W System.err: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-26 20:51:38.338 17723 17723 W System.err: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-26 20:51:38.338 17723 17723 W System.err: at java.lang.Thread.run(Thread.java:919)
03-26 20:51:38.339 17723 17723 W System.err: Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-26 20:51:38.339 17723 17723 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryUntilNotLoading(DocumentResolver.kt:606)
03-26 20:51:38.339 17723 17723 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.query(DocumentResolver.kt:563)
03-26 20:51:38.339 17723 17723 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.kt:400)
03-26 20:51:38.339 17723 17723 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:262)
03-26 20:51:38.339 17723 17723 W System.err: ... 9 more
03-26 20:51:38.340 17723 17723 W System.err: Caused by: java.lang.InterruptedException
03-26 20:51:38.340 17723 17723 W System.err: at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1024)
03-26 20:51:38.341 17723 17723 W System.err: at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1334)
03-26 20:51:38.341 17723 17723 W System.err: at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:232)
03-26 20:51:38.341 17723 17723 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryUntilNotLoading(DocumentResolver.kt:604)
03-26 20:51:38.341 17723 17723 W System.err: ... 12 more
03-26 20:51:38.354 17723 17723 V Toast : Toast SHOW: android.widget.Toast@f98f964 view = android.widget.LinearLayout{776d7cd V.E...... ......I. 0,0-0,0} caller: me.zhanghai.android.files.util.ContextExtensionsKt.showToast:214 Hi @yan12125 and @bbhtt,
Having InterruptedException in the log might be fine because it can happen normally when you navigate away from a directory when it is currently loading, or it has received a change nofiication and is loading again in the background, as a result of that load being no longer needed and cancelled.
The change in v1.4.0 is that the Java NIO2 FileSystemProvider implementation in this app for DocumentsProvider is changed to always wait for a result that doesn't have EXTRA_LOADING before returning the data. This is important for the case of file operations because otherwise the file operation may happen according to a stale cache and result in missing files/incorrect behavior. There isn't a way to return partial results in Java NIO2 FileSystemProvider so I had to make it always wait for the non-loading result before returning. (Note that this seems to be the same with GNOME Nautilus.)
The expected behavior here is that loading of directories will indeed become slower because we no longer display the cached result. The bug I was trying to fix in 6256e71 is that theoratically if the DocumentsProvider is notifying us the loading has finished too fast, we might miss that notification so that we'll wait indefinitely. But I'm actually not sure if it is a bug that you are seeing.
So could you help test the following things?
bbhtt
commented
2 years ago I reverted https://github.com/zhanghai/MaterialFiles/commit/6256e71ff6bb492b7b9eec8ab428d5d0c32dc589 on my branch and built from it.
1,2. I don't see any indefinite hang in loading only the delay and exceptions described earlier. Are there any know steps to reproduce that issue? Because I don't think I ever came across such a hang.
Logs:
03-27 13:13:31.948 9249 9249 W System.err: java8.nio.file.FileSystemException: /: java.lang.InterruptedException
03-27 13:13:31.948 9249 9249 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:264)
03-27 13:13:31.948 9249 9249 W System.err: at java8.nio.file.Files.newDirectoryStream(Files.java:457)
03-27 13:13:31.948 9249 9249 W System.err: at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:152)
03-27 13:13:31.949 9249 9249 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.kt:42)
03-27 13:13:31.949 9249 9249 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.$r8$lambda$zAlkFlJrlhzk0ZkhSD7tgqwgsQc(Unknown Source:0)
03-27 13:13:31.949 9249 9249 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData$$ExternalSyntheticLambda0.call(Unknown Source:2)
03-27 13:13:31.949 9249 9249 W System.err: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-27 13:13:31.949 9249 9249 W System.err: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-27 13:13:31.949 9249 9249 W System.err: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-27 13:13:31.949 9249 9249 W System.err: at java.lang.Thread.run(Thread.java:919)
03-27 13:13:31.949 9249 9249 W System.err: Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-27 13:13:31.949 9249 9249 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:604)
03-27 13:13:31.950 9249 9249 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.kt:400)
03-27 13:13:31.950 9249 9249 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:262)
03-27 13:13:31.950 9249 9249 W System.err: ... 9 more
03-27 13:13:31.950 9249 9249 W System.err: Caused by: java.lang.InterruptedException
03-27 13:13:31.950 9249 9249 W System.err: at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:84)
03-27 13:13:31.950 9249 9249 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
03-27 13:13:31.950 9249 9249 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source:1)
03-27 13:13:31.950 9249 9249 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
03-27 13:13:31.950 9249 9249 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source:1)
03-27 13:13:31.951 9249 9249 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:585)
03-27 13:13:31.951 9249 9249 W System.err: ... 11 more
03-27 13:14:58.468 9465 9465 W System.err: java8.nio.file.FileSystemException: /: java.lang.InterruptedException
03-27 13:14:58.468 9465 9465 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:264)
03-27 13:14:58.469 9465 9465 W System.err: at java8.nio.file.Files.newDirectoryStream(Files.java:457)
03-27 13:14:58.469 9465 9465 W System.err: at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:152)
03-27 13:14:58.469 9465 9465 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.kt:42)
03-27 13:14:58.469 9465 9465 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.$r8$lambda$zAlkFlJrlhzk0ZkhSD7tgqwgsQc(Unknown Source:0)
03-27 13:14:58.469 9465 9465 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData$$ExternalSyntheticLambda0.call(Unknown Source:2)
03-27 13:14:58.469 9465 9465 W System.err: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-27 13:14:58.469 9465 9465 W System.err: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-27 13:14:58.469 9465 9465 W System.err: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-27 13:14:58.469 9465 9465 W System.err: at java.lang.Thread.run(Thread.java:919)
03-27 13:14:58.470 9465 9465 W System.err: Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-27 13:14:58.470 9465 9465 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:604)
03-27 13:14:58.470 9465 9465 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.kt:400)
03-27 13:14:58.470 9465 9465 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:262)
03-27 13:14:58.470 9465 9465 W System.err: ... 9 more
03-27 13:14:58.471 9465 9465 W System.err: Caused by: java.lang.InterruptedException
03-27 13:14:58.471 9465 9465 W System.err: at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:84)
03-27 13:14:58.471 9465 9465 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
03-27 13:14:58.471 9465 9465 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source:1)
03-27 13:14:58.471 9465 9465 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
03-27 13:14:58.471 9465 9465 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source:1)
03-27 13:14:58.471 9465 9465 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:585)
03-27 13:14:58.471 9465 9465 W System.err: ... 11 more
03-27 13:15:00.433 9465 9465 W System.err: java8.nio.file.FileSystemException: /: java.lang.InterruptedException
03-27 13:15:00.433 9465 9465 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:264)
03-27 13:15:00.433 9465 9465 W System.err: at java8.nio.file.Files.newDirectoryStream(Files.java:457)
03-27 13:15:00.433 9465 9465 W System.err: at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:152)
03-27 13:15:00.433 9465 9465 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.kt:42)
03-27 13:15:00.433 9465 9465 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.$r8$lambda$zAlkFlJrlhzk0ZkhSD7tgqwgsQc(Unknown Source:0)
03-27 13:15:00.433 9465 9465 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData$$ExternalSyntheticLambda0.call(Unknown Source:2)
03-27 13:15:00.434 9465 9465 W System.err: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-27 13:15:00.434 9465 9465 W System.err: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-27 13:15:00.434 9465 9465 W System.err: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-27 13:15:00.434 9465 9465 W System.err: at java.lang.Thread.run(Thread.java:919)
03-27 13:15:00.434 9465 9465 W System.err: Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-27 13:15:00.434 9465 9465 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:604)
03-27 13:15:00.434 9465 9465 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.kt:400)
03-27 13:15:00.434 9465 9465 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:262)
03-27 13:15:00.434 9465 9465 W System.err: ... 9 more
03-27 13:15:00.435 9465 9465 W System.err: Caused by: java.lang.InterruptedException
03-27 13:15:00.435 9465 9465 W System.err: at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:84)
03-27 13:15:00.435 9465 9465 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
03-27 13:15:00.435 9465 9465 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source:1)
03-27 13:15:00.435 9465 9465 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
03-27 13:15:00.435 9465 9465 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source:1)
03-27 13:15:00.435 9465 9465 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:585)
03-27 13:15:00.435 9465 9465 W System.err: ... 11 more
03-27 13:21:42.189 9958 9958 W System.err: java8.nio.file.FileSystemException: /: java.lang.InterruptedException
03-27 13:21:42.189 9958 9958 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:264)
03-27 13:21:42.189 9958 9958 W System.err: at java8.nio.file.Files.newDirectoryStream(Files.java:457)
03-27 13:21:42.189 9958 9958 W System.err: at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:152)
03-27 13:21:42.190 9958 9958 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.kt:42)
03-27 13:21:42.190 9958 9958 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.$r8$lambda$zAlkFlJrlhzk0ZkhSD7tgqwgsQc(Unknown Source:0)
03-27 13:21:42.190 9958 9958 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData$$ExternalSyntheticLambda0.call(Unknown Source:2)
03-27 13:21:42.190 9958 9958 W System.err: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-27 13:21:42.190 9958 9958 W System.err: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-27 13:21:42.190 9958 9958 W System.err: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-27 13:21:42.190 9958 9958 W System.err: at java.lang.Thread.run(Thread.java:919)
03-27 13:21:42.191 9958 9958 W System.err: Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-27 13:21:42.191 9958 9958 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:604)
03-27 13:21:42.191 9958 9958 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.kt:400)
03-27 13:21:42.191 9958 9958 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:262)
03-27 13:21:42.191 9958 9958 W System.err: ... 9 more
03-27 13:21:42.192 9958 9958 W System.err: Caused by: java.lang.InterruptedException
03-27 13:21:42.192 9958 9958 W System.err: at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:84)
03-27 13:21:42.192 9958 9958 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
03-27 13:21:42.192 9958 9958 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source:1)
03-27 13:21:42.192 9958 9958 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
03-27 13:21:42.192 9958 9958 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source:1)
03-27 13:21:42.192 9958 9958 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:585)
03-27 13:21:42.192 9958 9958 W System.err: ... 11 more
03-27 13:21:42.488 9958 9958 W System.err: java8.nio.file.FileSystemException: /: java.lang.InterruptedException
03-27 13:21:42.488 9958 9958 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:264)
03-27 13:21:42.488 9958 9958 W System.err: at java8.nio.file.Files.newDirectoryStream(Files.java:457)
03-27 13:21:42.488 9958 9958 W System.err: at me.zhanghai.android.files.provider.common.PathExtensionsKt.newDirectoryStream(PathExtensions.kt:152)
03-27 13:21:42.489 9958 9958 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.loadValue$lambda-1(FileListLiveData.kt:42)
03-27 13:21:42.489 9958 9958 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData.$r8$lambda$zAlkFlJrlhzk0ZkhSD7tgqwgsQc(Unknown Source:0)
03-27 13:21:42.489 9958 9958 W System.err: at me.zhanghai.android.files.filelist.FileListLiveData$$ExternalSyntheticLambda0.call(Unknown Source:2)
03-27 13:21:42.489 9958 9958 W System.err: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-27 13:21:42.489 9958 9958 W System.err: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-27 13:21:42.489 9958 9958 W System.err: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-27 13:21:42.489 9958 9958 W System.err: at java.lang.Thread.run(Thread.java:919)
03-27 13:21:42.489 9958 9958 W System.err: Caused by: me.zhanghai.android.files.provider.content.resolver.ResolverException: java.lang.InterruptedException
03-27 13:21:42.489 9958 9958 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:604)
03-27 13:21:42.489 9958 9958 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.queryChildren(DocumentResolver.kt:400)
03-27 13:21:42.490 9958 9958 W System.err: at me.zhanghai.android.files.provider.document.DocumentFileSystemProvider.newDirectoryStream(DocumentFileSystemProvider.kt:262)
03-27 13:21:42.490 9958 9958 W System.err: ... 9 more
03-27 13:21:42.490 9958 9958 W System.err: Caused by: java.lang.InterruptedException
03-27 13:21:42.490 9958 9958 W System.err: at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:84)
03-27 13:21:42.490 9958 9958 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
03-27 13:21:42.490 9958 9958 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source:1)
03-27 13:21:42.490 9958 9958 W System.err: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
03-27 13:21:42.490 9958 9958 W System.err: at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source:1)
03-27 13:21:42.490 9958 9958 W System.err: at me.zhanghai.android.files.provider.document.resolver.DocumentResolver.waitUntilChanged(DocumentResolver.kt:585)
03-27 13:21:42.491 9958 9958 W System.err: ... 11 morePlease see the screencap attached, this is from master (42b50cb):
... when you navigate away from a directory when it is currently loading, or it has received a change notification and is loading again in the background, as a result of that load being no longer needed and cancelled.
Yes, the toast usually appears when the loading has finished and I pull down to refresh to trigger it (like in the above video) or while navigating between directories.
yan12125
commented
2 years ago Does the loading for DAVx5 sometimes hang indefinitely before
Seems not. I tried 6256e71ff6bb492b7b9eec8ab428d5d0c32dc589 and e57ed72f075b3355076046e2b6533f3254b66c89 (the parent commit of 6256e71ff6bb492b7b9eec8ab428d5d0c32dc589). On both commits, I see repeatedly loading in some cases, and they ended up in a toast about InterruptedException. That's not "hang indefinitely" I guess. I will send you video clips later - I don't want to share screenshots with filenames for privacy concerns.
How slow is the loading since v1.4.0 (after https://github.com/zhanghai/MaterialFiles/commit/6256e71ff6bb492b7b9eec8ab428d5d0c32dc589), how many seconds does it take to load a directory? Is it still within a time that's acceptable?
Roughly 1~2 seconds. Maybe that's because I have configured my WebDAV share with time-consuming authentication (sha512 with 656000 rounds). That's OK for me.
zhanghai
commented
2 years ago I see. It seems to me in this case I may have to revert the fix for #603 and consider a better fix. However, reverting that probably means recursively copying files will likely only copy one level of files.
So to which level does this repeatitive loading impact usability of the app, compared to not being able to copy recursively? Which one do you think would be the lesser evil?
yan12125
commented
2 years ago I don't have the need for recursive copy yet, and such "repeatedly loading" rarely happens, either (like roughly once for every 20~30 times of switching directories). For me either is fine.
bbhtt
commented
2 years ago Recursive copying is not a priority for me either as I rarely copy files from a remote mount and if I do I can create the folder structure in the target drive and use "Select All" to copy all files directly.
I can live with the current slow loading as well as long as the delay stays within an acceptable range. (The issue is a bit more frequent for me.)
So either would be fine.
Also, if the exceptions generated are a non-issue, maybe suppressing the toast (if doable) is a good idea? Having that toast pop up now and then during navigation etc. does feel a little bit annoying and points to an issue needing attention.
zhanghai
commented
2 years ago I see, I'll keep the fix then. Regarding suppressing InterruptedException - it's a bit more complicated so I'll leave it as-is.
zhanghai
commented
2 years ago Punting to 1.5.0 for resolving the repeatedly loading issue.
Using the google play version.
Android version: 10 (Patch level: February 2022)
WebDAV is Nextcloud and sync adapter is DAVx⁵.
Output:
Crashed here I think:
I can see this (
java8.nio.file.FileSystemException: /: java.lang.InterruptedException) as a toast while trying to open the remote folders. It either crashes on tap or loads the folder contents very slowly and then crashes. Issue was not present in previous version, I think it started with the 1.4.0 update.Please let me know if anything else is needed.