Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

[Bug]: implicit hydration triggered by the client itself. 0x800701AA & 0x80070185 Server returns 404 to client #7747

Open
5 of 8 tasks
bigretromike opened this issue Jan 10, 2025 · 5 comments

Comments

@bigretromike
Copy link

⚠️ Before submitting, please verify the following: ⚠️

Bug description

While using nextcloud desktop client some files are locking up and Im unable to open(download) them while using VFS.
Error on windows prompt is :0x800701AA
I tried adding site to trusted sites in Internet options - didnt helped
I saw that nginx proxy said few times that sharred session cache is full - I lower the timeout and double capacity

Steps to reproduce

  1. start pc
  2. double check if client is green (synced)
  3. double click on file that is not stored locally and being serverd via VFS.
  4. randomly get 0x800701AA and no access to file, retry wont help.
  5. (workaround) somethines restarting client helps

Expected behavior

When using VFS I would like to being able to access every file that is shared with me (or on my account)

Which files are affected by this bug

Randome files: pdf, lnk, txt

Operating system

Windows

Which version of the operating system you are running.

Windows 11

Package

Other

Nextcloud Server version

30.0.4 (before I been on 29.0.10 and the same thing was happening)

Nextcloud Desktop Client version

3.15.3 (stable)

Is this bug present after an update or on a fresh install?

Updated from a minor version (ex. 3.4.2 to 3.4.4)

Are you using the Nextcloud Server Encryption module?

Encryption is Disabled

Are you using an external user-backend?

  • Default internal user-backend
  • LDAP/ Active Directory
  • SSO - SAML
  • Other

Nextcloud Server logs

No logs on server site has been recorded - last one are from few hours before.

Additional info

CLIENT.LOG

2025-01-10 22:13:08:105 [ critical nextcloud.sync.vfs.cfapi.wrapper C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\vfs\cfapi\cfapiwrapper.cpp:111 ]:	Couldn't send transfer info "1db54b8a079e561" : -2147024498 "Operacja w chmurze została anulowana przez użytkownika."
2025-01-10 22:13:08:106 [ info nextcloud.gui.folderwatcher C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\folderwatcher.cpp:252 ]:	Detected changes in paths: QSet("C:/Users/Lenovo/Nextcloud/Desktop/Total Commander 64 bit.lnk")
2025-01-10 22:13:08:106 [ info nextcloud.gui.folder C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\folder.cpp:668 ]:	Ignoring spurious notification for file "Desktop/Total Commander 64 bit.lnk"
2025-01-10 22:13:08:108 [ info nextcloud.gui.shellextensions.server C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\shellextensionsserver.cpp:126 ]:	"Desktop/Total Commander 64 bit.lnk"  record._lastShareStateFetchedTimestamp has less than  120000  ms difference with QDateTime::currentMSecsSinceEpoch(). Returning data from SyncJournal.
2025-01-10 22:13:08:210 [ info nextcloud.sync.credentials.webflow C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\creds\webflowcredentials.cpp:405 ]:	request finished
2025-01-10 22:13:08:210 [ info nextcloud.sync.networkjob.jsonapi C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\networkjobs.cpp:972 ]:	JsonApiJob of QUrl("https://cloud.test.local/ocs/v2.php/apps/user_status/api/v1/user_status?format=json") FINISHED WITH STATUS "OK"
2025-01-10 22:13:08:210 [ info nextcloud.sync.credentials.webflow C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\creds\webflowcredentials.cpp:405 ]:	request finished
2025-01-10 22:13:08:210 [ info nextcloud.sync.networkjob.jsonapi C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\networkjobs.cpp:972 ]:	JsonApiJob of QUrl("https://cloud.test.local/ocs/v2.php/apps/notifications/api/v2/notifications?format=json") FINISHED WITH STATUS "OK"
2025-01-10 22:13:08:210 [ warning nextcloud.sync.networkjob.jsonapi C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\networkjobs.cpp:993 ]:	Nothing changed so nothing to retrieve - status code:  304
2025-01-10 22:13:08:217 [ info nextcloud.gui.servernotification C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\tray\notificationhandler.cpp:75 ]:	Status code  304  Not Modified - No new notifications.
2025-01-10 22:13:08:270 [ info nextcloud.sync.credentials.webflow C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\creds\webflowcredentials.cpp:405 ]:	request finished
2025-01-10 22:13:08:270 [ info nextcloud.sync.networkjob.propfind C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\networkjobs.cpp:658 ]:	PROPFIND of QUrl("https://cloud.test.local/remote.php/dav/files/test-michal/") FINISHED WITH STATUS "OK"
2025-01-10 22:13:09:062 [ info nextcloud.gui.shellextensions.server C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\shellextensionsserver.cpp:126 ]:	"Desktop/Total Commander 64 bit.lnk"  record._lastShareStateFetchedTimestamp has less than  120000  ms difference with QDateTime::currentMSecsSinceEpoch(). Returning data from SyncJournal.
2025-01-10 22:13:09:062 [ critical nextcloud.sync.vfs.cfapi.wrapper C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\vfs\cfapi\cfapiwrapper.cpp:166 ]:	implicit hydration triggered by the client itself. Will lead to a deadlock. Cancel "C:\\Users\\Lenovo\\Nextcloud\\Desktop\\Total Commander 64 bit.lnk" "1db54b8a079e562"
2025-01-10 22:13:09:062 [ critical nextcloud.sync.vfs.cfapi.wrapper C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\vfs\cfapi\cfapiwrapper.cpp:166 ]:	implicit hydration triggered by the client itself. Will lead to a deadlock. Cancel "C:\\Users\\Lenovo\\Nextcloud\\Desktop\\Total Commander 64 bit.lnk" "1db54b8a079e562"
2025-01-10 22:13:09:094 [ info nextcloud.gui.shellextensions.server C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\shellextensionsserver.cpp:126 ]:	"Desktop/Total Commander 64 bit.lnk"  record._lastShareStateFetchedTimestamp has less than  120000  ms difference with QDateTime::currentMSecsSinceEpoch(). Returning data from SyncJournal.
2025-01-10 22:13:12:306 [ info nextcloud.gui.folder.manager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\folderman.cpp:965 ]:	Etag poll timer timeout
2025-01-10 22:13:12:306 [ info nextcloud.gui.folder.manager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\folderman.cpp:969 ]:	Folders to sync: 1
2025-01-10 22:13:12:306 [ info nextcloud.gui.folder.manager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\folderman.cpp:979 ]:	Number of folders that don't use push notifications: 1
2025-01-10 22:13:12:306 [ info nextcloud.gui.folder.manager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\folderman.cpp:996 ]:	Run etag job on folder OCC::Folder(0x24c9e9eb520)
2025-01-10 22:13:12:306 [ info nextcloud.gui.folder C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\folder.cpp:350 ]:	Trying to check "https://cloud.test.local/remote.php/dav/files/test-michal/" for changes via ETag check. (time since last sync: 714 s)
2025-01-10 22:13:12:306 [ info nextcloud.sync.accessmanager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\accessmanager.cpp:67 ]:	6 "PROPFIND" "https://cloud.test.local/remote.php/dav/files/test-michal/" has X-Request-ID "ff1b72d4-6b41-4250-8562-db108e59bcc6"
2025-01-10 22:13:12:306 [ info nextcloud.sync.networkjob C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\abstractnetworkjob.cpp:365 ]:	OCC::RequestEtagJob created for "https://cloud.test.local" + "/" "OCC::Folder"
2025-01-10 22:13:12:527 [ info nextcloud.sync.credentials.webflow C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\creds\webflowcredentials.cpp:405 ]:	request finished
2025-01-10 22:13:12:527 [ info nextcloud.sync.networkjob.etag C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\networkjobs.cpp:101 ]:	Request Etag of QUrl("https://cloud.test.local/remote.php/dav/files/test-michal/") FINISHED WITH STATUS "OK"
2025-01-10 22:13:12:560 [ info nextcloud.sync.accessmanager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\accessmanager.cpp:67 ]:	2 "" "https://cloud.test.local/ocs/v2.php/apps/user_status/api/v1/user_status?format=json" has X-Request-ID "87382944-9263-436e-9c87-603527451133"
2025-01-10 22:13:12:560 [ info nextcloud.sync.networkjob C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\abstractnetworkjob.cpp:365 ]:	OCC::JsonApiJob created for "https://cloud.test.local" + "/ocs/v2.php/apps/user_status/api/v1/user_status" "OCC::UserStatusConnector"
2025-01-10 22:13:12:704 [ info nextcloud.sync.credentials.webflow C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\creds\webflowcredentials.cpp:405 ]:	request finished
2025-01-10 22:13:12:704 [ info nextcloud.sync.networkjob.jsonapi C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\networkjobs.cpp:972 ]:	JsonApiJob of QUrl("https://cloud.test.local/ocs/v2.php/apps/user_status/api/v1/user_status?format=json") FINISHED WITH STATUS "OK"
2025-01-10 22:13:15:005 [ warning nextcloud.sync.configfile C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\configfile.cpp:735 ]:	Default update channel is "stable"
2025-01-10 22:13:15:008 [ warning nextcloud.sync.credentials.keychainchunk C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\creds\keychainchunk.cpp:360 ]:	Unable to read "Nextcloud_proxy-password" chunk "0" "Password entry not found"
2025-01-10 22:13:15:011 [ info nextcloud.sync.accessmanager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\accessmanager.cpp:67 ]:	6 "PROPFIND" "https://cloud.test.local/remote.php/dav/files/test-michal/" has X-Request-ID "0743f5db-2342-4276-8e60-c8b28dd8e712"
2025-01-10 22:13:15:011 [ info nextcloud.sync.networkjob C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\abstractnetworkjob.cpp:365 ]:	OCC::LsColJob created for "https://cloud.test.local" + "/" ""
2025-01-10 22:13:15:016 [ warning nextcloud.sync.credentials.keychainchunk C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\creds\keychainchunk.cpp:360 ]:	Unable to read "Nextcloud_proxy-password" chunk "0" "Password entry not found"
2025-01-10 22:13:15:017 [ info nextcloud.sync.clientsideencryption C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\clientsideencryption.cpp:776 ]:	Initializing
2025-01-10 22:13:15:017 [ info nextcloud.sync.clientsideencryption C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\clientsideencryption.cpp:778 ]:	No Client side encryption available on server.
2025-01-10 22:13:15:017 [ info nextcloud.sync.accessmanager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\accessmanager.cpp:67 ]:	6 "PROPFIND" "https://cloud.test.local/remote.php/dav/files/test-michal/" has X-Request-ID "a04cf1e0-88c8-468a-82de-493f1b7d084f"
2025-01-10 22:13:15:017 [ info nextcloud.sync.networkjob C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\abstractnetworkjob.cpp:365 ]:	OCC::LsColJob created for "https://cloud.test.local" + "/" ""
2025-01-10 22:13:15:018 [ info nextcloud.gui.account.settings C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\accountsettings.cpp:1365 ]:	Account "[email protected]" Client Side Encryption false
2025-01-10 22:13:15:018 [ info nextcloud.sync.accessmanager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\accessmanager.cpp:67 ]:	2 "" "https://cloud.test.local/ocs/v1.php/cloud/user?format=json" has X-Request-ID "4fccb29d-1de3-4bb6-b84a-17c198a4bb2a"
2025-01-10 22:13:15:018 [ info nextcloud.sync.networkjob C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\abstractnetworkjob.cpp:365 ]:	OCC::JsonApiJob created for "https://cloud.test.local" + "ocs/v1.php/cloud/user" "OCC::UserInfo"
2025-01-10 22:13:15:018 [ info nextcloud.sync.accessmanager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\accessmanager.cpp:67 ]:	2 "" "https://cloud.test.local/ocs/v1.php/cloud/user?format=json" has X-Request-ID "6e1d75b6-06f4-484a-807c-dfe3a041d50a"
2025-01-10 22:13:15:018 [ info nextcloud.sync.networkjob C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\abstractnetworkjob.cpp:365 ]:	OCC::JsonApiJob created for "https://cloud.test.local" + "ocs/v1.php/cloud/user" "OCC::UserInfo"
2025-01-10 22:13:15:026 [ info nextcloud.sync.accessmanager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\accessmanager.cpp:67 ]:	2 "" "https://cloud.test.local/ocs/v1.php/cloud/user?format=json" has X-Request-ID "a0ad5571-1d7c-4541-b659-c956c1c856a6"
2025-01-10 22:13:15:026 [ info nextcloud.sync.networkjob C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\abstractnetworkjob.cpp:365 ]:	OCC::JsonApiJob created for "https://cloud.test.local" + "ocs/v1.php/cloud/user" "OCC::UserInfo"
2025-01-10 22:13:15:307 [ info nextcloud.sync.credentials.webflow C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\creds\webflowcredentials.cpp:405 ]:	request finished
2025-01-10 22:13:15:307 [ info nextcloud.sync.networkjob.jsonapi C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\networkjobs.cpp:972 ]:	JsonApiJob of QUrl("https://cloud.test.local/ocs/v1.php/cloud/user?format=json") FINISHED WITH STATUS "OK"
2025-01-10 22:13:15:308 [ info nextcloud.sync.accessmanager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\accessmanager.cpp:67 ]:	2 "" "https://cloud.test.local/remote.php/dav/avatars/test-michal/128.png" has X-Request-ID "c13ddb7c-2287-4178-bf93-44928bdbcd01"
2025-01-10 22:13:15:308 [ info nextcloud.sync.networkjob C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\abstractnetworkjob.cpp:365 ]:	OCC::AvatarJob created for "https://cloud.test.local" + "" "OCC::UserInfo"
2025-01-10 22:13:15:319 [ info nextcloud.sync.credentials.webflow C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\creds\webflowcredentials.cpp:405 ]:	request finished
2025-01-10 22:13:15:319 [ info nextcloud.sync.networkjob.lscol C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\networkjobs.cpp:386 ]:	LSCOL of QUrl("https://cloud.test.local/remote.php/dav/files/test-michal/") FINISHED WITH STATUS "OK"
2025-01-10 22:13:15:622 [ info nextcloud.sync.credentials.webflow C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\creds\webflowcredentials.cpp:405 ]:	request finished
2025-01-10 22:13:15:622 [ info nextcloud.sync.networkjob.jsonapi C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\networkjobs.cpp:972 ]:	JsonApiJob of QUrl("https://cloud.test.local/ocs/v1.php/cloud/user?format=json") FINISHED WITH STATUS "OK"
2025-01-10 22:13:15:923 [ info nextcloud.sync.accessmanager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\accessmanager.cpp:67 ]:	2 "" "https://cloud.test.local/remote.php/dav/avatars/test-michal/128.png" has X-Request-ID "9aa63d34-1926-4df8-811d-61c5f264cac6"
2025-01-10 22:13:15:923 [ info nextcloud.sync.networkjob C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\abstractnetworkjob.cpp:365 ]:	OCC::AvatarJob created for "https://cloud.test.local" + "" "OCC::UserInfo"
2025-01-10 22:13:15:923 [ info nextcloud.sync.credentials.webflow C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\creds\webflowcredentials.cpp:405 ]:	request finished
2025-01-10 22:13:16:226 [ info nextcloud.sync.credentials.webflow C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\creds\webflowcredentials.cpp:405 ]:	request finished
2025-01-10 22:13:28:194 [ info nextcloud.sync.accessmanager C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\accessmanager.cpp:67 ]:	6 "PROPFIND" "https://cloud.test.local/remote.php/dav/files/test-michal/Documents" has X-Request-ID "db17c2ec-d583-486b-9180-1debc84b70fd"
2025-01-10 22:13:28:194 [ info nextcloud.sync.networkjob C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\abstractnetworkjob.cpp:365 ]:	OCC::LsColJob created for "https://cloud.test.local" + "/Documents" ""
2025-01-10 22:13:28:194 [ info nextcloud.gui.shellextensions.server C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\shellextensionsserver.cpp:144 ]:	LsColJob is already running for path:  "Documents"
2025-01-10 22:13:28:194 [ info nextcloud.gui.shellextensions.server C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\shellextensionsserver.cpp:144 ]:	LsColJob is already running for path:  "Documents"
2025-01-10 22:13:28:194 [ info nextcloud.gui.shellextensions.server C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\shellextensionsserver.cpp:144 ]:	LsColJob is already running for path:  "Documents"
2025-01-10 22:13:28:599 [ info nextcloud.sync.credentials.webflow C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\creds\webflowcredentials.cpp:405 ]:	request finished
2025-01-10 22:13:28:599 [ info nextcloud.sync.networkjob.lscol C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\libsync\networkjobs.cpp:386 ]:	LSCOL of QUrl("https://cloud.test.local/remote.php/dav/files/test-michal/Documents") FINISHED WITH STATUS "OK"
2025-01-10 22:13:28:599 [ info nextcloud.sync.database C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\common\syncjournaldb.cpp:959 ]:	Updating file record for path: "Documents/Arduino" inode: 31619 modtime: 1726128381 type: CSyncEnums::ItemTypeDirectory etag: "66e2a0fd4270c" fileId: "00250710ocol80u2q4o2" remotePerm: "DNVCKR" fileSize: 0 checksum: "" e2eMangledName: "" isE2eEncrypted: false lock: false lock owner type: 0 lock owner: "" lock owner id: "" lock editor: "" sharedByMe: false isShared: false lastShareStateFetchedTimestamp: 1736543608599 isLivePhoto false livePhotoFile ""
2025-01-10 22:13:28:599 [ info nextcloud.sync.database C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\common\syncjournaldb.cpp:959 ]:	Updating file record for path: "Documents/Default.rdp" inode: 19219 modtime: 1734563026 type: CSyncEnums::ItemTypeFile etag: "9f2d2c3275565bcee343f1ec671cf933" fileId: "00251530ocol80u2q4o2" remotePerm: "WDNVR" fileSize: 2368 checksum: "MD5:65f23e7eb4ffb36673578cd6fbcb50b4" e2eMangledName: "" isE2eEncrypted: false lock: false lock owner type: 0 lock owner: "" lock owner id: "" lock editor: "" sharedByMe: false isShared: false lastShareStateFetchedTimestamp: 1736543608599 isLivePhoto false livePhotoFile ""
2025-01-10 22:13:28:599 [ info nextcloud.sync.database C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\common\syncjournaldb.cpp:959 ]:	Updating file record for path: "Documents/KnownFolderPath.ps1" inode: 43217 modtime: 1723931998 type: CSyncEnums::ItemTypeFile etag: "5b438def15f631e82ba223cb825ef9a4" fileId: "00250186ocol80u2q4o2" remotePerm: "WDNVR" fileSize: 8489 checksum: "MD5:b49d135bb07df63919a141f8790bee87" e2eMangledName: "" isE2eEncrypted: false lock: false lock owner type: 0 lock owner: "" lock owner id: "" lock editor: "" sharedByMe: false isShared: false lastShareStateFetchedTimestamp: 1736543608599 isLivePhoto false livePhotoFile ""
2025-01-10 22:13:28:599 [ info nextcloud.sync.database C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\common\syncjournaldb.cpp:959 ]:	Updating file record for path: "Documents/NOWY" inode: 46775 modtime: 1719477215 type: CSyncEnums::ItemTypeDirectory etag: "667d23dfdab9b" fileId: "00001017ocol80u2q4o2" remotePerm: "DNVCKR" fileSize: 0 checksum: "" e2eMangledName: "" isE2eEncrypted: false lock: false lock owner type: 0 lock owner: "" lock owner id: "" lock editor: "" sharedByMe: false isShared: false lastShareStateFetchedTimestamp: 1736543608599 isLivePhoto false livePhotoFile ""
2025-01-10 22:13:28:599 [ info nextcloud.sync.database C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\common\syncjournaldb.cpp:959 ]:	Updating file record for path: "Documents/Visual Studio 2022" inode: 238095 modtime: 1724622867 type: CSyncEnums::ItemTypeDirectory etag: "66cba81363142" fileId: "00250442ocol80u2q4o2" remotePerm: "DNVCKR" fileSize: 0 checksum: "" e2eMangledName: "" isE2eEncrypted: false lock: false lock owner type: 0 lock owner: "" lock owner id: "" lock editor: "" sharedByMe: false isShared: false lastShareStateFetchedTimestamp: 1736543608599 isLivePhoto false livePhotoFile ""
2025-01-10 22:13:28:599 [ info nextcloud.sync.database C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\common\syncjournaldb.cpp:959 ]:	Updating file record for path: "Documents/modbus_test.py" inode: 6825 modtime: 1728676554 type: CSyncEnums::ItemTypeVirtualFile etag: "6abb473dc487af9099a5db5a5027a9fb" fileId: "00251640ocol80u2q4o2" remotePerm: "WDNVR" fileSize: 624 checksum: "SHA1:a6dd1cda6eda252517fa29b1623d8e38c57995c4" e2eMangledName: "" isE2eEncrypted: false lock: false lock owner type: 0 lock owner: "" lock owner id: "" lock editor: "" sharedByMe: false isShared: false lastShareStateFetchedTimestamp: 1736543608599 isLivePhoto false livePhotoFile ""
2025-01-10 22:13:28:604 [ info nextcloud.sync.database C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\common\syncjournaldb.cpp:959 ]:	Updating file record for path: "Documents/next-cloud-fix.txt" inode: 7411 modtime: 1736465266 type: CSyncEnums::ItemTypeFile etag: "ea554b4eb9307cc62339480973b22a50" fileId: "00252425ocol80u2q4o2" remotePerm: "WDNVR" fileSize: 209 checksum: "MD5:f4da59aee6f1bc17deb177c5dc79dc50" e2eMangledName: "" isE2eEncrypted: false lock: false lock owner type: 0 lock owner: "" lock owner id: "" lock editor: "" sharedByMe: false isShared: false lastShareStateFetchedTimestamp: 1736543608604 isLivePhoto false livePhotoFile ""
2025-01-10 22:13:28:604 [ info nextcloud.sync.database C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\common\syncjournaldb.cpp:959 ]:	Updating file record for path: "Documents/nextcloud.ps1" inode: 43224 modtime: 1723931997 type: CSyncEnums::ItemTypeFile etag: "e4881d8daec360c439c3d41fe7ad49d4" fileId: "00250185ocol80u2q4o2" remotePerm: "WDNVR" fileSize: 3134 checksum: "MD5:a55d4fcb28c654b9359a6db73200c10d" e2eMangledName: "" isE2eEncrypted: false lock: false lock owner type: 0 lock owner: "" lock owner id: "" lock editor: "" sharedByMe: false isShared: false lastShareStateFetchedTimestamp: 1736543608604 isLivePhoto false livePhotoFile ""
2025-01-10 22:13:28:604 [ info nextcloud.sync.database C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\common\syncjournaldb.cpp:959 ]:	Updating file record for path: "Documents/nowe_wlasne" inode: 46781 modtime: 1723932211 type: CSyncEnums::ItemTypeDirectory etag: "66c11e33ef079" fileId: "00001070ocol80u2q4o2" remotePerm: "DNVCKR" fileSize: 0 checksum: "" e2eMangledName: "" isE2eEncrypted: false lock: false lock owner type: 0 lock owner: "" lock owner id: "" lock editor: "" sharedByMe: false isShared: false lastShareStateFetchedTimestamp: 1736543608604 isLivePhoto false livePhotoFile ""
2025-01-10 22:13:28:604 [ info nextcloud.sync.database C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\common\syncjournaldb.cpp:959 ]:	Updating file record for path: "Documents/test1.txt" inode: 43227 modtime: 1723928629 type: CSyncEnums::ItemTypeFile etag: "f47f3066166ade053ed5e76d5842a5d9" fileId: "00250179ocol80u2q4o2" remotePerm: "WDNVR" fileSize: 0 checksum: "MD5:d41d8cd98f00b204e9800998ecf8427e" e2eMangledName: "" isE2eEncrypted: false lock: false lock owner type: 0 lock owner: "" lock owner id: "" lock editor: "" sharedByMe: false isShared: false lastShareStateFetchedTimestamp: 1736543608604 isLivePhoto false livePhotoFile ""
2025-01-10 22:13:28:604 [ info nextcloud.gui.shellextensions.server C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\shellextensionsserver.cpp:166 ]:	Sending reply from LsColJob for socket:  3520  and record:  "Documents/Arduino"
2025-01-10 22:13:35:084 [ warning nextcloud.gui.folderwatcher C:\Users\User\AppData\Local\Temp\windows-27802\client-building\desktop\src\gui\folderwatcher_win.cpp:137 ]:	Error converting file name "\\\\?\\C:\\Users\\Lenovo\\Nextcloud\\Documents\\test-debug.zip" to full length, keeping original name. "WindowsError: 2: Nie można odnaleźć określonego pliku."

NGINX.ACCESS.LOG

<my_ip> - test-michal [10/Jan/2025:22:48:41 +0100] "GET /remote.php/dav/files/test-michal/Desktop/Total%20Commander%2064%20bit.lnk HTTP/1.1" 200 1080 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22631 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - - [10/Jan/2025:22:48:42 +0100] "GET /apps/logreader/api/poll?lastReqId=sZIZxAprhB83wt2C0B25 HTTP/2.0" 200 22 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0"
<my_ip> - - [10/Jan/2025:22:48:46 +0100] "GET /csrftoken HTTP/2.0" 200 124 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0"
<my_ip> - test-michal [10/Jan/2025:22:48:52 +0100] "PROPFIND /remote.php/dav/files/test-michal/ HTTP/1.1" 207 253 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - - [10/Jan/2025:22:48:53 +0100] "GET /apps/logreader/api/poll?lastReqId=sZIZxAprhB83wt2C0B25 HTTP/2.0" 200 22 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0"
<my_ip> - - [10/Jan/2025:22:48:53 +0100] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/2.0" 304 0 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0"
<my_ip> - - [10/Jan/2025:22:49:04 +0100] "GET /apps/logreader/api/poll?lastReqId=sZIZxAprhB83wt2C0B25 HTTP/2.0" 200 22 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0"
<my_ip> - - [10/Jan/2025:22:49:15 +0100] "GET /apps/logreader/api/poll?lastReqId=sZIZxAprhB83wt2C0B25 HTTP/2.0" 200 22 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0"
<my_ip> - test-michal [10/Jan/2025:22:49:17 +0100] "PROPFIND /remote.php/dav/files/test-michal/ HTTP/1.1" 207 262 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - test-michal [10/Jan/2025:22:49:21 +0100] "GET /ocs/v2.php/apps/user_status/api/v1/user_status?format=json HTTP/1.1" 200 156 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - test-michal [10/Jan/2025:22:49:21 +0100] "GET /ocs/v2.php/apps/notifications/api/v2/notifications?format=json HTTP/1.1" 304 0 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - test-michal [10/Jan/2025:22:49:22 +0100] "PROPFIND /remote.php/dav/files/test-michal/ HTTP/1.1" 207 253 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - - [10/Jan/2025:22:49:23 +0100] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/2.0" 304 0 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0"
<my_ip> - - [10/Jan/2025:22:49:26 +0100] "GET /apps/logreader/api/poll?lastReqId=sZIZxAprhB83wt2C0B25 HTTP/2.0" 200 22 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0"
<my_ip> - - [10/Jan/2025:22:49:37 +0100] "GET /apps/logreader/api/poll?lastReqId=sZIZxAprhB83wt2C0B25 HTTP/2.0" 200 22 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0"
<my_ip> - test-michal [10/Jan/2025:22:49:42 +0100] "GET /ocs/v2.php/apps/user_status/api/v1/user_status?format=json HTTP/1.1" 200 156 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22631 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - test-michal [10/Jan/2025:22:49:42 +0100] "GET /ocs/v2.php/apps/notifications/api/v2/notifications?format=json HTTP/1.1" 304 0 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22631 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - test-michal [10/Jan/2025:22:49:42 +0100] "PROPFIND /remote.php/dav/files/test-michal/ HTTP/1.1" 207 262 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22631 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - test-michal [10/Jan/2025:22:49:42 +0100] "PROPFIND /remote.php/dav/files/test-michal/Desktop HTTP/1.1" 207 524 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22631 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - test-michal [10/Jan/2025:22:49:42 +0100] "PROPFIND /remote.php/dav/files/test-michal/ HTTP/1.1" 207 253 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22631 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - test-michal [10/Jan/2025:22:49:46 +0100] "PROPFIND /remote.php/dav/files/test-michal/ HTTP/1.1" 207 262 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22631 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
<my_ip> - - [10/Jan/2025:22:49:49 +0100] "GET /apps/logreader/api/poll?lastReqId=sZIZxAprhB83wt2C0B25 HTTP/2.0" 200 22 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0"
@JokoBurger
Copy link

Hello,

I'm facing the same issue, using ODIC backend (Authentik). Some random files (not all) are running into the same error message.
The sync was running for a few days and started trowing error 0x800701AA.

@bigretromike
Copy link
Author

yeah, something is not right. Can't pin point to issue. when I get those errors nothing comes up on server log side.

@bigretromike
Copy link
Author

Server updated to 30.0.5, still same issue.
Client 3.15.3 (build 20250107) a595d5

Closing client and restarting it don't help.
Adding cloud host to Trusted Sites in Internet Options on windows helps with 0x800701AA, it does not timeout, but it immediately throw 0x80070185, which was hidden under "time out".

The only known workaroud which is not good is to set files that affected to be stored always locally, but thats conflict with VFS where you dont wan't to store everything locally.

@bigretromike bigretromike changed the title [Bug]: implicit hydration triggered by the client itself. 0x800701AA [Bug]: implicit hydration triggered by the client itself. 0x800701AA & 0x80070185 Jan 31, 2025
@bigretromike
Copy link
Author

bigretromike commented Jan 31, 2025

Also both error show up on 2 different installation, one behind reverse proxy and served via nginx, other without proxy served via apache2.

In both cases clients are using VFS and are on Windows 11 (few 10).

Edit1: I also tried the "trick" with deleting .sync_xxxx from root folder on client side, it reset sync, synced again, but did not helped with same issue on files.

edit2: files that we had problem today were under 1 MB, pdf

edit3: clients that are affected use Windows Defender without any extra antyvirus software.

edit4: when having same issue with my pc, the pc is never hibernated, never slept, so its not fault of broken files.

edit5: the instance of nextcloud is inside local network, which exclude hardware firewall issue, same subnet. While few files throw error other files that are not stored locally works...

edit6: adding nextcloud.exe to firewall or disabling firewall on client, dont help.

edit 7: first error is 0x800701AA (aka timeout) when retry its always 0x80070185 (aka not success), retry again, again, again 0x80070185, retry then its longer waiting and we have timeout and its a loop.

Image

Image

edit 8: the timeout is always 60 seconds, I have change every settings that was set by default at 60 and everything lower. restarted apache, no luck. (i changes apache, mpm worker, mariadb net_read/write_timeout, php)

edit 9: when enabling debug log in apache2 i can see this while retrying that non working file this in error log:

[Fri Jan 31 18:40:05.234042 2025] [authz_core:debug] [pid 307544:tid 307544] mod_authz_core.c(815): [client 192.168.51.1:32613] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:05.234118 2025] [authz_core:debug] [pid 307544:tid 307544] mod_authz_core.c(815): [client 192.168.51.1:32613] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:05.234340 2025] [authz_core:debug] [pid 307544:tid 307544] mod_authz_core.c(815): [client 192.168.51.1:32613] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:05.234432 2025] [authz_core:debug] [pid 307544:tid 307544] mod_authz_core.c(815): [client 192.168.51.1:32613] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:05.332611 2025] [ssl:info] [pid 307568:tid 307568] [client 192.168.51.1:3873] AH01964: Connection to child 9 established (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:05.333137 2025] [ssl:debug] [pid 307568:tid 307568] ssl_engine_kernel.c(2391): [client 192.168.51.1:3873] AH02043: SSL virtual host for servername cloud.FQDN.com found
[Fri Jan 31 18:40:05.358088 2025] [ssl:debug] [pid 307568:tid 307568] ssl_engine_kernel.c(2251): [client 192.168.51.1:3873] AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_256_GCM_SHA384 (256/256 bits)
[Fri Jan 31 18:40:05.358296 2025] [socache_shmcb:debug] [pid 307568:tid 307568] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0x0d -> subcache 13)
[Fri Jan 31 18:40:05.358400 2025] [socache_shmcb:debug] [pid 307568:tid 307568] mod_socache_shmcb.c(860): AH00847: insert happened at idx=5, data=(1098:1130)
[Fri Jan 31 18:40:05.358435 2025] [socache_shmcb:debug] [pid 307568:tid 307568] mod_socache_shmcb.c(863): AH00848: finished insert, subcache: idx_pos/idx_used=0/6, data_pos/data_used=0/1317
[Fri Jan 31 18:40:05.358457 2025] [socache_shmcb:debug] [pid 307568:tid 307568] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully
[Fri Jan 31 18:40:05.358757 2025] [socache_shmcb:debug] [pid 307568:tid 307568] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0x07 -> subcache 7)
[Fri Jan 31 18:40:05.358842 2025] [socache_shmcb:debug] [pid 307568:tid 307568] mod_socache_shmcb.c(860): AH00847: insert happened at idx=10, data=(2191:2223)
[Fri Jan 31 18:40:05.358911 2025] [socache_shmcb:debug] [pid 307568:tid 307568] mod_socache_shmcb.c(863): AH00848: finished insert, subcache: idx_pos/idx_used=0/11, data_pos/data_used=0/2411
[Fri Jan 31 18:40:05.358938 2025] [socache_shmcb:debug] [pid 307568:tid 307568] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully
[Fri Jan 31 18:40:05.376031 2025] [ssl:debug] [pid 307568:tid 307568] ssl_engine_kernel.c(415): [client 192.168.51.1:3873] AH02034: Initial (No.1) HTTPS request received for child 9 (server cloud.FQDN.                         com:443)
[Fri Jan 31 18:40:05.376873 2025] [authz_core:debug] [pid 307568:tid 307568] mod_authz_core.c(815): [client 192.168.51.1:3873] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:05.376953 2025] [authz_core:debug] [pid 307568:tid 307568] mod_authz_core.c(815): [client 192.168.51.1:3873] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:05.377192 2025] [authz_core:debug] [pid 307568:tid 307568] mod_authz_core.c(815): [client 192.168.51.1:3873] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:05.377258 2025] [authz_core:debug] [pid 307568:tid 307568] mod_authz_core.c(815): [client 192.168.51.1:3873] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:09.183338 2025] [ssl:debug] [pid 307540:tid 307540] ssl_engine_io.c(1150): [client 192.168.51.1:32609] AH02001: Connection closed to child 7 with standard shutdown (server cloud.FQDN.                         com:443)
[Fri Jan 31 18:40:11.154535 2025] [ssl:debug] [pid 307570:tid 307570] ssl_engine_io.c(1150): [client 192.168.51.1:60528] AH02001: Connection closed to child 1 with standard shutdown (server cloud.FQDN.                         com:443)
[Fri Jan 31 18:40:11.944812 2025] [ssl:info] [pid 307556:tid 307556] [client 192.168.51.1:49514] AH01964: Connection to child 10 established (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:11.945342 2025] [ssl:debug] [pid 307556:tid 307556] ssl_engine_kernel.c(2391): [client 192.168.51.1:49514] AH02043: SSL virtual host for servername cloud.FQDN.com found
[Fri Jan 31 18:40:11.953244 2025] [ssl:debug] [pid 307556:tid 307556] ssl_engine_kernel.c(2251): [client 192.168.51.1:49514] AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_256_GCM_SHA384 (256/256 bits)
[Fri Jan 31 18:40:11.953466 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0x51 -> subcache 17)
[Fri Jan 31 18:40:11.953542 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(745): AH00842: expiring 1 and reclaiming 0 removed socache entries
[Fri Jan 31 18:40:11.953569 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(765): AH00843: we now have 8 socache entries
[Fri Jan 31 18:40:11.953592 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(860): AH00847: insert happened at idx=9, data=(1975:2007)
[Fri Jan 31 18:40:11.953613 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(863): AH00848: finished insert, subcache: idx_pos/idx_used=1/9, data_pos/data_used=219/1976
[Fri Jan 31 18:40:11.953634 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully
[Fri Jan 31 18:40:11.953886 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0xf9 -> subcache 25)
[Fri Jan 31 18:40:11.953947 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(745): AH00842: expiring 1 and reclaiming 0 removed socache entries
[Fri Jan 31 18:40:11.953972 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(765): AH00843: we now have 4 socache entries
[Fri Jan 31 18:40:11.953992 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(860): AH00847: insert happened at idx=5, data=(1098:1130)
[Fri Jan 31 18:40:11.954012 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(863): AH00848: finished insert, subcache: idx_pos/idx_used=1/5, data_pos/data_used=220/1097
[Fri Jan 31 18:40:11.954110 2025] [socache_shmcb:debug] [pid 307556:tid 307556] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully
[Fri Jan 31 18:40:11.955943 2025] [ssl:debug] [pid 307556:tid 307556] ssl_engine_kernel.c(415): [client 192.168.51.1:49514] AH02034: Initial (No.1) HTTPS request received for child 10 (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:11.956904 2025] [authz_core:debug] [pid 307556:tid 307556] mod_authz_core.c(815): [client 192.168.51.1:49514] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:11.956975 2025] [authz_core:debug] [pid 307556:tid 307556] mod_authz_core.c(815): [client 192.168.51.1:49514] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:11.957272 2025] [authz_core:debug] [pid 307556:tid 307556] mod_authz_core.c(815): [client 192.168.51.1:49514] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:11.957331 2025] [authz_core:debug] [pid 307556:tid 307556] mod_authz_core.c(815): [client 192.168.51.1:49514] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:15.385408 2025] [ssl:debug] [pid 307544:tid 307544] ssl_engine_io.c(1150): [client 192.168.51.1:32613] AH02001: Connection closed to child 11 with standard shutdown (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:15.513683 2025] [ssl:debug] [pid 307568:tid 307568] ssl_engine_io.c(1150): [client 192.168.51.1:3873] AH02001: Connection closed to child 9 with standard shutdown (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:20.938127 2025] [ssl:info] [pid 307537:tid 307537] [client 192.168.51.1:32641] AH01964: Connection to child 4 established (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:20.938965 2025] [ssl:debug] [pid 307537:tid 307537] ssl_engine_kernel.c(2391): [client 192.168.51.1:32641] AH02043: SSL virtual host for servername cloud.FQDN.com found
[Fri Jan 31 18:40:20.953188 2025] [ssl:debug] [pid 307537:tid 307537] ssl_engine_kernel.c(2251): [client 192.168.51.1:32641] AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_256_GCM_SHA384 (256/256 bits)
[Fri Jan 31 18:40:20.953421 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0xce -> subcache 14)
[Fri Jan 31 18:40:20.953497 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(745): AH00842: expiring 2 and reclaiming 0 removed socache entries
[Fri Jan 31 18:40:20.953523 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(765): AH00843: we now have 7 socache entries
[Fri Jan 31 18:40:20.953545 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(860): AH00847: insert happened at idx=9, data=(1977:2009)
[Fri Jan 31 18:40:20.953567 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(863): AH00848: finished insert, subcache: idx_pos/idx_used=2/8, data_pos/data_used=439/1757
[Fri Jan 31 18:40:20.953588 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully
[Fri Jan 31 18:40:20.953903 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0x5a -> subcache 26)
[Fri Jan 31 18:40:20.953985 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(745): AH00842: expiring 2 and reclaiming 0 removed socache entries
[Fri Jan 31 18:40:20.954024 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(765): AH00843: we now have 6 socache entries
[Fri Jan 31 18:40:20.954046 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(860): AH00847: insert happened at idx=8, data=(1755:1787)
[Fri Jan 31 18:40:20.954066 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(863): AH00848: finished insert, subcache: idx_pos/idx_used=2/7, data_pos/data_used=439/1536
[Fri Jan 31 18:40:20.954086 2025] [socache_shmcb:debug] [pid 307537:tid 307537] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully
[Fri Jan 31 18:40:20.963212 2025] [ssl:debug] [pid 307537:tid 307537] ssl_engine_kernel.c(415): [client 192.168.51.1:32641] AH02034: Initial (No.1) HTTPS request received for child 4 (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:20.964325 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:20.964431 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:20.964797 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:20.964885 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:20.972909 2025] [ssl:debug] [pid 307556:tid 307556] ssl_engine_kernel.c(415): [client 192.168.51.1:49514] AH02034: Subsequent (No.2) HTTPS request received for child 10 (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:20.973756 2025] [authz_core:debug] [pid 307556:tid 307556] mod_authz_core.c(815): [client 192.168.51.1:49514] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:20.973828 2025] [authz_core:debug] [pid 307556:tid 307556] mod_authz_core.c(815): [client 192.168.51.1:49514] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:20.974079 2025] [authz_core:debug] [pid 307556:tid 307556] mod_authz_core.c(815): [client 192.168.51.1:49514] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:20.974139 2025] [authz_core:debug] [pid 307556:tid 307556] mod_authz_core.c(815): [client 192.168.51.1:49514] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:23.188310 2025] [ssl:debug] [pid 307537:tid 307537] ssl_engine_kernel.c(415): [client 192.168.51.1:32641] AH02034: Subsequent (No.2) HTTPS request received for child 4 (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:23.189491 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:23.189567 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:23.189875 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:23.189961 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:25.100725 2025] [ssl:debug] [pid 307537:tid 307537] ssl_engine_kernel.c(415): [client 192.168.51.1:32641] AH02034: Subsequent (No.3) HTTPS request received for child 4 (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:25.101683 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:25.101758 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:25.102028 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:25.102105 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:28.014854 2025] [ssl:debug] [pid 307537:tid 307537] ssl_engine_kernel.c(415): [client 192.168.51.1:32641] AH02034: Subsequent (No.4) HTTPS request received for child 4 (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:28.016061 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:28.016137 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:28.016461 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:28.016537 2025] [authz_core:debug] [pid 307537:tid 307537] mod_authz_core.c(815): [client 192.168.51.1:32641] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:29.080259 2025] [ssl:info] [pid 307536:tid 307536] [client 192.168.51.1:3873] AH01964: Connection to child 3 established (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:29.080558 2025] [ssl:info] [pid 307630:tid 307630] [client 192.168.51.1:3877] AH01964: Connection to child 5 established (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:29.080853 2025] [ssl:debug] [pid 307536:tid 307536] ssl_engine_kernel.c(2391): [client 192.168.51.1:3873] AH02043: SSL virtual host for servername cloud.FQDN.com found
[Fri Jan 31 18:40:29.081124 2025] [ssl:debug] [pid 307630:tid 307630] ssl_engine_kernel.c(2391): [client 192.168.51.1:3877] AH02043: SSL virtual host for servername cloud.FQDN.com found
[Fri Jan 31 18:40:29.105659 2025] [ssl:debug] [pid 307630:tid 307630] ssl_engine_kernel.c(2251): [client 192.168.51.1:3877] AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_256_GCM_SHA384 (256/256 bits)
[Fri Jan 31 18:40:29.105691 2025] [ssl:debug] [pid 307536:tid 307536] ssl_engine_kernel.c(2251): [client 192.168.51.1:3873] AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_256_GCM_SHA384 (256/256 bits)
[Fri Jan 31 18:40:29.105864 2025] [socache_shmcb:debug] [pid 307630:tid 307630] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0x82 -> subcache 2)
[Fri Jan 31 18:40:29.105915 2025] [socache_shmcb:debug] [pid 307630:tid 307630] mod_socache_shmcb.c(860): AH00847: insert happened at idx=4, data=(880:912)
[Fri Jan 31 18:40:29.105939 2025] [socache_shmcb:debug] [pid 307630:tid 307630] mod_socache_shmcb.c(863): AH00848: finished insert, subcache: idx_pos/idx_used=0/5, data_pos/data_used=0/1100
[Fri Jan 31 18:40:29.105959 2025] [socache_shmcb:debug] [pid 307630:tid 307630] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully
[Fri Jan 31 18:40:29.105998 2025] [socache_shmcb:debug] [pid 307536:tid 307536] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0x17 -> subcache 23)
[Fri Jan 31 18:40:29.106076 2025] [socache_shmcb:debug] [pid 307536:tid 307536] mod_socache_shmcb.c(745): AH00842: expiring 3 and reclaiming 0 removed socache entries
[Fri Jan 31 18:40:29.106103 2025] [socache_shmcb:debug] [pid 307536:tid 307536] mod_socache_shmcb.c(765): AH00843: we now have 3 socache entries
[Fri Jan 31 18:40:29.106125 2025] [socache_shmcb:debug] [pid 307536:tid 307536] mod_socache_shmcb.c(860): AH00847: insert happened at idx=6, data=(1318:1350)
[Fri Jan 31 18:40:29.106145 2025] [socache_shmcb:debug] [pid 307536:tid 307536] mod_socache_shmcb.c(863): AH00848: finished insert, subcache: idx_pos/idx_used=3/4, data_pos/data_used=658/880
[Fri Jan 31 18:40:29.106165 2025] [socache_shmcb:debug] [pid 307536:tid 307536] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully
[Fri Jan 31 18:40:29.106255 2025] [socache_shmcb:debug] [pid 307630:tid 307630] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0xda -> subcache 26)
[Fri Jan 31 18:40:29.106329 2025] [socache_shmcb:debug] [pid 307630:tid 307630] mod_socache_shmcb.c(860): AH00847: insert happened at idx=9, data=(1975:2007)
[Fri Jan 31 18:40:29.106356 2025] [socache_shmcb:debug] [pid 307630:tid 307630] mod_socache_shmcb.c(863): AH00848: finished insert, subcache: idx_pos/idx_used=2/8, data_pos/data_used=439/1756
[Fri Jan 31 18:40:29.106378 2025] [socache_shmcb:debug] [pid 307630:tid 307630] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully
[Fri Jan 31 18:40:29.106491 2025] [socache_shmcb:debug] [pid 307536:tid 307536] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0xdd -> subcache 29)
[Fri Jan 31 18:40:29.106559 2025] [socache_shmcb:debug] [pid 307536:tid 307536] mod_socache_shmcb.c(860): AH00847: insert happened at idx=10, data=(2196:2228)
[Fri Jan 31 18:40:29.106587 2025] [socache_shmcb:debug] [pid 307536:tid 307536] mod_socache_shmcb.c(863): AH00848: finished insert, subcache: idx_pos/idx_used=1/10, data_pos/data_used=220/2196
[Fri Jan 31 18:40:29.106608 2025] [socache_shmcb:debug] [pid 307536:tid 307536] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully
[Fri Jan 31 18:40:29.106801 2025] [ssl:debug] [pid 307630:tid 307630] ssl_engine_kernel.c(415): [client 192.168.51.1:3877] AH02034: Initial (No.1) HTTPS request received for child 5 (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:29.106896 2025] [ssl:debug] [pid 307536:tid 307536] ssl_engine_kernel.c(415): [client 192.168.51.1:3873] AH02034: Initial (No.1) HTTPS request received for child 3 (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:29.107750 2025] [authz_core:debug] [pid 307536:tid 307536] mod_authz_core.c(815): [client 192.168.51.1:3873] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:29.107751 2025] [authz_core:debug] [pid 307630:tid 307630] mod_authz_core.c(815): [client 192.168.51.1:3877] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:29.107819 2025] [authz_core:debug] [pid 307536:tid 307536] mod_authz_core.c(815): [client 192.168.51.1:3873] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:29.107851 2025] [authz_core:debug] [pid 307630:tid 307630] mod_authz_core.c(815): [client 192.168.51.1:3877] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:29.108131 2025] [authz_core:debug] [pid 307536:tid 307536] mod_authz_core.c(815): [client 192.168.51.1:3873] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:29.108137 2025] [authz_core:debug] [pid 307630:tid 307630] mod_authz_core.c(815): [client 192.168.51.1:3877] AH01626: authorization result of Require all granted: granted
[Fri Jan 31 18:40:29.108193 2025] [authz_core:debug] [pid 307536:tid 307536] mod_authz_core.c(815): [client 192.168.51.1:3873] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:29.108244 2025] [authz_core:debug] [pid 307630:tid 307630] mod_authz_core.c(815): [client 192.168.51.1:3877] AH01626: authorization result of <RequireAny>: granted
[Fri Jan 31 18:40:29.291316 2025] [ssl:info] [pid 307629:tid 307629] [client 192.168.51.1:60593] AH01964: Connection to child 0 established (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:29.291685 2025] [ssl:info] [pid 307569:tid 307569] [client 192.168.51.1:60594] AH01964: Connection to child 12 established (server cloud.FQDN.com:443)
[Fri Jan 31 18:40:29.291870 2025] [ssl:debug] [pid 307629:tid 307629] ssl_engine_kernel.c(2391): [client 192.168.51.1:60593] AH02043: SSL virtual host for servername cloud.FQDN.com found
[Fri Jan 31 18:40:29.292283 2025] [ssl:debug] [pid 307569:tid 307569] ssl_engine_kernel.c(2391): [client 192.168.51.1:60594] AH02043: SSL virtual host for servername cloud.FQDN.com found

not sure if related or not

access.log

192.168.51.1 - "" [31/Jan/2025:18:43:44 +0100] "GET /index.php/core/preview?fileId=00161436ocad9kxu2atw&x=96&y=96&a=true HTTP/1.1" **404** 814 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
...
192.168.51.1 - "" [31/Jan/2025:18:45:34 +0100] "GET /index.php/core/preview?fileId=00161436ocad9kxu2atw&x=96&y=96&a=true HTTP/1.1" **404** 3378 "-" "Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)"

Looks like server return 404 on those files....

@bigretromike bigretromike changed the title [Bug]: implicit hydration triggered by the client itself. 0x800701AA & 0x80070185 [Bug]: implicit hydration triggered by the client itself. 0x800701AA & 0x80070185 Server returns 404 to client Jan 31, 2025
@bigretromike
Copy link
Author

bigretromike commented Jan 31, 2025

mysql inspection:
SELECT * FROM oc_filecache WHERE fileid = '00161436ocad9kxu2atw';

results:

| 161436 |      22 | files/Prezenty dla pilotów/2025/AM010124 TAD.pdf  | 6a6a0cfc59b4283f35665c032adb9071 | 161433 | AM010124 TAD.pdf |        8 |        7 | 2769270 | 1735830474 |    1735830474 |         0 |                0 | e6f59e957e31b79afb5c91b61debc343 |          27 | 

I store data on mounted path via NFS
cd /mnt/nas/
find . -name "AM010124 TAD.pdf"

file is located: /mnt/nas/a.m/files/Prezenty dla pilotów/2025/AM010124 TAD.pdf

when doing this (access file with my account, file is shared from different account - a.m)
curl -u "administrator:password" -X PROPFIND "https://cloud.FQDN.com/remote.php/webdav/a.m/files/Prezenty%20dla%20pilot%C3%B3w/2025/AM010124%20TAD.pdf"
I end up with Internal Error from saberdav ? probably im not encoding right?

<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>404 Not Found</title>
</head><body>
<h1>Not Found</h1>
<p>The requested URL was not found on this server.</p>
<hr>
<address>Apache/2.4.62 (Debian) Server at cloud.FQDN.com Port 443</address>
</body></html>

But if I request it with mine user even if I dont shared this file:
curl -u "administrator:password" -X PROPFIND "https://cloud.FQDN.com/remote.php/dav/files/administrator/Prezenty%20dla%20pilot%C3%B3w/2025/AM010124%20TAD.pdf"

I get this:

<?xml version="1.0"?>
<d:multistatus xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns" xmlns:oc="http://owncloud.org/ns" xmlns:nc="http://nextcloud.org/ns"><d:response><d:href>/remote.php/dav/files/administrator/Prezenty%20dla%20pilot%c3%b3w/2025/AM010124%20TAD.pdf</d:href><d:propstat><d:prop><d:getlastmodified>Thu, 02 Jan 2025 15:07:54 GMT</d:getlastmodified><d:getcontentlength>2769270</d:getcontentlength><d:resourcetype/><d:getetag>&quot;e6f59e957e31b79afb5c91b61debc343&quot;</d:getetag><d:getcontenttype>application/pdf</d:getcontenttype></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat></d:response></d:multistatus>

When I request preview like:

curl -u "administrator:password" -H "User-Agent: Mozilla/5.0" "https://cloud.mitologistic.com/index.php/co re/preview?fileId=00161436ocad9kxu2atw&x=96&y=96&a=true"
I get in return:
[]

I can access that file fine via webui, I can open it in pdf viewer on nextcloud also I can download it to local drive.

If I rescan files for user that shared them:
sudo sudo -c "php /var/www/nextcloud/occ files:scan a.m" www-data -s /bin/bash

I get:

Cannot load Zend OPcache - it was already loaded
Starting scan for user 1 out of 1 (a.m)
+---------+-------+-----+---------+---------+--------+--------------+
| Folders | Files | New | Updated | Removed | Errors | Elapsed time |
+---------+-------+-----+---------+---------+--------+--------------+
| 66      | 426   | 0   | 201     | 0       | 0      | 00:00:03     |
+---------+-------+-----+---------+---------+--------+--------------+

But still curl with preview nor client works.

changing loglevel in nextcloud from 2 to 0 and trying to access that same file with client I have:


{"reqId":"b6OR1ExApe7m5nmMSAWn","level":0,"time":"2025-01-31T18:35:14+00:00","remoteAddr":"192.168.51.1","user":"administrator","app":"workflowengine","method":"PROPFIND","url":"/remote.php/dav/files/administrator/",
"message":"Flow activation: rules were requested for operation Zablokuj dost\u0119p do pliku",
"userAgent":"Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)","version":"30.0.5.1","data":{"app":"workflowengine","level":"0"}}
{"reqId":"Lk1I8st0rG7kIYxi0q5E","level":0,"time":"2025-01-31T18:35:18+00:00","remoteAddr":"192.168.51.1","user":"--","app":"no app in context",
"method":"GET","url":"/index.php/core/preview?fileId=00161436ocad9kxu2atw&x=96&y=96&a=true","message":"The loading of lazy AppConfig values have been requested",
"userAgent":"Mozilla/5.0","version":"30.0.5.1","exception":{"Exception":"RuntimeException","Message":"ignorable exception",
"Code":0,"Trace":[{"file":"/var/www/nextcloud/lib/private/AppConfig.php","line":1180,
"function":"loadConfig","class":"OC\\AppConfig","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppConfig.php","line":100,"function":"loadConfigAll","class":"OC\\AppConfig","type":"->"},
{"file":"/var/www/nextcloud/lib/private/AllConfig.php","line":169,"function":"getKeys","class":"OC\\AppConfig","type":"->"},{"file":"/var/www/nextcloud/lib/private/Security/Bruteforce/Throttler.php","line":95,
"function":"getAppKeys","class":"OC\\AllConfig","type":"->"},{"file":"/var/www/nextcloud/lib/private/Security/Bruteforce/Throttler.php","line":175,"function":"isBypassListed",
"class":"OC\\Security\\Bruteforce\\Throttler","type":"->"},{"file":"/var/www/nextcloud/lib/private/Security/Bruteforce/Throttler.php","line":192,
"function":"getAttempts","class":"OC\\Security\\Bruteforce\\Throttler","type":"->"},{"file":"/var/www/nextcloud/lib/private/Security/Bruteforce/Throttler.php","line":265,
"function":"getDelay","class":"OC\\Security\\Bruteforce\\Throttler","type":"->"},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":383,
"function":"sleepDelayOrThrowOnMax","class":"OC\\Security\\Bruteforce\\Throttler","type":"->"},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":543,
"function":"logClientIn","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/base.php","line":1088,
"function":"tryBasicAuthLogin","class":"OC\\User\\Session","type":"->"},{"file":"/var/www/nextcloud/lib/base.php","line":992,
"function":"handleLogin","class":"OC","type":"::"},{"file":"/var/www/nextcloud/index.php","line":24,"function":"handleRequest","class":"OC","type":"::"}],
"File":"/var/www/nextcloud/lib/private/AppConfig.php","Line":1194,"message":"The loading of lazy AppConfig values have been requested","exception":{},"CustomMessage":"The loading of lazy AppConfig values have been requested"}}




{"reqId":"xYEksHOXel57Uh8lDvFz","level":0,"time":"2025-01-31T18:36:16+00:00","remoteAddr":"192.168.51.1","user":"administrator","app":"workflowengine","method":"PROPFIND","url":"/remote.php/dav/files/administrator/",
"message":"Flow activation: rules were requested for operation Zablokuj dost\u0119p do pliku",
"userAgent":"Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)","version":"30.0.5.1","data":{"app":"workflowengine","level":"0"}}


I also see something about BruteForce, I disabled bruteforce plugin and this is log without that plugin, still something about bruteforce:

{"reqId":"nj46QBqvbY9g9g1oQmxH","level":0,"time":"2025-01-31T18:54:56+00:00","remoteAddr":"192.168.51.1","user":"--","app":"no app in context","method":"GET","url":"/index.php/core/preview?fileId=00161436ocad9kxu2atw&x=96&y=96&a=true","message":"The loading of lazy AppConfig values have been requested","userAgent":"Mozilla/5.0","version":"30.0.5.1","exception":{"Exception":"RuntimeException","Message":"ignorable exception","Code":0,"Trace":[{"file":"/var/www/nextcloud/lib/private/AppConfig.php","line":1180,"function":"loadConfig","class":"OC\\AppConfig","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppConfig.php","line":100,"function":"loadConfigAll","class":"OC\\AppConfig","type":"->"},{"file":"/var/www/nextcloud/lib/private/AllConfig.php","line":169,"function":"getKeys","class":"OC\\AppConfig","type":"->"},{"file":"/var/www/nextcloud/lib/private/Security/Bruteforce/Throttler.php","line":95,"function":"getAppKeys","class":"OC\\AllConfig","type":"->"},{"file":"/var/www/nextcloud/lib/private/Security/Bruteforce/Throttler.php","line":175,"function":"isBypassListed","class":"OC\\Security\\Bruteforce\\Throttler","type":"->"},{"file":"/var/www/nextcloud/lib/private/Security/Bruteforce/Throttler.php","line":192,"function":"getAttempts","class":"OC\\Security\\Bruteforce\\Throttler","type":"->"},{"file":"/var/www/nextcloud/lib/private/Security/Bruteforce/Throttler.php","line":265,"function":"getDelay","class":"OC\\Security\\Bruteforce\\Throttler","type":"->"},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":383,"function":"sleepDelayOrThrowOnMax","class":"OC\\Security\\Bruteforce\\Throttler","type":"->"},{"file":"/var/www/nextcloud/lib/private/User/Session.php","line":543,"function":"logClientIn","class":"OC\\User\\Session","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/base.php","line":1088,"function":"tryBasicAuthLogin","class":"OC\\User\\Session","type":"->"},{"file":"/var/www/nextcloud/lib/base.php","line":992,"function":"handleLogin","class":"OC","type":"::"},{"file":"/var/www/nextcloud/index.php","line":24,"function":"handleRequest","class":"OC","type":"::"}],"File":"/var/www/nextcloud/lib/private/AppConfig.php","Line":1194,"message":"The loading of lazy AppConfig values have been requested","exception":{},"CustomMessage":"The loading of lazy AppConfig values have been requested"}}

{"reqId":"cKxEVboPydxpVkNNP4UE","level":3,"time":"2025-01-31T18:44:59+00:00","remoteAddr":"192.168.51.1","user":"administrator","app":"index","method":"GET","url":"/settings/api/apps/media?fileName=https%3A%2F%2Fnextcloud.com%2Fc%2Fuploads%2F2024%2F09%2FNextcloud-Hub-9-1024x576.jpg","message":"Exception thrown: OCP\\Files\\NotFoundException","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0","version":"30.0.5.1","exception":{"Exception":"OCP\\Files\\NotFoundException","Message":"","Code":0,"Trace":[{"file":"/var/www/nextcloud/lib/private/Files/Node/Folder.php","line":81,"function":"getFileInfo","class":"OC\\Files\\Node\\Node","type":"->"},{"file":"/var/www/nextcloud/lib/private/Files/SimpleFS/SimpleFolder.php","line":33,"function":"getDirectoryListing","class":"OC\\Files\\Node\\Folder","type":"->"},{"file":"/var/www/nextcloud/apps/settings/lib/Controller/AppSettingsController.php","line":149,"function":"getDirectoryListing","class":"OC\\Files\\SimpleFS\\SimpleFolder","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":208,"function":"getAppDiscoverMedia","class":"OCA\\Settings\\Controller\\AppSettingsController","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":114,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/App.php","line":161,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/var/www/nextcloud/lib/private/Route/Router.php","line":302,"function":"main","class":"OC\\AppFramework\\App","type":"::"},{"file":"/var/www/nextcloud/lib/base.php","line":1003,"function":"match","class":"OC\\Route\\Router","type":"->"},{"file":"/var/www/nextcloud/index.php","line":24,"function":"handleRequest","class":"OC","type":"::"}],"File":"/var/www/nextcloud/lib/private/Files/Node/Node.php","Line":90,"message":"","exception":{},"CustomMessage":"Exception thrown: OCP\\Files\\NotFoundException"}}
{"reqId":"JJQ5AMLoAPk2mDXBdCAn","level":3,"time":"2025-01-31T18:44:59+00:00","remoteAddr":"192.168.51.1","user":"administrator","app":"index","method":"GET","url":"/settings/api/apps/media?fileName=https%3A%2F%2Fgithub.com%2Fnextcloud%2Ffirstrunwizard%2Fraw%2Fmaster%2Fimg%2FNextcloud.webm","message":"Exception thrown: OCP\\Files\\NotFoundException","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0","version":"30.0.5.1","exception":{"Exception":"OCP\\Files\\NotFoundException","Message":"","Code":0,"Trace":[{"file":"/var/www/nextcloud/lib/private/Files/Node/Folder.php","line":81,"function":"getFileInfo","class":"OC\\Files\\Node\\Node","type":"->"},{"file":"/var/www/nextcloud/lib/private/Files/SimpleFS/SimpleFolder.php","line":33,"function":"getDirectoryListing","class":"OC\\Files\\Node\\Folder","type":"->"},{"file":"/var/www/nextcloud/apps/settings/lib/Controller/AppSettingsController.php","line":149,"function":"getDirectoryListing","class":"OC\\Files\\SimpleFS\\SimpleFolder","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":208,"function":"getAppDiscoverMedia","class":"OCA\\Settings\\Controller\\AppSettingsController","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":114,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/App.php","line":161,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/var/www/nextcloud/lib/private/Route/Router.php","line":302,"function":"main","class":"OC\\AppFramework\\App","type":"::"},{"file":"/var/www/nextcloud/lib/base.php","line":1003,"function":"match","class":"OC\\Route\\Router","type":"->"},{"file":"/var/www/nextcloud/index.php","line":24,"function":"handleRequest","class":"OC","type":"::"}],"File":"/var/www/nextcloud/lib/private/Files/Node/Node.php","Line":90,"message":"","exception":{},"CustomMessage":"Exception thrown: OCP\\Files\\NotFoundException"}}
{"reqId":"yNL1N7K5J25ZvmCX88rT","level":0,"time":"2025-01-31T18:50:44+00:00","remoteAddr":"192.168.51.1","user":"administrator","app":"workflowengine","method":"PROPFIND","url":"/remote.php/dav/files/administrator/","message":"Flow activation: rules were requested for operation Zablokuj dost\u0119p do pliku","userAgent":"Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)","version":"30.0.5.1","data":{"app":"workflowengine","level":"0"}}
{"reqId":"QhDQ584AEnchArVFGN9t","level":0,"time":"2025-01-31T18:51:07+00:00","remoteAddr":"192.168.51.1","user":"administrator","app":"workflowengine","method":"PROPFIND","url":"/remote.php/dav/files/administrator/Zlecenia%20dla%20pilot%C3%B3w/2025","message":"Flow activation: rules were requested for operation Zablokuj dost\u0119p do pliku","userAgent":"Mozilla/5.0 (Windows) mirall/3.15.3 (build 20250107) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)","version":"30.0.5.1","data":{"app":"workflowengine","level":"0"}}

Looks like there is something about ignorable exception

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

No branches or pull requests

3 participants