Dvc: Error on first-time dvc pull

[kevin-hanselman]

Unfortunately, given the sensitive information in my code/data, I can't provide a fully reproducible bug report.

OS: Ubuntu 18.04.3 LTS
Present in DVC versions: 0.64.0 through 0.66.1

Steps to "reproduce":

git clone ...
cd <repo>
dvc pull

Until DVC v0.64.0 the above worked fine. Now I get the following error shortly after running DVC:

dvc pull
ERROR: unexpected error - 'NoneType' object has no attribute 'execute' 

I also tried reproducing this in a separate repo, but I couldn't reproduce it; it worked fine. My initial thought is that the repo which exhibits this bug uses two data sources imported via dvc import; perhaps that's related to the problem?

[shcheklein]

Hi @kevlar1818 ! Could you please run it in your environment with the -v flag: dvc pull -v and share as much of the stack trace as possible for you? It would be great to see at least what line, what file in DVC produces this exception.

[shcheklein]

@kevlar1818 was not able to reproduce it with some simple tests. Would really need a bit of your input there.

[kevin-hanselman]

@shcheklein Here's the full output. The only change I made was to obfuscate the S3 paths.

$ dvc pull -v
DEBUG: Trying to spawn '['/usr/bin/python3.7', '/usr/local/bin/dvc', 'daemon', '-q', 'updater']'
DEBUG: Spawned '['/usr/bin/python3.7', '/usr/local/bin/dvc', 'daemon', '-q', 'updater']'
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: cache '.dvc/cache/0d/d3328d29a89bf1a9efa55216714dea.dir' expected '0dd3328d29a89bf1a9efa55216714dea.dir' actual 'None'
DEBUG: Preparing to download data from 's3://XXXX'
DEBUG: Preparing to collect status from s3://XXXX
DEBUG: Collecting information from local cache...
DEBUG: cache '.dvc/cache/0d/d3328d29a89bf1a9efa55216714dea.dir' expected '0dd3328d29a89bf1a9efa55216714dea.dir' actual 'None'
DEBUG: Collecting information from remote cache...
DEBUG: Downloading 's3://XXXX/0d/d3328d29a89bf1a9efa55216714dea.dir' to '.dvc/cache/0d/d3328d29a89bf1a9efa55216714dea.dir'
DEBUG: Path .dvc/cache/0d/d3328d29a89bf1a9efa55216714dea.dir inode 13035981728
DEBUG: SELECT mtime, size, md5, timestamp from state WHERE inode=?
DEBUG: fetched: []
DEBUG: Path .dvc/cache/0d/d3328d29a89bf1a9efa55216714dea.dir inode 13035981728
DEBUG: SELECT mtime, size, md5, timestamp from state WHERE inode=?
DEBUG: fetched: []
DEBUG: INSERT INTO state(inode, mtime, size, md5, timestamp) VALUES (?, ?, ?, ?, ?)
DEBUG: cache '.dvc/cache/0d/d3328d29a89bf1a9efa55216714dea.dir' expected '0dd3328d29a89bf1a9efa55216714dea.dir' actual '0dd3328d29a89bf1a9efa55216714dea'
DEBUG: Preparing to download data from 's3://XXXX/'
DEBUG: Preparing to collect status from s3://XXXX/
DEBUG: Collecting information from local cache...
DEBUG: Path .dvc/cache/0d/d3328d29a89bf1a9efa55216714dea.dir inode 13035981728
DEBUG: SELECT mtime, size, md5, timestamp from state WHERE inode=?
DEBUG: fetched: [('1572360618341517056', '232', '0dd3328d29a89bf1a9efa55216714dea', '1572360618358746368')]
DEBUG: UPDATE state SET timestamp = ? WHERE inode = ?
DEBUG: cache '.dvc/cache/0d/d3328d29a89bf1a9efa55216714dea.dir' expected '0dd3328d29a89bf1a9efa55216714dea.dir' actual '0dd3328d29a89bf1a9efa55216714dea'
DEBUG: cache '.dvc/cache/80/0a0523baaf1b755cbd03c71338c658' expected '800a0523baaf1b755cbd03c71338c658' actual 'None'
DEBUG: cache '.dvc/cache/04/4abe681a5b3264aeb8213e57f411ca' expected '044abe681a5b3264aeb8213e57f411ca' actual 'None'
DEBUG: cache '.dvc/cache/fc/253970d6957be0732d6b9986d84e9b' expected 'fc253970d6957be0732d6b9986d84e9b' actual 'None'
DEBUG: Collecting information from remote cache...
DEBUG: Downloading 's3://XXXX/04/4abe681a5b3264aeb8213e57f411ca' to '.dvc/cache/04/4abe681a5b3264aeb8213e57f411ca'
DEBUG: Downloading 's3://XXXX/80/0a0523baaf1b755cbd03c71338c658' to '.dvc/cache/80/0a0523baaf1b755cbd03c71338c658'
DEBUG: Downloading 's3://XXXX/fc/253970d6957be0732d6b9986d84e9b' to '.dvc/cache/fc/253970d6957be0732d6b9986d84e9b'
DEBUG: Writing '/tmp/tmpp6u3h50ldvc-erepo/.dvc/config.local'.
DEBUG: cache '.dvc/cache/36/e1f35b55ce34234aca0aa3b75ab166.dir' expected '36e1f35b55ce34234aca0aa3b75ab166.dir' actual 'None'
DEBUG: Preparing to download data from 's3://XXXX/'
DEBUG: Preparing to collect status from s3://XXXX/
DEBUG: Collecting information from local cache...
DEBUG: cache '.dvc/cache/36/e1f35b55ce34234aca0aa3b75ab166.dir' expected '36e1f35b55ce34234aca0aa3b75ab166.dir' actual 'None'
DEBUG: Collecting information from remote cache...
DEBUG: Downloading 's3://XXXX/36/e1f35b55ce34234aca0aa3b75ab166.dir' to '.dvc/cache/36/e1f35b55ce34234aca0aa3b75ab166.dir'
DEBUG: Path .dvc/cache/36/e1f35b55ce34234aca0aa3b75ab166.dir inode 13038759721
DEBUG: SELECT mtime, size, md5, timestamp from state WHERE inode=?
DEBUG: SELECT count from state_info WHERE rowid=?
DEBUG: fetched: [(0,)]
DEBUG: UPDATE state_info SET count = ? WHERE rowid = ?
ERROR: unexpected error - 'NoneType' object has no attribute 'execute'
------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/dvc/main.py", line 43, in main
    ret = cmd.run()
  File "/usr/local/lib/python3.7/dist-packages/dvc/command/data_sync.py", line 31, in run
    recursive=self.args.recursive,
  File "/usr/local/lib/python3.7/dist-packages/dvc/repo/__init__.py", line 33, in wrapper
    ret = f(repo, *args, **kwargs)
  File "/usr/local/lib/python3.7/dist-packages/dvc/repo/pull.py", line 25, in pull
    recursive=recursive,
  File "/usr/local/lib/python3.7/dist-packages/dvc/repo/fetch.py", line 63, in _fetch
    d, f = _fetch_external(self, repo_url, repo_rev, files)
  File "/usr/local/lib/python3.7/dist-packages/dvc/repo/fetch.py", line 90, in _fetch_external
    cache.update(out.get_used_cache())
  File "/usr/local/lib/python3.7/dist-packages/dvc/output/base.py", line 415, in get_used_cache
    ret.update(self._collect_used_dir_cache(**kwargs))
  File "/usr/local/lib/python3.7/dist-packages/dvc/output/base.py", line 369, in _collect_used_dir_cache
    if self.cache.changed_cache_file(self.checksum):
  File "/usr/local/lib/python3.7/dist-packages/dvc/remote/base.py", line 649, in changed_cache_file
    actual = self.get_checksum(cache_info)
  File "/usr/local/lib/python3.7/dist-packages/dvc/remote/base.py", line 296, in get_checksum
    checksum = self.state.get(path_info)
  File "/usr/local/lib/python3.7/dist-packages/dvc/state.py", line 414, in get
    existing_record = self.get_state_record_for_inode(actual_inode)
  File "/usr/local/lib/python3.7/dist-packages/dvc/state.py", line 355, in get_state_record_for_inode
    self._execute(cmd, (self._to_sqlite(inode),))
  File "/usr/local/lib/python3.7/dist-packages/dvc/state.py", line 137, in _execute
    return self.cursor.execute(cmd, parameters)
AttributeError: 'NoneType' object has no attribute 'execute'
------------------------------------------------------------

[shcheklein]

@kevlar1818 thanks! 🙏 let us digest this information and try to reproduce.

[kevin-hanselman]

Thanks, @shcheklein! Should the "awaiting-response" tag be removed?

[shcheklein]

@kevlar1818 done!

[shcheklein]

@kevlar1818 was able to reproduce:

mkdir test-import
dvc import https://github.com/iterative/example-get-started data/features
// some really terrible UI is happening here - I'll create a ticket for this
git add .
git commit -am "init"
cd ..
git clone test-import test1
cd test1
dvc pull
// error happens

@Suor if you have any immediate ideas how to fix this (e.g. wrap with with state) let me know. Otherwise I'm looking into this.

[shcheklein]

@kevlar1818 created a PR to fix the issue. Thanks for reporting this. Waiting for the team to review - fingers crossed 🤞

[kevin-hanselman]

Thanks @shcheklein and @efiop! :tada: