exp run: multiple error messages

[skshetry]

I had run this experiment before already. But now, it provides same error messages twice (from two different workers I think), and makes the output very ugly.

And even though it has failed, it suggests me to track files and also updates lock files, nothing wrong with it but is questionable.

$ dvc exp run --set-param foo=13 -v
2021-03-08 17:34:44,409 DEBUG: Check for update is disabled.
2021-03-08 17:34:44,513 DEBUG: Detaching HEAD at 'HEAD'               
2021-03-08 17:34:44,515 DEBUG: Stashing workspace
2021-03-08 17:34:44,523 DEBUG: Stashing changes in 'refs/stash'
2021-03-08 17:34:44,537 DEBUG: Applying stash commit 'e9fc4a1adbb971cbf0dc9dad959f9a1186ab82b8'
2021-03-08 17:34:44,704 DEBUG: Using experiment params 'defaultdict(<class 'dict'>, {'params.yaml': {'foo': 13}})'
2021-03-08 17:34:44,716 DEBUG: Stashing changes in 'refs/exps/stash'
2021-03-08 17:34:44,740 DEBUG: Stashed experiment 'bfc3174' with baseline 'f9d0f0a' for future execution.
2021-03-08 17:34:44,742 DEBUG: Restoring stashed workspace
2021-03-08 17:34:44,742 DEBUG: Popping from stash 'refs/stash'
2021-03-08 17:34:44,742 DEBUG: Applying stash commit 'e9fc4a1adbb971cbf0dc9dad959f9a1186ab82b8'
2021-03-08 17:34:44,750 DEBUG: Dropping 'refs/stash@{0}'
2021-03-08 17:34:44,755 DEBUG: Removing '/tmp/tmp.WTJ1L9Of5F/.git/logs/refs/stash'
2021-03-08 17:34:44,757 DEBUG: Restore HEAD to 'master'
2021-03-08 17:34:44,760 DEBUG: Detaching HEAD at 'f9d0f0af0f3884238997ba7a1415f147fd3341e6'
2021-03-08 17:34:44,771 DEBUG: Removing 'dvc.lock'
2021-03-08 17:34:44,771 DEBUG: Popping from stash 'refs/exps/stash'
2021-03-08 17:34:44,772 DEBUG: Applying stash commit 'bfc31747adac7ade25bb20938a0cbd678c317336'
2021-03-08 17:34:44,779 DEBUG: Dropping 'refs/exps/stash@{0}'
2021-03-08 17:34:44,784 DEBUG: Removing '/tmp/tmp.WTJ1L9Of5F/.git/logs/refs/exps/stash'
2021-03-08 17:34:44,795 DEBUG: Running repro in '/tmp/tmp.WTJ1L9Of5F'
2021-03-08 17:34:44,795 DEBUG: Removing '/tmp/tmp.WTJ1L9Of5F/.dvc/tmp/repro.dat'
2021-03-08 17:34:44,802 DEBUG: Lockfile for 'dvc.yaml' not found      
2021-03-08 17:34:44,805 DEBUG: Removing 'metrics.yaml'
2021-03-08 17:34:44,811 DEBUG: Lockfile for 'dvc.yaml' not found      
2021-03-08 17:34:44,814 DEBUG: Lockfile for 'dvc.yaml' not found
2021-03-08 17:34:45,144 DEBUG: Dependency 'params.yaml' of stage: 'echo' changed because it is '{'foo': 'new'}'.
2021-03-08 17:34:45,144 DEBUG: stage: 'echo' changed.
2021-03-08 17:34:45,145 DEBUG: Removing output 'metrics.yaml' of stage: 'echo'.
2021-03-08 17:34:45,145 DEBUG: Removing 'metrics.yaml'
2021-03-08 17:34:45,147 DEBUG: defaultdict(<class 'dict'>, {'params.yaml': {'foo': 'new'}})
Stage 'echo' is cached - skipping run, checking out outputs
2021-03-08 17:34:45,151 DEBUG: 'metrics.yaml' doesn't exist.
2021-03-08 17:34:45,151 DEBUG: Checking out 'metrics.yaml' with cache 'object md5: c9bd145ce5d42186ba42f08ead99cfc4'.
2021-03-08 17:34:45,151 DEBUG: Cache type 'reflink' is not supported: reflink is not supported
2021-03-08 17:34:45,152 DEBUG: Created 'copy': .dvc/cache/c9/bd145ce5d42186ba42f08ead99cfc4 -> metrics.yaml
2021-03-08 17:34:45,153 DEBUG: state save (8437, 1615204185148178944, 8) c9bd145ce5d42186ba42f08ead99cfc4
2021-03-08 17:34:45,158 DEBUG: {'metrics.yaml': 'modified'}
2021-03-08 17:34:45,159 DEBUG: Computed stage: 'echo' md5: '72854c5a63f25ca969565a7afe7b0bd8'
2021-03-08 17:34:45,163 DEBUG: Checking out 'metrics.yaml' with cache 'object md5: c9bd145ce5d42186ba42f08ead99cfc4'.
2021-03-08 17:34:45,163 DEBUG: Skipping copying for 'metrics.yaml', since it is not a symlink or a hardlink.
2021-03-08 17:34:45,163 DEBUG: state save (8437, 1615204185148178944, 8) c9bd145ce5d42186ba42f08ead99cfc4
2021-03-08 17:34:45,165 DEBUG: stage: 'echo' was reproduced
Generating lock file 'dvc.lock'
Updating lock file 'dvc.lock'

To track the changes with git, run:

	git add params.yaml
2021-03-08 17:34:45,195 ERROR: Reproduced experiment conflicts with existing experiment 'exp-00f1d'. To overwrite the existing experiment run:

	dvc exp run -f ...

To run this experiment with a different name run:

	dvc exp run -n <new_name> ...

------------------------------------------------------------
Traceback (most recent call last):
  File "/home/saugat/repos/iterative/dvc/dvc/repo/experiments/executor/base.py", line 341, in _repro_dvc
    yield dvc
  File "/home/saugat/repos/iterative/dvc/dvc/repo/experiments/executor/base.py", line 294, in reproduce
    cls.commit(
  File "/home/saugat/repos/iterative/dvc/dvc/repo/experiments/executor/base.py", line 412, in commit
    raise ExperimentExistsError(ref_info.name)
dvc.repo.experiments.base.ExperimentExistsError: Reproduced experiment conflicts with existing experiment 'exp-00f1d'. To overwrite the existing experiment run:

	dvc exp run -f ...

To run this experiment with a different name run:

	dvc exp run -n <new_name> ...

------------------------------------------------------------
2021-03-08 17:34:45,315 DEBUG: Restore HEAD to 'master'
2021-03-08 17:34:45,321 ERROR: Reproduced experiment conflicts with existing experiment 'exp-00f1d'. To overwrite the existing experiment run:

	dvc exp run -f ...

To run this experiment with a different name run:

	dvc exp run -n <new_name> ...

------------------------------------------------------------
Traceback (most recent call last):
  File "/home/saugat/repos/iterative/dvc/dvc/main.py", line 50, in main
    ret = cmd.run()
  File "/home/saugat/repos/iterative/dvc/dvc/command/experiments.py", line 520, in run
    results = self.repo.experiments.run(
  File "/home/saugat/repos/iterative/dvc/dvc/repo/experiments/__init__.py", line 831, in run
    return run(self.repo, *args, **kwargs)
  File "/home/saugat/repos/iterative/dvc/dvc/repo/__init__.py", line 49, in wrapper
    return f(repo, *args, **kwargs)
  File "/home/saugat/repos/iterative/dvc/dvc/repo/experiments/run.py", line 37, in run
    return repo.experiments.reproduce_one(
  File "/home/saugat/repos/iterative/dvc/dvc/repo/experiments/__init__.py", line 382, in reproduce_one
    results = self._workspace_repro()
  File "/home/saugat/repos/iterative/dvc/dvc/repo/experiments/__init__.py", line 57, in wrapper
    ret = f(exp, *args, **kwargs)
  File "/home/saugat/repos/iterative/dvc/dvc/repo/experiments/__init__.py", line 721, in _workspace_repro
    exec_result = BaseExecutor.reproduce(
  File "/home/saugat/repos/iterative/dvc/dvc/repo/experiments/executor/base.py", line 294, in reproduce
    cls.commit(
  File "/home/saugat/repos/iterative/dvc/dvc/repo/experiments/executor/base.py", line 412, in commit
    raise ExperimentExistsError(ref_info.name)
dvc.repo.experiments.base.ExperimentExistsError: Reproduced experiment conflicts with existing experiment 'exp-00f1d'. To overwrite the existing experiment run:

	dvc exp run -f ...

To run this experiment with a different name run:

	dvc exp run -n <new_name> ...

------------------------------------------------------------

[dberenbaum]

To clarify the issue here, this situation occurs when running the same non-persisted experiment multiple times, correct?

What is the expected behavior?

1. Show only one message (multiple workers issue)
2. Not suggesting to track changes with Git
3. Otherwise continue to show the error as is?

EDIT: Seems that this occurs anytime the same experiment is run multiple times, regardless of whether it is persisted in Git history, UNLESS it matches HEAD, in which case experiment is skipped.

[pmrowla]

This is a bug, running the same experiment more than once is intended to be allowed (and we will only save repeated experiments once, without requiring -f/--force).

the expected behavior is that we just output Reproduced existing experiment 'exp-00f1d' and that's it. There should not actually be any git conflicts for identical experiments, the bug is that something under the hood is introducing a git conflict

[dberenbaum]

Does it matter if they have different parent commits?

[pmrowla]

@dberenbaum if they have different parent commits they will be considered 2 separate experiments. Experiment refs are stored in separate namespaces grouped by parent commit, so there would not be be a git conflict.

[pmrowla]

Looks like this issue is specific to workspace runs, using --temp does not error out and just returns the existing experiment (as expected)

[pmrowla]

The duplicate error message was happening for workspace runs because they don't happen in a separate multiprocessing context. For multiprocessing (temp) runs exp executors have to log all of their exceptions separately because any raised exceptions will end up being dropped by ProcessPoolExecutor before the main/outer level DVC error logging happens.

but for workspace runs we don't use multiprocessing, so any raised exceptions are passed directly into the outer level DVC error logging, so we were mistakenly logging them twice (once inside the executor and once in the main/outer level error handling).