dvc run broken in 0.66.1. Fails with error unexpected error.

[MikkelAntonsen]

Running dvc on ubuntu, installed with pip. Version is 0.66.1.
I get ERROR: unexpected error when my dvc run ends. The output files are made correctly, but *.dvc files do not appear and no checksumming is done.

Installing 0.65.0 fixes the problem.

I ran the command dvc run -f make_dataset.dvc -d make_dataset.py -d data -o dataset_train.json -o dataset_val.json -o dataset_test.json python3 make_dataset.py --directory data --output dataset --val-size 0.2 --test-size 0.1 --seed 42

[efiop]

@MikkelAntonsen Could you please post the full log by adding -v flag right after dvc run part of your command?

[MikkelAntonsen]

DEBUG: PRAGMA user_version;
DEBUG: fetched: [(3,)]
DEBUG: CREATE TABLE IF NOT EXISTS state (inode INTEGER PRIMARY KEY, mtime TEXT NOT NULL, size TEXT NOT NULL, md5 TEXT NOT NULL, timestamp TEXT NOT NULL)
DEBUG: CREATE TABLE IF NOT EXISTS state_info (count INTEGER)
DEBUG: CREATE TABLE IF NOT EXISTS link_state (path TEXT PRIMARY KEY, inode INTEGER NOT NULL, mtime TEXT NOT NULL)
DEBUG: INSERT OR IGNORE INTO state_info (count) SELECT 0 WHERE NOT EXISTS (SELECT * FROM state_info)
DEBUG: PRAGMA user_version = 3;
DEBUG: Removing output 'dataset_train.json' of 'make_dataset.dvc'.
DEBUG: Removing 'dataset_train.json'
DEBUG: Removing output 'dataset_val.json' of 'make_dataset.dvc'.
DEBUG: Removing 'dataset_val.json'
DEBUG: Removing output 'dataset_test.json' of 'make_dataset.dvc'.
DEBUG: Removing 'dataset_test.json'
Running command:
    python3 make_dataset.py --directory data --output dataset --val-size 0.2 --test-size 0.1 --seed 42
DEBUG: Computed stage 'make_dataset.dvc' md5: '4a7f27db527bf2bdf7fffb72ef70096b'
Looking in directory '/home/user/workspace/data'
DEBUG: Path make_dataset.py inode 11010278
DEBUG: SELECT mtime, size, md5, timestamp from state WHERE inode=?
DEBUG: fetched: [('1572340762339777536', '9969', '67e201582b32f55989aa63dee4b8ce9d', '1572345432579496704')]
DEBUG: UPDATE state SET timestamp = ? WHERE inode = ? 
DEBUG: Path data inode 11010118
DEBUG: SELECT mtime, size, md5, timestamp from state WHERE inode=?
DEBUG: fetched: [('ee8a1bf128d585064577cb8fbef01c30', '13183655891', '0cf4e4fc8a7c3c0a91a3df3872397518.dir', '1572345432726209536')]
DEBUG: UPDATE state SET timestamp = ? WHERE inode = ? 
DEBUG: SELECT count from state_info WHERE rowid=?
DEBUG: fetched: [(13,)]
DEBUG: UPDATE state_info SET count = ? WHERE rowid = ? 
ERROR: unexpected error
------------------------------------------------------------
Traceback (most recent call last):
  File "/home/user/.local/lib/python3.6/site-packages/dvc/main.py", line 43, in main
    ret = cmd.run()
  File "/home/user/.local/lib/python3.6/site-packages/dvc/command/run.py", line 54, in run 
    always_changed=self.args.always_changed,
  File "/home/user/.local/lib/python3.6/site-packages/dvc/repo/__init__.py", line 33, in wrapper
    ret = f(repo, *args, **kwargs)
  File "/home/user/.local/lib/python3.6/site-packages/dvc/repo/scm_context.py", line 4, in run 
    result = method(repo, *args, **kw)
  File "/home/user/.local/lib/python3.6/site-packages/dvc/repo/run.py", line 20, in run 
    stage.run(no_commit=kwargs.get("no_commit", False))
  File "/home/user/.local/lib/python3.6/site-packages/dvc/stage.py", line 883, in run 
    self.save()
  File "/home/user/.local/lib/python3.6/site-packages/dvc/stage.py", line 708, in save
    dep.save()
  File "/home/user/.local/lib/python3.6/site-packages/dvc/output/base.py", line 231, in save
    self.info = self.remote.save_info(self.path_info)
  File "/home/user/.local/lib/python3.6/site-packages/dvc/remote/base.py", line 323, in save_info
    return {self.PARAM_CHECKSUM: self.get_checksum(path_info)}
  File "/home/user/.local/lib/python3.6/site-packages/dvc/remote/base.py", line 312, in get_checksum
    checksum = self.get_dir_checksum(path_info)
  File "/home/user/.local/lib/python3.6/site-packages/dvc/remote/base.py", line 228, in get_dir_checksum
    dir_info = self._collect_dir(path_info)
  File "/home/user/.local/lib/python3.6/site-packages/dvc/remote/base.py", line 193, in _collect_dir
    for fname in self.walk_files(path_info):
  File "/home/user/.local/lib/python3.6/site-packages/dvc/remote/base.py", line 468, in walk_files
    raise NotImplementedError
NotImplementedError
------------------------------------------------------------

[efiop]

Hm, not able to reproduce. Looks like something went wrong here. Let's try to narrow it down. So data is a regular dir with nothing special about it? Could you run dvc run -v -d data -f tmp.dvc echo tmp and show the full log, please?

[MikkelAntonsen]

data is a symlink to an other directory. I get the same result as when I use the symlink when I use the absolute path to the directory.

Running your command I get

(scripts) user@user:~/workspace/retinanet $ dvc run -v -d data -f tmp.dvc echo tmp
DEBUG: PRAGMA user_version;
DEBUG: fetched: [(3,)]
DEBUG: CREATE TABLE IF NOT EXISTS state (inode INTEGER PRIMARY KEY, mtime TEXT NOT NULL, size TEXT NOT NULL, md5 TEXT NOT NULL, timestamp TEXT NOT NULL)
DEBUG: CREATE TABLE IF NOT EXISTS state_info (count INTEGER)
DEBUG: CREATE TABLE IF NOT EXISTS link_state (path TEXT PRIMARY KEY, inode INTEGER NOT NULL, mtime TEXT NOT NULL)
DEBUG: INSERT OR IGNORE INTO state_info (count) SELECT 0 WHERE NOT EXISTS (SELECT * FROM state_info)
DEBUG: PRAGMA user_version = 3;
Running command:
    echo tmp 
DEBUG: Computed stage 'tmp.dvc' md5: '79a813a29ee25bfe5ef24be13ca83c5d'
tmp
DEBUG: Path data inode 11010118
DEBUG: SELECT mtime, size, md5, timestamp from state WHERE inode=?
DEBUG: fetched: [('ee8a1bf128d585064577cb8fbef01c30', '13183655891', '0cf4e4fc8a7c3c0a91a3df3872397518.dir', '1572349258802244352')]
DEBUG: UPDATE state SET timestamp = ? WHERE inode = ? 
DEBUG: SELECT count from state_info WHERE rowid=?
DEBUG: fetched: [(13,)]
DEBUG: UPDATE state_info SET count = ? WHERE rowid = ? 
ERROR: unexpected error
------------------------------------------------------------
Traceback (most recent call last):
  File "/home/user/.local/lib/python3.6/site-packages/dvc/main.py", line 43, in main
    ret = cmd.run()
  File "/home/user/.local/lib/python3.6/site-packages/dvc/command/run.py", line 54, in run
    always_changed=self.args.always_changed,
  File "/home/user/.local/lib/python3.6/site-packages/dvc/repo/__init__.py", line 33, in wrapper
    ret = f(repo, *args, **kwargs)
  File "/home/user/.local/lib/python3.6/site-packages/dvc/repo/scm_context.py", line 4, in run
    result = method(repo, *args, **kw)
  File "/home/user/.local/lib/python3.6/site-packages/dvc/repo/run.py", line 20, in run
    stage.run(no_commit=kwargs.get("no_commit", False))
  File "/home/user/.local/lib/python3.6/site-packages/dvc/stage.py", line 883, in run
    self.save()
  File "/home/user/.local/lib/python3.6/site-packages/dvc/stage.py", line 708, in save
    dep.save()
  File "/home/user/.local/lib/python3.6/site-packages/dvc/output/base.py", line 231, in save
    self.info = self.remote.save_info(self.path_info)
  File "/home/user/.local/lib/python3.6/site-packages/dvc/remote/base.py", line 323, in save_info
    return {self.PARAM_CHECKSUM: self.get_checksum(path_info)}
  File "/home/user/.local/lib/python3.6/site-packages/dvc/remote/base.py", line 312, in get_checksum
    checksum = self.get_dir_checksum(path_info)
  File "/home/user/.local/lib/python3.6/site-packages/dvc/remote/base.py", line 228, in get_dir_checksum
    dir_info = self._collect_dir(path_info)
  File "/home/user/.local/lib/python3.6/site-packages/dvc/remote/base.py", line 193, in _collect_dir
    for fname in self.walk_files(path_info):
  File "/home/user/.local/lib/python3.6/site-packages/dvc/remote/base.py", line 468, in walk_files
    raise NotImplementedError
NotImplementedError
------------------------------------------------------------

[efiop]

@MikkelAntonsen Interesting. Ok, and could you please save this script into test_dvc.py:

from dvc.repo import Repo
from dvc.stage import Stage

repo = Repo(".")
stage = Stage.create(repo, deps=["data"])

print(type(stage.deps[0]))
print(type(stage.deps[0].remote))
print(type(stage.deps[0].cache))

and then run it with

python test_dvc.py

and show the output?

[MikkelAntonsen]

I get this

<class 'dvc.dependency.local.DependencyLOCAL'>
<class 'dvc.remote.local.RemoteLOCAL'>
<class 'dvc.remote.local.RemoteLOCAL'>
Exception ignored in: <function Lock.del at 0x7f8726d21ae8>
Traceback (most recent call last):
File "/home/user/miniconda3/lib/python3.7/site-packages/flufl/lock/_lockfile.py", line 331, in del
File "/home/user/miniconda3/lib/python3.7/site-packages/flufl/lock/_lockfile.py", line 326, in finalize
File "/home/user/miniconda3/lib/python3.7/site-packages/flufl/lock/_lockfile.py", line 285, in unlock
File "/home/user/miniconda3/lib/python3.7/site-packages/flufl/lock/_lockfile.py", line 312, in is_locked
File "/home/user/miniconda3/lib/python3.7/site-packages/flufl/lock/_lockfile.py", line 459, in _touch
ImportError: sys.meta_path is None, Python is likely shutting down

[efiop]

@MikkelAntonsen Yep, seems alright. (that last traceback is a known bug in __del__ of a dependency we are using, have a fix for that about to be merged).

How about

from dvc.repo import Repo
from dvc.stage import Stage

repo = Repo(".")
stage = Stage.create(repo, deps=["data"])

print(type(stage.deps[0]))
print(type(stage.deps[0].remote))
print(type(stage.deps[0].cache))

path_info = stage.deps[0].path_info
print(path_info)
stage.deps[0].remote.walk_files(path_info)
stage.deps[0].cache.walk_files(path_info)

?

[MikkelAntonsen]

<class 'dvc.dependency.local.DependencyLOCAL'>
<class 'dvc.remote.local.RemoteLOCAL'>
<class 'dvc.remote.local.RemoteLOCAL'>
data
Traceback (most recent call last):
File "test_dvc.py", line 13, in
stage.deps[0].remote.walk_files(path_info)
File "/home/mikkel/.local/lib/python3.6/site-packages/dvc/remote/base.py", line 468, in walk_files
raise NotImplementedError
NotImplementedError
Exception ignored in: <object repr() failed>
Traceback (most recent call last):
File "/home/mikkel/.local/lib/python3.6/site-packages/flufl/lock/_lockfile.py", line 331, in del
File "/home/mikkel/.local/lib/python3.6/site-packages/flufl/lock/_lockfile.py", line 326, in finalize
File "/home/mikkel/.local/lib/python3.6/site-packages/flufl/lock/_lockfile.py", line 285, in unlock
File "/home/mikkel/.local/lib/python3.6/site-packages/flufl/lock/_lockfile.py", line 312, in is_locked
File "/home/mikkel/.local/lib/python3.6/site-packages/flufl/lock/_lockfile.py", line 459, in _touch
ImportError: sys.meta_path is None, Python is likely shutting down

[efiop]

@MikkelAntonsen Hm, that is pretty interesting. For some reason, it doesn't see walk_files defined in RemoteLOCAL. Not quite sure what is going on. Could you try to reinstall dvc, please?