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.

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

Nextcloud 3.2.1stable-Win64: Hung on client start #3318

Closed
tokudan opened this issue May 14, 2021 · 10 comments 路 Fixed by #3390
Closed

Nextcloud 3.2.1stable-Win64: Hung on client start #3318

tokudan opened this issue May 14, 2021 · 10 comments 路 Fixed by #3390
Labels
1. to develop bug feature: 馃捊 virtual filesystem os: 馃毆 Windows

Comments

@tokudan
Copy link

tokudan commented May 14, 2021 •
edited

How to use GitHub

  • Please use the 馃憤 reaction to show that you are affected by the same issue.
  • Please don't comment if you have no relevant information to add. It's just extra noise for everyone subscribed to this issue.
  • Subscribe to receive notifications on status change and new comments.

Expected behaviour

Nextcloud client starts and syncs files.

Actual behaviour

Nextcloud client reliably hangs on start, not reacting to anything. Icon grey.
Last log entries:
This might be related to virtual files, as I had no issues until I told the client to free up space. On the next restart the client started hanging.

Steps to reproduce

  1. Sync any folder, enabling VFS. (Size probably does not matter, but this is unverified)
  2. Create an ignore list, which is stored as .sync-exclude.lst in the synced folder.
  3. Tell the nextcloud client or the windows explorer to free up space for that folder and make sure that .sync-exclude.lst is not available locally anymore.
  4. Restart the nextcloud client, it hangs on start.

Workaround to fix the issue

Make sure to always have the file .sync-exclude.lst available locally before exiting the Nextcloud client, e.g. by right-clicking on it and selecting "Always keep on this device".

Client configuration

Client version: 3.2.1stable-Win64 (build 20210428) Qt 5.12.9 SSL OpenSSL 1.1.1g 21 Apr 2020

Operating system:

OS language: German

Qt version used by client package (Linux only, see also Settings dialog):

Client package (From Nextcloud or distro) (Linux only):

Installation path of client: c:\Program Files\Nextcloud

Server configuration

Nextcloud version:

Storage backend (external storage):

Logs

Please use Gist (https://gist.github.com/) or a similar code paster for longer
logs.

  1. Client logfile after hanging:
C:\Users\Daniel\AppData\Roaming\Nextcloud\logs>dir
 Volume in Laufwerk C: hat keine Bezeichnung.

 Verzeichnis von C:\Users\Daniel\AppData\Roaming\Nextcloud\logs

14.05.2021  21:11    <DIR>          .
14.05.2021  21:11    <DIR>          ..
14.05.2021  21:11               185 20210514_2111_owncloud.log.0
               1 Datei(en),            185 Bytes
               2 Verzeichnis(se), 563.372.048.384 Bytes frei

C:\Users\Daniel\AppData\Roaming\Nextcloud\logs>type 20210514_2111_owncloud.log.0
2021-05-14 21:11:14:237 [ info nextcloud.gui.application ]:     "################## Nextcloud locale:[de_DE] ui_lang:[] version:[3.2.1stable-Win64 (build 20210428)] os:[Windows 10 (10.0)]"
2021-05-14 21:11:14:237 [ info nextcloud.gui.application ]:     Using "de_DE" translation
2021-05-14 21:11:14:253 [ info nextcloud.gui.application ]:     VFS windows plugin is available
2021-05-14 21:11:14:253 [ info nextcloud.gui.application ]:     VFS suffix plugin is available
2021-05-14 21:11:14:253 [ debug nextcloud.gui.socketapi ]       [ OCC::SocketApi::SocketApi ]:  creating "//./pipe" true
2021-05-14 21:11:14:253 [ info nextcloud.gui.socketapi ]:       server started, listening at  "\\\\.\\pipe\\nextcloud-Daniel"
2021-05-14 21:11:14:258 [ info nextcloud.gui.folder.manager ]:  setting remote poll timer interval to 30000 msec
2021-05-14 21:11:14:275 [ info nextcloud.gui.account.manager ]: Account for QUrl("https://cloud.example.com") using auth type "webflow"
2021-05-14 21:11:14:275 [ info nextcloud.sync.credentials.webflow ]:    Get QNAM
2021-05-14 21:11:14:275 [ info nextcloud.gui.account.manager ]: Restored:  0  unknown certs.
2021-05-14 21:11:14:275 [ debug nextcloud.gui.activity ]        [ OCC::User::setNotificationRefreshInterval ]:  Starting Notification refresh timer with  300  sec interval
2021-05-14 21:11:14:306 [ info nextcloud.gui.folder.manager ]:  Setup folders from settings file
2021-05-14 21:11:14:306 [ info plugins ]:       Created VFS instance for: "win"
2021-05-14 21:11:14:306 [ info nextcloud.sync.database ]:       Detected filesystem "NTFS" for "C:/Users/Daniel/Documents/GOG Downloads/.sync_9be4e0632301.db"
2021-05-14 21:11:14:306 [ debug nextcloud.gui.folder ]  [ OCC::Folder::checkLocalPath ]:        Checked local path ok
2021-05-14 21:11:14:306 [ info nextcloud.sync.configfile ]:     Adding user defined ignore list to csync: "C:/Users/Daniel/AppData/Roaming/Nextcloud/sync-exclude.lst"

C:\Users\Daniel\AppData\Roaming\Nextcloud\logs>

Since 3.1: Under the "General" settings, you can click on "Create Debug Archive ..." to pick the location of where the desktop client will export the logs and the database to a zip file.
On previous releases: Via the command line: nextcloud --logdebug --logwindow or nextcloud --logdebug --logfile log.txt
(See also https://docs.nextcloud.com/desktop/3.0/troubleshooting.html#log-files)

  1. Web server error log:
    I don't have access to those.

  2. Server logfile: nextcloud log (data/nextcloud.log):
@weiw11
Copy link

weiw11 commented May 19, 2021

Might be same issue as #3243? I have similar error log.

@tokudan
Copy link
Author

tokudan commented May 20, 2021

Might be same issue as #3243? I have similar error log.

I doubt it, my client completely freezes instead of crashing.
It's probably in the same area so it might have a similar cause, but the result seems to be completely different.

@weiw11
Copy link

weiw11 commented May 20, 2021

I have the same error as you and I just posted it there since there's more activity and I thought it may have some connections.

Do you have any other cloud storage programs installed on your device?

Also does your explorer.exe work when the client freezes?

@Deebster
Copy link

I am also having this issue. On initially adding the sync it works as expected, but after a reboot it just sits there burning CPU. I left it for over 24 hours and no progress or further log messages. I have a virtual files sync to the root of my 177gb account, mostly flac files.

I am seeing nearly 800 B/sec being written to C:\Windows\System32\LogFiles\Cloudfiles\CldFlt3.etl. Joplin on the desktop/Android is able to sync so the Nextcloud instance itself seems fine.

2021-05-24 13:45:26:426 [ info nextcloud.gui.application ]:	"################## Nextcloud locale:[en_GB] ui_lang:[] version:[3.2.1stable-Win64 (build 20210428)] os:[Windows 10 (10.0)]"
2021-05-24 13:45:26:445 [ info nextcloud.gui.application ]:	Using "en_GB" translation
2021-05-24 13:45:26:457 [ info nextcloud.gui.application ]:	VFS windows plugin is available
2021-05-24 13:45:26:457 [ info nextcloud.gui.application ]:	VFS suffix plugin is available
2021-05-24 13:45:26:463 [ debug nextcloud.gui.socketapi ]	[ OCC::SocketApi::SocketApi ]:	creating "//./pipe" true
2021-05-24 13:45:26:463 [ info nextcloud.gui.socketapi ]:	server started, listening at  "\\\\.\\pipe\\nextcloud-micro"
2021-05-24 13:45:26:464 [ info nextcloud.gui.folder.manager ]:	setting remote poll timer interval to 30000 msec
2021-05-24 13:45:26:590 [ info nextcloud.gui.account.manager ]:	Account for QUrl("https://REDACTED") using auth type "webflow"
2021-05-24 13:45:26:591 [ info nextcloud.sync.credentials.webflow ]:	Get QNAM
2021-05-24 13:45:26:592 [ info nextcloud.gui.account.manager ]:	Restored:  0  unknown certs.
2021-05-24 13:45:26:610 [ debug nextcloud.gui.activity ]	[ OCC::User::setNotificationRefreshInterval ]:	Starting Notification refresh timer with  300  sec interval
2021-05-24 13:45:26:709 [ info nextcloud.gui.folder.manager ]:	Setup folders from settings file
2021-05-24 13:45:26:711 [ info plugins ]:	Created VFS instance for: "win"
2021-05-24 13:45:26:712 [ info nextcloud.sync.database ]:	Detected filesystem "NTFS" for "d:/nextcloud/.sync_e7b8ae9d9552.db"
2021-05-24 13:45:26:713 [ debug nextcloud.gui.folder ]	[ OCC::Folder::checkLocalPath ]:	Checked local path ok
2021-05-24 13:45:26:715 [ info nextcloud.sync.configfile ]:	Adding user defined ignore list to csync: "C:/Users/micro/AppData/Roaming/Nextcloud/sync-exclude.lst"

@allexzander
Copy link
Contributor

@tokudan

So, when syncing small folders, the client always work fine? Does the issue only happen when syncing at least one large folder?

@tokudan
Copy link
Author

tokudan commented May 25, 2021 •
edited

What I just noticed: Deleting the file .sync-exclude.lst from the synced directory solves that issue for me. I can restart the Nextcloud client without any issues after removing just that file. Recreating that file and trying to free up the space for that file, causes the same issue again, so I guess despite my experiences above it's just related to this single file.
Just telling the Nextcloud client to free up space or even freeing up space through the explorer seems to have the same effect.

So I guess this could be solved two ways:
Either ensure that the client can always download files even if not fully initialized or ensure that certain files are always available locally.

Do you have any other cloud storage programs installed on your device?

OneDrive is installed by default on Win10, but I'm not using it (not logged in), it's not running and as far as I can see there's no directory linked to it.

Also does your explorer.exe work when the client freezes?

Yes, the explorer mostly works and I can browse the synced directories, except when the actual files have not been downloaded. Right clicking on a file to get the context menu causes the explorer to hang. Trying to copy a file that has not been downloaded results in:
Error 0x8007016A: Cloudstorage not started
(Message roughly translated from German)
Also nextcloud.exe is stuck at ~8% CPU which is about one CPU thread.

So, when syncing small folders, the client always work fine? Does the issue only happen when syncing at least one large folder?

I think that was a biased observation on my part as I only have a .sync-exclude.lst in my large folder.

@tokudan
Copy link
Author

tokudan commented May 25, 2021

I updated the description in the first post with a workaround that works for me.

@aaronspruit
Copy link

aaronspruit commented May 29, 2021 •
edited

I was having a similar issue with one of my machines where the client was running in virtual drive mode.

Machine A - where the .sync-exclude.lst file was created. Sync worked fine, never had any hangs

Machine B - would hang when converted to virtual drive. Additionally I wiped the machine with a new reinstall of Windows 10 21H1 and still had the issue. I could not open the client by right-clicking the taskbar item. Additionally, if I attempted to hydrate any of the files (regardless of where they exists, note that the exclude file was not in the root folder, that explorer session would hang until I killed the NextCloud process.

When looking at the logs, this is what I found:

2021-05-28 21:47:52:830 [ info nextcloud.sync.networkjob.lscol ]:	LSCOL of QUrl("https://<domain>/remote.php/dav/files/<user>/") FINISHED WITH STATUS "OK"
2021-05-28 21:47:52:833 [ debug nextcloud.sync.engine ]	[ OCC::SyncEngine::slotRootEtagReceived ]:	Root etag: "eedb81e179d4d3f0b16ec13b4020b494"
2021-05-28 21:47:52:833 [ info nextcloud.gui.folder ]:	Root etag from during sync: "eedb81e179d4d3f0b16ec13b4020b494"
2021-05-28 21:47:52:833 [ debug nextcloud.sync.database.sql ]	[ OCC::SqlQuery::bindValue ]:	SQL bind 1 -8235331962034358849
2021-05-28 21:47:52:833 [ debug nextcloud.sync.database.sql ]	[ OCC::SqlQuery::exec ]:	SQL exec "SELECT path, inode, modtime, type, md5, fileid, remotePerm, filesize,  ignoredChildrenRemote, contentchecksumtype.name || ':' || contentChecksum, e2eMangledName, isE2eEncrypted  FROM metadata  LEFT JOIN checksumtype as contentchecksumtype ON metadata.contentChecksumTypeId == contentchecksumtype.id WHERE parent_hash(path) = ?1 ORDER BY path||'/' ASC"
2021-05-28 21:47:52:835 [ info sync.discovery ]:	Processing ".Contacts-Backup" | valid: true/true/true | mtime: 1622232307/1622232307/1622232307 | size: 0/65536/0 | etag: "60b14cf609e91"//"60b14cf609e91" | checksum: ""//"" | perm: 0x18c1bfd19b8//0x18c1bfd17d8 | fileid: "00000119ochz3wzoynpi"//"00000119ochz3wzoynpi" | inode: 92581/92581/ | type: CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory | e2ee: false/false | e2eeMangledName: ""/""
2021-05-28 21:47:52:835 [ info sync.discovery ]:	Discovered ".Contacts-Backup" CSyncEnums::CSYNC_INSTRUCTION_NONE OCC::SyncFileItem::None CSyncEnums::ItemTypeDirectory
2021-05-28 21:47:52:836 [ info sync.discovery ]:	Processing ".sync-exclude.lst" | valid: false/false/true | mtime: 0/0/1621803604 | size: 0/0/18 | etag: ""//"284da53d3340075bfe6bbc1938dcd977" | checksum: ""//"SHA1:162d17e4568cfe9c1fa5ff907e97bdeda3722197</checksum>" | perm: 0x7fffdcdeb198//0x18c1bfd1b38 | fileid: ""//"00498509ochz3wzoynpi" | inode: 0/0/ | type: CSyncEnums::ItemTypeSkip/CSyncEnums::ItemTypeSkip/CSyncEnums::ItemTypeFile | e2ee: false/false | e2eeMangledName: ""/""
2021-05-28 21:47:52:836 [ debug nextcloud.sync.database.sql ]	[ OCC::SqlQuery::bindValue ]:	SQL bind 1 "00498509ochz3wzoynpi"
2021-05-28 21:47:52:836 [ debug nextcloud.sync.database.sql ]	[ OCC::SqlQuery::exec ]:	SQL exec "SELECT path, inode, modtime, type, md5, fileid, remotePerm, filesize,  ignoredChildrenRemote, contentchecksumtype.name || ':' || contentChecksum, e2eMangledName, isE2eEncrypted  FROM metadata  LEFT JOIN checksumtype as contentchecksumtype ON metadata.contentChecksumTypeId == contentchecksumtype.id WHERE fileid=?1"
2021-05-28 21:47:52:836 [ info sync.discovery ]:	Discovered ".sync-exclude.lst" CSyncEnums::CSYNC_INSTRUCTION_NEW OCC::SyncFileItem::Down CSyncEnums::ItemTypeVirtualFile
2021-05-28 21:47:52:836 [ debug nextcloud.sync.database.sql ]	[ OCC::SqlQuery::bindValue ]:	SQL bind 1 ".sync-exclude.lst"
2021-05-28 21:47:52:836 [ debug nextcloud.sync.database.sql ]	[ OCC::SqlQuery::exec ]:	SQL exec "SELECT lastTryEtag, lastTryModtime, retrycount, errorstring, lastTryTime, ignoreDuration, renameTarget, errorCategory, requestId FROM blacklist WHERE path=?1 COLLATE NOCASE"
2021-05-28 21:47:52:837 [ info sync.discovery ]:	Processing "Desktop" | valid: true/true/true | mtime: 1622240530/1622240530/1622240530 | size: 0/4096/0 | etag: "60b16d12d152a"//"60b16d12d152a" | checksum: ""//"" | perm: 0x18c1bfd2618//0x18c1bfd2738 | fileid: "00000115ochz3wzoynpi"//"00000115ochz3wzoynpi" | inode: 299397/299397/ | type: CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory | e2ee: false/false | e2eeMangledName: ""/""
2021-05-28 21:47:52:837 [ info sync.discovery ]:	Discovered "Desktop" CSyncEnums::CSYNC_INSTRUCTION_NONE OCC::SyncFileItem::None CSyncEnums::ItemTypeDirectory
2021-05-28 21:47:52:839 [ info sync.discovery ]:	Processing "Documents" | valid: true/true/true | mtime: 1621714301/1621714301/1621714301 | size: 0/8192/0 | etag: "60aad9df6d662"//"60aad9df6d662" | checksum: ""//"" | perm: 0x18c1bfd22b8//0x18c1bfd2408 | fileid: "00000118ochz3wzoynpi"//"00000118ochz3wzoynpi" | inode: 299399/299399/ | type: CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory | e2ee: false/false | e2eeMangledName: ""/""
2021-05-28 21:47:52:839 [ info sync.discovery ]:	Discovered "Documents" CSyncEnums::CSYNC_INSTRUCTION_NONE OCC::SyncFileItem::None CSyncEnums::ItemTypeDirectory
2021-05-28 21:47:52:840 [ info sync.discovery ]:	Processing "Externally Shared" | valid: true/true/true | mtime: 1621807068/1621807068/1621807068 | size: 0/0/0 | etag: "60aacfdc9de8b"//"60aacfdc9de8b" | checksum: ""//"" | perm: 0x18c1bfd2d98//0x18c1bfd2738 | fileid: "00338947ochz3wzoynpi"//"00338947ochz3wzoynpi" | inode: 300170/300170/ | type: CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory | e2ee: false/false | e2eeMangledName: ""/""
2021-05-28 21:47:52:840 [ info sync.discovery ]:	Discovered "Externally Shared" CSyncEnums::CSYNC_INSTRUCTION_NONE OCC::SyncFileItem::None CSyncEnums::ItemTypeDirectory
2021-05-28 21:47:52:841 [ info sync.discovery ]:	Processing "Family" | valid: true/true/true | mtime: 1621783320/1621783320/1621783320 | size: 0/4096/0 | etag: "60aa7318f033d"//"60aa7318f033d" | checksum: ""//"" | perm: 0x18c1bfd2348//0x18c1bfd23d8 | fileid: "00356714ochz3wzoynpi"//"00356714ochz3wzoynpi" | inode: 300171/300171/ | type: CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory | e2ee: false/false | e2eeMangledName: ""/""
2021-05-28 21:47:52:841 [ info sync.discovery ]:	Discovered "Family" CSyncEnums::CSYNC_INSTRUCTION_NONE OCC::SyncFileItem::None CSyncEnums::ItemTypeDirectory
2021-05-28 21:47:52:872 [ debug nextcloud.sync.vfs.cfapi.wrapper ]	[ `anonymous-namespace'::cfApiFetchDataCallback ]:	Fetch data callback called. File size: 26
2021-05-28 21:48:16:458 [ debug nextcloud.sync.vfs.cfapi.wrapper ]	[ `anonymous-namespace'::cfApiFetchDataCallback ]:	Fetch data callback called. File size: 418
2021-05-28 21:48:53:015 [ info nextcloud.sync.vfs.cfapi.wrapper ]:	Cancel fetch data of "C:\\Users\\<me>\\Nextcloud\\Lightroom\\.sync-exclude.lst"
2021-05-28 21:48:53:016 [ debug nextcloud.sync.vfs.cfapi.wrapper ]	[ `anonymous-namespace'::cfApiFetchDataCallback ]:	Fetch data callback called. File size: 26
2021-05-28 21:49:17:233 [ info nextcloud.sync.vfs.cfapi.wrapper ]:	Cancel fetch data of "C:\\Users\\<me>\\Nextcloud\\Documents\\desktop.ini"
2021-05-28 21:49:17:234 [ debug nextcloud.sync.vfs.cfapi.wrapper ]	[ `anonymous-namespace'::cfApiFetchDataCallback ]:	Fetch data callback called. File size: 418
2021-05-28 21:49:53:651 [ info nextcloud.sync.vfs.cfapi.wrapper ]:	Cancel fetch data of "C:\\Users\\<me>\\Nextcloud\\Lightroom\\.sync-exclude.lst"
2021-05-28 21:49:53:693 [ debug nextcloud.sync.vfs.cfapi.wrapper ]	[ `anonymous-namespace'::cfApiFetchDataCallback ]:	Fetch data callback called. File size: 26
2021-05-28 21:50:17:881 [ info nextcloud.sync.vfs.cfapi.wrapper ]:	Cancel fetch data of "C:\\Users\\<me>\\Nextcloud\\Documents\\desktop.ini"
2021-05-28 21:50:23:070 [ debug nextcloud.sync.vfs.cfapi.wrapper ]	[ `anonymous-namespace'::cfApiFetchDataCallback ]:	Fetch data callback called. File size: 418
2021-05-28 21:50:54:150 [ info nextcloud.sync.vfs.cfapi.wrapper ]:	Cancel fetch data of "C:\\Users\\<me>\\Nextcloud\\Lightroom\\.sync-exclude.lst"
2021-05-28 21:50:54:151 [ debug nextcloud.sync.vfs.cfapi.wrapper ]	[ `anonymous-namespace'::cfApiFetchDataCallback ]:	Fetch data callback called. File size: 26
2021-05-28 21:51:23:374 [ info nextcloud.sync.vfs.cfapi.wrapper ]:	Cancel fetch data of "C:\\Users\\<me>\\Nextcloud\\Documents\\desktop.ini"
2021-05-28 21:51:23:374 [ debug nextcloud.sync.vfs.cfapi.wrapper ]	[ `anonymous-namespace'::cfApiFetchDataCallback ]:	Fetch data callback called. File size: 418
2021-05-28 21:57:16:704 [ info nextcloud.sync.vfs.cfapi.wrapper ]:	Cancel fetch data of "C:\\Users\\<me>\\Nextcloud\\Lightroom\\.sync-exclude.lst"
2021-05-28 21:57:16:705 [ info nextcloud.sync.vfs.cfapi.wrapper ]:	Cancel fetch data of "C:\\Users\\<me>\\Nextcloud\\Documents\\desktop.ini"
2021-05-28 21:57:16:743 [ debug nextcloud.sync.vfs.cfapi.wrapper ]	[ `anonymous-namespace'::cfApiFetchDataCallback ]:	Fetch data callback called. File size: 26
2021-05-28 21:57:17:846 [ debug nextcloud.sync.vfs.cfapi.wrapper ]	[ `anonymous-namespace'::cfApiFetchDataCallback ]:	Fetch data callback called. File size: 418
2021-05-28 21:58:17:241 [ info nextcloud.sync.vfs.cfapi.wrapper ]:	Cancel fetch data of "C:\\Users\\<me>\\Nextcloud\\Lightroom\\.sync-exclude.lst"

After finding this article, I killed the NextCloud process, and removed the exclude.lst from the subfolder. I then restarted NextCloud and everything worked as expected.

I have now recreated the exclude file on Machine B and marked it as always online, and it seems as though Machine B is now working properly. Machine A already had that file marked as always online - which is not something I did, but it is where I originally created the ignore files list. Therefore, even with these updates/recreates, Machine A continues to work as expected.

@dryo
Copy link

dryo commented May 30, 2021

This was it! This really has to be fixed on next update.

@allexzander
Copy link
Contributor

Thank you for discovering this. We'll see if we can put a fix into a next patch.

@allexzander allexzander mentioned this issue Jun 1, 2021
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
1. to develop bug feature: 馃捊 virtual filesystem os: 馃毆 Windows
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

VFS freeze fix. Treat .sync-exclude.lst as a non-virtual file always. nextcloud/desktop
7 participants
@Deebster @tokudan @dryo @aaronspruit @allexzander @FlexW @weiw11