dvc exp show: fails with ERROR: unexpected error - 'NoneType' object is not subscriptable

[clamydo]

Bug Report

Description

I have set up a DVC pipeline. Before and after running dvc exp run (for the first time), which runs successful, I get following error

$ dvc exp show -vv
2021-03-24 12:05:23,923 TRACE: Namespace(all_branches=False, all_commits=False, all_tags=False, cd='.', cmd='show', cprofile=False, cprofile_dump=None, exclude_metrics=[], exclude_params=[], func=<class 'dvc.command.experiments.CmdExperimentsShow'>, include_metrics=[], include_params=[], instrument=False, instrument_open=False, no_pager=False, no_timestamp=False, num=1, pdb=False, precision=None, quiet=0, sha=False, show_json=False, sort_by=None, sort_order='asc', verbose=2, version=None)
2021-03-24 12:05:24,071 DEBUG: Check for update is enabled.
2021-03-24 12:05:24,186 TRACE: Context during resolution of stage prepare:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,188 TRACE: Context during resolution of stage train:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,190 TRACE: Context during resolution of stage infer:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,191 TRACE: Context during resolution of stage evaluate:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,353 TRACE: Context during resolution of stage prepare:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,354 TRACE: Context during resolution of stage train:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,356 TRACE: Context during resolution of stage infer:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,357 TRACE: Context during resolution of stage evaluate:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,379 TRACE: Context during resolution of stage prepare:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,379 DEBUG: Lockfile for 'dvc.yaml' not found
2021-03-24 12:05:24,381 TRACE: Context during resolution of stage train:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,383 TRACE: Context during resolution of stage infer:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,385 TRACE: Context during resolution of stage evaluate:
{'target': {'line_id': 6100, 'startdate': '2020-01-03', 'enddate': '2020-01-15'}, 'parameter': {'win_size': 15, 'speed_threshold': -20, 'gradient_threshold': 0.15, 'slice_distance_threshold': 3.0, 'com_distance_threshold': 2.0}}
2021-03-24 12:05:24,404 ERROR: unexpected error - 'NoneType' object is not subscriptable
------------------------------------------------------------
Traceback (most recent call last):
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/main.py", line 50, in main
    ret = cmd.run()
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/command/experiments.py", line 371, in run
    all_experiments = self.repo.experiments.show(
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/repo/experiments/__init__.py", line 810, in show
    return show(self.repo, *args, **kwargs)
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/repo/__init__.py", line 49, in wrapper
    return f(repo, *args, **kwargs)
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/repo/experiments/show.py", line 112, in show
    res[rev]["baseline"] = _collect_experiment_commit(
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/repo/experiments/show.py", line 32, in _collect_experiment_commit
    vals = _read_metrics(repo, metrics, rev)
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/repo/metrics/show.py", line 82, in _read_metrics
    val = load_yaml(metric, fs=fs)
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/utils/serialize/_yaml.py", line 20, in load_yaml
    return _load_data(path, parser=parse_yaml, fs=fs)
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/utils/serialize/_common.py", line 50, in _load_data
    with open_fn(path, encoding="utf-8") as fd:  # type: ignore
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/fs/repo.py", line 143, in open
    return dvc_fs.open(path_info, mode=mode, encoding=encoding, **kwargs)
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/fs/dvc.py", line 81, in open
    remote_info = remote_obj.odb.hash_to_path_info(checksum)
  File "/home/<user>/.local/pipx/venvs/dvc/lib/python3.8/site-packages/dvc/objects/db/base.py", line 68, in hash_to_path_info
    return self.fs.path_info / hash_[0:2] / hash_[2:]
TypeError: 'NoneType' object is not subscriptable
------------------------------------------------------------
2021-03-24 12:05:24,620 DEBUG: Version info for developers:
DVC version: 2.0.7 (pip)
---------------------------------
Platform: Python 3.8.3 on Linux-5.4.72-microsoft-standard-WSL2-x86_64-with-glibc2.29
Supports: http, https
Cache types: hardlink, symlink
Cache directory: ext4 on /dev/sdb
Caches: local
Remotes: local
Workspace directory: ext4 on /dev/sdb
Repo: dvc, git

There is a line 2021-03-24 12:05:24,379 DEBUG: Lockfile for 'dvc.yaml' not found, however there is a dvc.lock file in the working directory present.

Reproduce

I have not tried to reproduce this in a minimal example yet; this is what I do in my repo

1. dvc exp show -> error
2. dvc exp run -> okay
3. dvc exp list -> okay
4. dvc exp show -> error

Environment information

Output of dvc doctor:

$ dvc doctor
DVC version: 2.0.7 (pip)
---------------------------------
Platform: Python 3.8.3 on Linux-5.4.72-microsoft-standard-WSL2-x86_64-with-glibc2.29
Supports: http, https
Cache types: hardlink, symlink
Cache directory: ext4 on /dev/sdb
Caches: local
Remotes: local
Workspace directory: ext4 on /dev/sdb
Repo: dvc, git

Additional Information (if any):

[clamydo]

Perhaps, it is a racing condition? I've stepped into the debugger. This is what I get

$ (Pdb) p out.hash_info
HashInfo(name=None, value=None, size=None, nfiles=None)

$(Pdb) p self._find_outs(path, strict=False)[0].hash_info
HashInfo(name='md5', value='58037eb1e92e534b55a3f892734dab4a', size=133, nfiles=None)

In the second command, I reran the _find_out method that is called a few lines earlier, where the error happens. That is, in the debugger I get non-None values, as opposed to the observation above. Therefore, could this be a racing condition?

[clamydo]

For what it's worth: I cannot reproduce this bug anymore.

[pmrowla]

There is a line 2021-03-24 12:05:24,379 DEBUG: Lockfile for 'dvc.yaml' not found, however there is a dvc.lock file in the working directory present.

@fkjogu

dvc.lock was probably not git committed at this point in time, so DVC errored out trying to load a nonexistent dvc.lock version from HEAD (which is different than the working directory version).

If you run dvc exp show -A I'm guessing the error will come back (since DVC will try to load the "bad" git commit will when using -A).

[pmrowla]

Closing this as a duplicate of #5667, basically we need to mark these "bad" commits in the table, and then continue trying to process whatever other else we can.

[clamydo]

If you run dvc exp show -A I'm guessing the error will come back (since DVC will try to load the "bad" git commit will when using -A).

Can confirm, Thanks for the reply