Syncing Headless as a Non-Admin in Windows fails partially

[daLuiz]

Hi there!

I am trying to use Pydio Sync in headless mode on a windows server, and it works fine if I use an Admin account. However for security reasons I would like to use a non-admin service account.

I configured pydio sync to run as a service with a non-admin account using NSSM, and this seems to work well at first. The agent starts, I configured the api-user and pw via command line parameters (--api_user "xx" --api_password "yy"), and I can access the configuration at http://localhost:5556/ just fine.

Now I define my sync task, this also works well. The server is a Pydio 6.2.2 server, over which I have no control. It is configured to only download, no 2-way sync.

Then I start sync, and it first syncs the entire folder structure just fine, then it starts syncing the files. After a few files however, I get the following error: Unexpected Error: Cannot operate on a closed cursor. It then waits some time, continues to sync 1 file, and stops again with the same error.

Taking a look at the log file, I see the following:

2018-08-03 10:19:57 INFO    4784  Thread-4 logging : 1627 | info | Loading remote changes with sequence 21795 for job id XXXXXXXXXXXXX
2018-08-03 10:19:58 INFO    4784  Thread-4 logging : 1627 | info | Reducing changes for XXXXXXXXXXXXX
2018-08-03 10:20:00 INFO    4784  Thread-4 logging : 1627 | info | Processing 144 changes
2018-08-03 10:20:01 ERROR   4784  Thread-4 logging : 1601 | error | JWT not available
2018-08-03 10:20:03 INFO    4784  Thread-4 logging : 1627 | info | /PATH/TO/XXX.pdf <====DOWNLOAD==== /PATH/TO/XXX.pdf
2018-08-03 10:20:03 INFO    4784  Thread-4 logging : 1627 | info | File /PATH/TO/XXX.pdf downloaded from server
2018-08-03 10:20:03 ERROR   4784  Thread-4 logging : 1601 | error | Unexpected Error: Cannot operate on a closed cursor.
Traceback (most recent call last):
  File "C:\BuildAgent\work\19045f4c63bc432e\build\pydio-agent\out01-PYZ.pyz\pydio.job.continous_merger", line 672, in run
  File "C:\BuildAgent\work\19045f4c63bc432e\build\pydio-agent\out01-PYZ.pyz\pydio.job.change_stores", line 175, in process_changes_with_callback
ProgrammingError: Cannot operate on a closed cursor.
2018-08-03 10:21:03 INFO    4784  Thread-4 logging : 1627 | info | Loading remote changes with sequence 21796 for job id XXXXXXXXXXXXX
2018-08-03 10:21:05 INFO    4784  Thread-4 logging : 1627 | info | Reducing changes for XXXXXXXXXXXXX
2018-08-03 10:21:07 INFO    4784  Thread-4 logging : 1627 | info | Processing 143 changes
2018-08-03 10:21:08 ERROR   4784  Thread-4 logging : 1601 | error | JWT not available
2018-08-03 10:21:09 INFO    4784  Thread-4 logging : 1627 | info | /PATH/TO/YYY.pdf <====DOWNLOAD==== /PATH/TO/YYY.pdf
2018-08-03 10:21:09 INFO    4784  Thread-4 logging : 1627 | info | File /PATH/TO/YYY.pdf downloaded from server
2018-08-03 10:21:09 ERROR   4784  Thread-4 logging : 1601 | error | Unexpected Error: Cannot operate on a closed cursor.
Traceback (most recent call last):
  File "C:\BuildAgent\work\19045f4c63bc432e\build\pydio-agent\out01-PYZ.pyz\pydio.job.continous_merger", line 672, in run
  File "C:\BuildAgent\work\19045f4c63bc432e\build\pydio-agent\out01-PYZ.pyz\pydio.job.change_stores", line 175, in process_changes_with_callback
ProgrammingError: Cannot operate on a closed cursor.
2018-08-03 10:22:09 INFO    4784  Thread-4 logging : 1627 | info | Loading remote changes with sequence 21797 for job id XXXXXXXXXXXXX
2018-08-03 10:22:10 INFO    4784  Thread-4 logging : 1627 | info | Reducing changes for XXXXXXXXXXXXX
2018-08-03 10:22:11 INFO    4784  Thread-4 logging : 1627 | info | Processing 142 changes
2018-08-03 10:22:12 ERROR   4784  Thread-4 logging : 1601 | error | JWT not available
2018-08-03 10:22:13 INFO    4784  Thread-4 logging : 1627 | info | /PATH/TO/ZZZ.pdf <====DOWNLOAD==== /PATH/TO/ZZZ.pdf
2018-08-03 10:22:13 INFO    4784  Thread-4 logging : 1627 | info | File /PATH/TO/ZZZ.pdf downloaded from server
2018-08-03 10:22:13 ERROR   4784  Thread-4 logging : 1601 | error | Unexpected Error: Cannot operate on a closed cursor.
Traceback (most recent call last):
  File "C:\BuildAgent\work\19045f4c63bc432e\build\pydio-agent\out01-PYZ.pyz\pydio.job.continous_merger", line 672, in run
  File "C:\BuildAgent\work\19045f4c63bc432e\build\pydio-agent\out01-PYZ.pyz\pydio.job.change_stores", line 175, in process_changes_with_callback
ProgrammingError: Cannot operate on a closed cursor.

This keeps continuing file by file, and it looks like it may eventually sync all files, but it doesn't look reliable.

This is all with the latest development version (64bit) here: from https://download.pydio.com/pub/pydio-sync/develop/packages/, dated 30. Jul. 2018 . With version 1.2.9 I couldn't get it to work at all, it immediately ran into this error:

2018-08-03 09:04:27 ERROR   3964  Thread-2 logging : 1601 | error | Unexpected Error: 'NoneType' object has no attribute 'locked'
Traceback (most recent call last):
  File "C:\BuildAgent\work\a00136d723583ad3\build\pydio-agent\out01-PYZ.pyz\pydio.job.continous_merger", line 448, in run
AttributeError: 'NoneType' object has no attribute 'locked'

I tried syncing both to a network path (UNC path and drive letter for the service account user), and to a local path on the C:\ drive, with the same result.

Any ideas on this?

Thanks,
Luiz

[daLuiz]

It did now actually finish to sync all files, now it continuously repeats the following error messages in the log:

2018-08-03 12:52:32 INFO    4296  Thread-5 logging : 1627 | info | Loading remote changes with sequence 26959 for job id XXXXXXXXXXXX
2018-08-03 12:52:33 INFO    4296  Thread-5 logging : 1627 | info | No changes detected in XXXXXXXXXXXX
2018-08-03 12:52:35 ERROR   4296  Thread-5 logging : 1601 | error | Unexpected Error: 'NoneType' object has no attribute 'isAlive'
Traceback (most recent call last):
  File "C:\BuildAgent\work\19045f4c63bc432e\build\pydio-agent\out01-PYZ.pyz\pydio.job.continous_merger", line 533, in run
AttributeError: 'NoneType' object has no attribute 'isAlive'
2018-08-03 12:53:35 INFO    4296  Thread-5 logging : 1627 | info | Loading remote changes with sequence 26959 for job id XXXXXXXXXXXX
2018-08-03 12:53:36 INFO    4296  Thread-5 logging : 1627 | info | No changes detected in XXXXXXXXXXXX
2018-08-03 12:53:38 ERROR   4296  Thread-5 logging : 1601 | error | Unexpected Error: 'NoneType' object has no attribute 'isAlive'
Traceback (most recent call last):
  File "C:\BuildAgent\work\19045f4c63bc432e\build\pydio-agent\out01-PYZ.pyz\pydio.job.continous_merger", line 533, in run
AttributeError: 'NoneType' object has no attribute 'isAlive'
2018-08-03 12:54:38 INFO    4296  Thread-5 logging : 1627 | info | Loading remote changes with sequence 26959 for job id XXXXXXXXXXXX
2018-08-03 12:54:38 INFO    4296  Thread-5 logging : 1627 | info | No changes detected in XXXXXXXXXXXX
2018-08-03 12:54:41 ERROR   4296  Thread-5 logging : 1601 | error | Unexpected Error: 'NoneType' object has no attribute 'isAlive'
Traceback (most recent call last):
  File "C:\BuildAgent\work\19045f4c63bc432e\build\pydio-agent\out01-PYZ.pyz\pydio.job.continous_merger", line 533, in run
AttributeError: 'NoneType' object has no attribute 'isAlive'

[mcr-ksh]

same issue for Linux. Just figured that it must be with something with "download", i.e. read-only share. The self.event_handler and self.watcher are not started which is later not properly checked.

check continous_merger.py line 562 and change to:
if self.watcher and (not self.watcher.isAlive() and not self.interrupt):
from
if not self.watcher.isAlive() and not self.interrupt:

[GwynethLlewelyn]

Sadly, over a year has passed since your bug report and it still hasn't been fixed on the source code... I guess that's because they're moving to Pydio Cells...

I've downloaded the latest 2.2.0 build from the developers' directory, which was built in January 2019, and it unfortunately still exhibits the very same error...

(Edited: I forgot to mention that I'm using PydioSync under macOS Catalina Beta and Pydio 8.2.3 running under Ubuntu Linux 16.04.6 LTS [Xenial])