Dvc: Unexpected error - Adding files

Created on 21 Nov 2019 · 69Comments · Source: iterative/dvc

Everytime that im trying to add some individuals files or complete directories the same unexpected error appears:

> dvc add -v -R model
DEBUG: Trying to spawn '['c:\\users\\luisfelipe_melo_mora\\appdata\\local\\programs\\python\\python37-32\\python.exe', 'C:\\Users\\luisfelipe_melo_mora\\AppData\\Local\\Programs\\Python\\Python37-32\\Scripts\\dvc', 'daemon', '-q', 'updater']'
DEBUG: Spawned '['c:\\users\\luisfelipe_melo_mora\\appdata\\local\\programs\\python\\python37-32\\python.exe', 'C:\\Users\\luisfelipe_melo_mora\\AppData\\Local\\Programs\\Python\\Python37-32\\Scripts\\dvc', 'daemon', '-q',
'updater']'
ERROR: unexpected error - Already unlocked
------------------------------------------------------------
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\main.py", line 48, in main
    cmd = args.func(args)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\command\base.py", line 48, in __init__
    updater.check()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\updater.py", line 54, in check
    self._with_lock(self._check, "checking")
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\updater.py", line 45, in _with_lock
    func()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 338, in __exit__
    self.unlock()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 287, in unlock
    raise NotLockedError('Already unlocked')
flufl.lock._lockfile.NotLockedError: Already unlocked
------------------------------------------------------------


Having any troubles? Hit us up at https://dvc.org/support, we are always happy to help!

I have a remote configuration by SSH:

['remote "myssh"']
url = ssh://domain:/path
user = myuser
port = 22
ask_password = true
[core]
remote = myssh

And here the version of dvc that im using:

> dvc version
DVC version: 0.69.0
Python version: 3.7.4
Platform: Windows-10-10.0.17134-SP0
Binary: False
Package: pip
Cache: reflink - False, hardlink - True, symlink - False

Thanks for your help!

bug p0-critical

Source

luchoPipe87

All 69 comments

Hi @luchoPipe87 !

That looks pretty weird. Btw, why did you remove fs info from dvc version output? Are you working inside some mounted partition?

efiop on 21 Nov 2019

Hi @efiop!
I didn't remove any information from the dvc version
I dont even know what fs (file system?) means. I'm not working in any particular partition.

luchoPipe87 on 21 Nov 2019

@luchoPipe87 You are not working on a NAS partition or anything like that? Just regular hard drive(ssd) on your machine? Btw, did you run dvc version inside of the dvc repo?

efiop on 21 Nov 2019

I get the same error when doing:

dvc init
dvc destroy -f

casperdcl on 21 Nov 2019

👀1

@casperdcl I am able to reproduce from that too! Thank you! Looks like it is our daemon getting confused by a deleted lock. Not quite sure what is up with dvc add in the original issue 🤔

efiop on 21 Nov 2019

I'm doing dvc init -f -v to try to restart the config but nothing seems to help :(

luchoPipe87 on 21 Nov 2019

@luchoPipe87 Is there any other dvc process running in the background?

efiop on 21 Nov 2019

I only have one project. So i would say no.
i was looking into the task manager and it doesnt seem any dvc process...

luchoPipe87 on 21 Nov 2019

@luchoPipe87 Got it. And does running simple dvc status show the same error?

efiop on 21 Nov 2019

If i do dvc status after the "add" error i got that:

> dvc status
ERROR: failed to obtain data status - Already unlocked


Having any troubles? Hit us up at https://dvc.org/support, we are always happy to help!

And i received this one after a dvc init -f -v

> dvc status
ERROR: unexpected error - Already unlocked


Having any troubles? Hit us up at https://dvc.org/support, we are always happy to help!

luchoPipe87 on 21 Nov 2019

@luchoPipe87 And could you try manually deleting .dvc/updater.lock and running dvc status once again, please?

efiop on 21 Nov 2019

every time that i deleted .dvc/updater.lock and i ran dvc status i receive the same error:

 dvc status
ERROR: unexpected error - Already unlocked


Having any troubles? Hit us up at https://dvc.org/support, we are always happy to help!

luchoPipe87 on 21 Nov 2019

@luchoPipe87 Interesting. And what flufl.lock version do you have installed? Could you show pip freeze | grep flufl.lock?

efiop on 21 Nov 2019

Sure! I cant do grep btw, im in Windows machine ...

luchoPipe87 on 21 Nov 2019

@luchoPipe87 Right, sorry, I thought that you are using gitbash 🙂 Not sure what is the alternative command for cmd/powershell.

Ok, so flufl lock version looks alright. Ok, let's try to narrow this down. Could you please try running this script in your repo root:

from dvc.lock import Lock

with Lock("mylock"):
    pass

efiop on 21 Nov 2019

No worries! :)
Here the output after running the script:

> python test.py
Traceback (most recent call last):
  File "test.py", line 4, in <module>
    pass
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 338, in __exit__
    self.unlock()
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 287, in unlock
    raise NotLockedError('Already unlocked')
flufl.lock._lockfile.NotLockedError: Already unlocked

luchoPipe87 on 21 Nov 2019

findstr instead of grep on windows

casperdcl on 21 Nov 2019

👀1 👍1

@luchoPipe87 Thanks! Ok, looks like it might be flufl.lock issue. Could you try this too, please:

from dvc.lock import Lock

with Lock("mylock") as lock:
    print("is locked: " + str(lock.is_locked))

efiop on 21 Nov 2019

@luchoPipe87 Ok, this might be the issue https://gitlab.com/warsaw/flufl.lock/blob/master/flufl/lock/_lockfile.py#L490 , because stat on windows is pretty useless IIRC.

Could you try running:

import os
from dvc.lock import Lock

with Lock("mylock") as lock:
    print("is locked: " + str(lock.is_locked))
    print("stat " + str(os.stat(lock._lockfile)))

efiop on 21 Nov 2019

As one could see https://github.com/iterative/dvc/blob/master/dvc/system.py#L280 we actually don't use os.stat to count the number of hardlinks. flufl.lock should do the same, but the project is pretty much dead. 'Guess we should consider forking it into something like flufl.lock2 and fix up these kind of things. But we should definitely start from simply patching it up in our Lock class.

efiop on 21 Nov 2019

@luchoPipe87 I'll prepare a patch in a minute and will ask you to try it out, if you don't mind 🙂

efiop on 21 Nov 2019

@luchoPipe87 Ok, please install my version of dvc with

pip install git+https://github.com/efiop/dvc.git@2831

and try running those commands again.

efiop on 21 Nov 2019

Here the output of the last command :)

> python test.py
Traceback (most recent call last):
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\dvc\lock.py", line 78, in lock
    super(Lock, self).lock(timedelta(seconds=DEFAULT_TIMEOUT))
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 259, in lock
    raise TimeOutError('Could not acquire the lock')
flufl.lock._lockfile.TimeOutError: Could not acquire the lock

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "test.py", line 4, in <module>
    with Lock("mylock") as lock:
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 334, in __enter__
    self.lock()
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\dvc\lock.py", line 80, in lock
    raise LockError(FAILED_TO_LOCK_MESSAGE)
dvc.lock.LockError: cannot perform the command because another DVC process seems to be running on this project. If that is not the case, manually remove `.dvc/lock` and try again.

luchoPipe87 on 21 Nov 2019

@luchoPipe87 You mean that test script with the patched dvc? Could you run dvc status with that patched dvc, please?

efiop on 21 Nov 2019

I installed your dvc version and its getting better (Is another error :P )

> dvc init -f -v
DEBUG: Removing '.dvc'
DEBUG: Adding '.dvc\config.local' to '.dvc\.gitignore'.
DEBUG: Adding '.dvc\updater' to '.dvc\.gitignore'.
DEBUG: Adding '.dvc\state-journal' to '.dvc\.gitignore'.
DEBUG: Adding '.dvc\state-wal' to '.dvc\.gitignore'.
DEBUG: Adding '.dvc\state' to '.dvc\.gitignore'.
DEBUG: Adding '.dvc\lock' to '.dvc\.gitignore'.
DEBUG: Adding '.dvc\tmp' to '.dvc\.gitignore'.
DEBUG: Adding '.dvc\updater.lock' to '.dvc\.gitignore'.
DEBUG: Adding '.dvc\cache' to '.dvc\.gitignore'.
Exception ignored in: <function Lock.__del__ at 0x03E86738>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 171, in _getdirinfo
    path, 0, FILE_SHARE_READ, None, OPEN_EXISTING, flags, None
pywintypes.error: (2, 'CreateFileW', 'The system cannot find the file specified.')

You can now commit the changes to git.

DEBUG: Analytics is enabled.
+---------------------------------------------------------------------+
|                                                                     |
|        DVC has enabled anonymous aggregate usage analytics.         |
|     Read the analytics documentation (and how to opt-out) here:     |
|              https://dvc.org/doc/user-guide/analytics               |
|                                                                     |
+---------------------------------------------------------------------+

What's next?
------------
- Check out the documentation: https://dvc.org/doc
- Get help and share ideas: https://dvc.org/chat
- Star us on GitHub: https://github.com/iterative/dvc
Exception ignored in: <function Lock.__del__ at 0x03E86738>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 171, in _getdirinfo
    path, 0, FILE_SHARE_READ, None, OPEN_EXISTING, flags, None
pywintypes.error: (2, 'CreateFileW', 'The system cannot find the file specified.')
Exception ignored in: <function Lock.__del__ at 0x03E86738>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 171, in _getdirinfo
    path, 0, FILE_SHARE_READ, None, OPEN_EXISTING, flags, None
pywintypes.error: (2, 'CreateFileW', 'The system cannot find the file specified.')
Exception ignored in: <function Lock.__del__ at 0x03E86738>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 171, in _getdirinfo
    path, 0, FILE_SHARE_READ, None, OPEN_EXISTING, flags, None
pywintypes.error: (2, 'CreateFileW', 'The system cannot find the file specified.')
Exception ignored in: <function Lock.__del__ at 0x03E86738>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 171, in _getdirinfo
    path, 0, FILE_SHARE_READ, None, OPEN_EXISTING, flags, None
pywintypes.error: (2, 'CreateFileW', 'The system cannot find the file specified.')
Exception ignored in: <function Lock.__del__ at 0x03E86738>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 171, in _getdirinfo
    path, 0, FILE_SHARE_READ, None, OPEN_EXISTING, flags, None
pywintypes.error: (2, 'CreateFileW', 'The system cannot find the file specified.')

luchoPipe87 on 21 Nov 2019

@luchoPipe87 I've updated my patch, please reinstall with

pip install --force-reinstall git+https://github.com/efiop/dvc.git@2831

and try dvc status again.

efiop on 21 Nov 2019

Here it is:

> dvc status
ERROR: failed to obtain data status - Already unlocked


Having any troubles? Hit us up at https://dvc.org/support, we are always happy to help!
Exception ignored in: <function Lock.__del__ at 0x047D4DB0>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 176, in _getdirinfo
    raise OSError(exc[2])
TypeError: 'error' object is not subscriptable
Exception ignored in: <function Lock.__del__ at 0x047D4DB0>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 176, in _getdirinfo
    raise OSError(exc[2])
TypeError: 'error' object is not subscriptable

luchoPipe87 on 21 Nov 2019

@luchoPipe87 Really sorry for these back and forwards, don't have my windows machine on me, so have to improvise a bit :) Updated my POC patch, please reinstall and give it another try. If it still fails, I'll just get to it properly in the morning with my windows machine.

efiop on 21 Nov 2019

@luchoPipe87 Ok, tested that patch on my win machine. It seems to work fine now for me. Interesting that os.stat works fine on my ntfs. About the missing fs lines, I simply forgot that psutil is not installed by default, so you need to install it manually first with pip install psutil. Could you please do that and then run dvc version once again?

efiop on 22 Nov 2019

@luchoPipe87 Also would appreciate if you could run

import os
from dvc.lock import Lock

with Lock("mylock") as lock:
    print("is locked: " + str(lock.is_locked))
    print("stat " + str(os.stat(lock._lockfile)))

once again.

efiop on 22 Nov 2019

Hi @efiop,
No worries! and thank you very much for your quick reply. It is still dont working :(
Here the outputs:

> dvc status
Exception ignored in: <function Lock.__del__ at 0x0449FF60>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 176, in _getdirinfo
    raise OSError(str(exc))
OSError: (2, 'CreateFileW', 'The system cannot find the file specified.')
ERROR: unexpected error - Already unlocked


Having any troubles? Hit us up at https://dvc.org/support, we are always happy to help!
Exception ignored in: <function Lock.__del__ at 0x0449FF60>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 176, in _getdirinfo
    raise OSError(str(exc))
OSError: (2, 'CreateFileW', 'The system cannot find the file specified.')
Exception ignored in: <function Lock.__del__ at 0x0449FF60>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 176, in _getdirinfo
    raise OSError(str(exc))
OSError: (2, 'CreateFileW', 'The system cannot find the file specified.')
Exception ignored in: <function Lock.__del__ at 0x0449FF60>
Traceback (most recent call last):
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 99, in __del__
    self.finalize()
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 326, in finalize
    self.unlock(unconditionally=True)
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 285, in unlock
    is_locked = self.is_locked
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 319, in is_locked
    if self._linkcount != 2:
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\lock.py", line 111, in
_linkcount
    return System._getdirinfo(self._lockfile).nNumberOfLinks
  File "c:\users\luisfelipe_melo_mora\appdata\local\programs\python\python37-32\lib\site-packages\dvc\system.py", line 176, in _getdirinfo
    raise OSError(str(exc))
OSError: (2, 'CreateFileW', 'The system cannot find the file specified.')

And here the output when i'm running your script:

 > python test.py
is locked: False
stat os.stat_result(st_mode=33206, st_ino=7881299348254485, st_dev=814588499, st_nlink=1, st_uid=0, st_gid=0, st_size=34, st_atime=1605944720, st_mtime=1605944720, st_ctime=1574408720)
Traceback (most recent call last):
  File "test.py", line 6, in <module>
    print("stat " + str(os.stat(lock._lockfile)))
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 338, in __exit__
    self.unlock()
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 287, in unlock
    raise NotLockedError('Already unlocked')
flufl.lock._lockfile.NotLockedError: Already unlocked

luchoPipe87 on 22 Nov 2019

Thanks @luchoPipe87 ! Just noticed that those errors are coming from __del__, so might be a yet another bug in flufl.lock. Looking into it.

E.g. pretty strange that it sets self._owned = True in __init__ and then if that is true, tries to unlock lock that it might not even own in reality. Looks like that in combination with non-working is_locked is causing this issue.

efiop on 22 Nov 2019

@luchoPipe87 Could you please install psutil with pip install psutil and then run dvc version once again and show me the output?

efiop on 22 Nov 2019

@efiop I did it! In my previous message you can find the output after the installation of this package.

luchoPipe87 on 22 Nov 2019

@luchoPipe87 There might be a misunderstanding here, I mean run $ dvc version command, not seeing it anywhere in the previous log 🤔 Also, I've updated my patched dvc, so please install it too first 🙂 In short, please run these commands:

pip install psutil
pip install --force-reinstall git+https://github.com/efiop/dvc.git@2831
dvc version
dvc status

and show output of the last two commands 🙂

efiop on 22 Nov 2019

Here it is, we're almost there (i suppose :D )

> dvc version
WARNING: Unable to detect supported link types, as cache directory '.dvc\cache' doesn't exist. It is usually auto-created by commands such as `dvc add/fetch/pull/run/import`, but you could create it manually to enable this check.
DVC version: 0.70.0+ffa157
Python version: 3.7.4
Platform: Windows-10-10.0.17134-SP0
Binary: False
Package: None
Filesystem type (cache directory): ('NTFS', 'C:\\')
Filesystem type (workspace): ('NTFS', 'C:\\')
PS C:\Users\luisfelipe_melo_mora\Documents\Projects\CI-CD\git\sshpass> dvc status
ERROR: unexpected error - Already unlocked


Having any troubles? Hit us up at https://dvc.org/support, we are always happy to help!

luchoPipe87 on 22 Nov 2019

Thanks! 🙂 Run one more test please:

import os
from dvc.lock import Lock

with Lock("mylock") as lock:
    print("is locked: " + str(lock.is_locked))
    print("linkcount: " + str(lock._linkcount))
    print("read: " + lock._read())
    print("claimfile: " + lock._claimfile)
    self._touch()

efiop on 22 Nov 2019


> python test.py
is locked: False
linkcount: 1
read: mylock^W10GZLMLH2^21340^1073831748
claimfile: mylock^W10GZLMLH2^21340^1073831748
Traceback (most recent call last):
  File "test.py", line 17, in <module>
    self._touch()
NameError: name 'self' is not defined

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "test.py", line 17, in <module>
    self._touch()
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 338, in __exit__
    self.unlock()
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 287, in unlock
    raise NotLockedError('Already unlocked')
flufl.lock._lockfile.NotLockedError: Already unlocked

luchoPipe87 on 22 Nov 2019

Sorry, made a typo. Here is a fixed version:

import os
from dvc.lock import Lock

with Lock("mylock") as lock:
    print("is locked: " + str(lock.is_locked))
    print("linkcount: " + str(lock._linkcount))
    print("read: " + lock._read())
    print("claimfile: " + lock._claimfile)
    lock._touch()

efiop on 22 Nov 2019

Sure! :D

> python test.py
Traceback (most recent call last):
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\dvc\lock.py", line 78, in lock
    super(Lock, self).lock(timedelta(seconds=DEFAULT_TIMEOUT))
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 259, in lock
    raise TimeOutError('Could not acquire the lock')
flufl.lock._lockfile.TimeOutError: Could not acquire the lock

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "test.py", line 4, in <module>
    with Lock("mylock") as lock:
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 334, in __enter__
    self.lock()
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\dvc\lock.py", line 80, in lock
    raise LockError(FAILED_TO_LOCK_MESSAGE)
dvc.lock.LockError: cannot perform the command because another DVC process seems to be running on this project. If that is not the case, manually remove `.dvc/lock` and try again.

luchoPipe87 on 22 Nov 2019

@luchoPipe87 So far, I'm surprised about the the _linkcount, looks like the hardlink is not created. Please run this:

import os
import logging
from dvc.lock import Lock

logging.getLogger('flufl.lock').setLevel(logging.DEBUG)

if os.path.exists("mylock"):
    os.unlink("mylock")

with Lock("mylock") as lock:
    print("is locked: " + str(lock.is_locked))
    print("linkcount: " + str(lock._linkcount))
    print("read: " + lock._read())
    print("claimfile: " + lock._claimfile)
    lock._touch()

efiop on 22 Nov 2019

Hi again @efiop,
Here the output of your code:

> python test.py
DEBUG: laying claim: mylock
DEBUG: got the lock: mylock
is locked: False
linkcount: 1
read: mylock^W10GZLMLH2^3184^153735438
claimfile: mylock^W10GZLMLH2^3184^153735438
Traceback (most recent call last):
  File "test.py", line 15, in <module>
    lock._touch()
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 338, in __exit__
    self.unlock()
  File "C:\Users\luisfelipe_melo_mora\AppData\Local\Programs\Python\Python37-32\lib\site-packages\flufl\lock\_lockfile.py", line 287, in unlock
    raise NotLockedError('Already unlocked')
flufl.lock._lockfile.NotLockedError: Already unlocked
DEBUG: finalize: mylock
DEBUG: unlocked: mylock

luchoPipe87 on 25 Nov 2019

@luchoPipe87 Thanks! Unfortunately, I'm still not able to reproduce 🙁 How about we have a video call to debug it on-screen together? It will take no more than 1.5 hours of your time and I'm certain we will be able to pinpoint the bug.

efiop on 25 Nov 2019

Yes sure! It can be on Wednesday around this time (9h30 here in sk)?

luchoPipe87 on 25 Nov 2019

@luchoPipe87 Sounds good! 🙂 Please drop me an email (you can find mine in my profile) and I'll send you an invite with google hangout. Thank you! 🙂

efiop on 25 Nov 2019

Done ;)

luchoPipe87 on 25 Nov 2019

❤1

@luchoPipe87 Thanks! Sent an invitation. Thank you for your patience and see you on Wednesday! 🙂

efiop on 25 Nov 2019

For the record. We've tried creating hardlinks and looking at the hardlink counter and it turns out that it is not increased for some unknown reason. The issue doesn't reproduce on my windows machine, so I suppose it might be some system settings that are preventing that. We've tried both python's os.link + os.stat as well as cmd/ps mklink + fsutil and they both behave the same, so looks like it is not a python bug, but rather something odd with the fs/settings. I'll try to do some reasearch to explain this behavior. For now, the workaround that I've provided is to use zc.lockfile instead of flufl.lock. Potentially, we might want to introduce a fallback logic in dvc to choose zc.lockfile instead of flufl.lock when os.link doesn't work as expected.

efiop on 27 Nov 2019

Considering the number of issues we get with flufl.lock, we might want to get back to using zc.lockfile by default and, if flock() is not supported, fallback to flufl.lock.

efiop on 27 Nov 2019

@efiop, what about the NTFS version (fsutil fsinfo ntfsinfo)? Was it the same on your computer?

ghost on 27 Nov 2019

@mroutis Good point! Don't know, didn't check 🙁@luchoPipe87 could you please provide it by running fsutil fsinfo ntfsinfo C: ?

efiop on 27 Nov 2019

Sorry guys...

luchoPipe87 on 27 Nov 2019

@luchoPipe87 , do you have any admin rights?

https://docs.microsoft.com/en-us/windows-server/administration/windows-commands/fsutil

ghost on 27 Nov 2019

my bad! :)

C:\WINDOWS\system32>fsutil fsinfo ntfsinfo C:
NTFS Volume Serial Number :        0xc6308daa308da253
NTFS Version   :                   3.1
LFS Version    :                   2.0
Number Sectors :                   0x000000003b5a07ff
Total Clusters :                   0x00000000076b40ff
Free Clusters  :                   0x000000000506bfd8
Total Reserved :                   0x0000000000001c88
Bytes Per Sector  :                512
Bytes Per Physical Sector :        4096
Bytes Per Cluster :                4096
Bytes Per FileRecord Segment    :  1024
Clusters Per FileRecord Segment :  0
Mft Valid Data Length :            0x000000001bb80000
Mft Start Lcn  :                   0x00000000000c0000
Mft2 Start Lcn :                   0x0000000000000002
Mft Zone Start :                   0x0000000000e53f60
Mft Zone End   :                   0x0000000000e58000
Max Device Trim Extent Count :     512
Max Device Trim Byte Count :       0xffffffff
Max Volume Trim Extent Count :     62
Max Volume Trim Byte Count :       0x40000000
Resource Manager Identifier :      67DFC453-B574-11E9-8A9C-A44CC841BDCA

luchoPipe87 on 27 Nov 2019

lol, just read the NTFS wikipedia article, the 3.1 version was released during XP (it is the latest version, so nothing to see here).
What Windows version are you using, btw? Not sure if they changed something related to the link count https://support.microsoft.com/en-us/help/4523205 :sweat_smile:

ghost on 27 Nov 2019

👀1

In my case:

PS C:\WINDOWS\system32> fsutil fsinfo ntfsinfo C:
NTFS Volume Serial Number :        0xa0a82441a82417f4
NTFS Version      :                3.1
LFS Version       :                2.0
Total Sectors     :                304,953,408  (145.4 GB)
Total Clusters    :                 38,119,176  (145.4 GB)
Free Clusters     :                  3,058,114  ( 11.7 GB)
Total Reserved Clusters :                5,425  ( 21.2 MB)
Reserved For Storage Reserve :               0  (  0.0 KB)
Bytes Per Sector  :                512
Bytes Per Physical Sector :        512
Bytes Per Cluster :                4096
Bytes Per FileRecord Segment    :  1024
Clusters Per FileRecord Segment :  0
Mft Valid Data Length :            809.75 MB
Mft Start Lcn  :                   0x00000000000c0000
Mft2 Start Lcn :                   0x0000000000000002
Mft Zone Start :                   0x0000000001df47c0
Mft Zone End   :                   0x0000000001e00fe0
MFT Zone Size  :                   200.13 MB
Max Device Trim Extent Count :     64
Max Device Trim Byte Count :       0x7fff8000
Max Volume Trim Extent Count :     62
Max Volume Trim Byte Count :       0x40000000
Resource Manager Identifier :      EBDB7152-118A-11E8-B3E9-EF47FED40743

efiop on 27 Nov 2019

@mroutis It was windows 10 :)

efiop on 27 Nov 2019

Which is just a skin over XP, right?

Win 7 and XP both have 40M lines of code (Vista in between had 50). I doubt things are much different now :)

casperdcl on 27 Nov 2019

😄1

@efiop, but there are different versions of Windows 10, right? I haven't read the release log, but might be a _driver_ thingy? https://docs.microsoft.com/en-us/windows/release-information/

ghost on 27 Nov 2019

@mroutis It was provided in the dvc version output: @luchoPipe87 has Windows-10-10.0.17134-SP0 and I have Windows-10-10.0.18362-SP0.

efiop on 27 Nov 2019

@luchoPipe87 Hm, btw, do you have a RAID or something setup on your machine? Maybe some special encryption stuff? I just wonder if the link we are creating get's altered by something right away, maybe some weird encryption stuff or backups... Considering that it is work machine, i suppose it has both raid/backups and some special encryption. Or maybe antivirus O_o?

efiop on 27 Nov 2019

@luchoPipe87 ping 🙂

efiop on 5 Dec 2019

hi @efiop !
Any news about the bug? I'm very sorry i was a bit busy these last days ;)

luchoPipe87 on 9 Dec 2019

@luchoPipe87 No worries 🙂 I still don't have a certain explanation for what is going on your machine, but the workaround that I've provided you with should still work and it will soon become the default behavior (see #2918).

efiop on 9 Dec 2019

Hi @luchoPipe87 !

Another user is having a similar strange hardlink behavior and we've created a patch that might solve it. If you have time, could you please run commands described in https://github.com/iterative/dvc/issues/3080#issuecomment-572213159 and show us the output of the last one, please?

Thanks!

efiop on 8 Jan 2020

Hi!
Here the output of dvc version after installing dvc@3080:

dvc version
WARNING: Unable to detect supported link types, as cache directory '.dvc\cache' doesn't exist. It is usually auto-created by commands such as dvc add/fetch/pull/run/import, but you could create it manually to enable this check.
DVC version: 0.80.0+7839cc
Python version: 3.7.4
Platform: Windows-10-10.0.17134-SP0
Binary: False
Package: None
Filesystem type (workspace): ('NTFS', 'C:\')

luchoPipe87 on 9 Jan 2020

Thanks @luchoPipe87 ! 🙏 Could you please create .dvc\cache directory and run it again?

efiop on 9 Jan 2020

hi,
I have created the .dvc\cache manually.
Then i ran the dvc version, here the output:

$dvc version
ERROR: unexpected error

Having any troubles? Hit us up at https://dvc.org/support, we are always happy to help!

luchoPipe87 on 9 Jan 2020

@luchoPipe87 Thanks! Ok, so it looks like your case is indeed a bit different. Hardlinks are created, but there is no way for us to count them to verify it. Very interesting. Still not sure what we could do there to fix it, but at least it works for you now with flock() based locks. Btw, did you ask your sys admin about it by any chance? Also, how is your dvc experience so far? 🙂

efiop on 9 Jan 2020

Was this page helpful?

0 / 5 - 0 ratings