Opam "cannot revert" some things "while removing", but it is unclear why

[RalfJung]

On CI, we are seeing lots of logs like this:

 [WARNING] While removing coq-stdpp.dev.2020-02-11.3.e95c967d: cannot revert:
            - modifications of lib/coq/user-contrib/stdpp/zmap.vo
            - modifications of lib/coq/user-contrib/stdpp/zmap.v
            - modifications of lib/coq/user-contrib/stdpp/zmap.glob
            - modifications of lib/coq/user-contrib/stdpp/vector.vo
            - modifications of lib/coq/user-contrib/stdpp/vector.v
            - modifications of lib/coq/user-contrib/stdpp/vector.glob
            - modifications of lib/coq/user-contrib/stdpp/telescopes.vo
            - modifications of lib/coq/user-contrib/stdpp/telescopes.v
            - modifications of lib/coq/user-contrib/stdpp/telescopes.glob
            - modifications of lib/coq/user-contrib/stdpp/tactics.vo
            - modifications of lib/coq/user-contrib/stdpp/tactics.v
            - modifications of lib/coq/user-contrib/stdpp/tactics.glob
            - modifications of lib/coq/user-contrib/stdpp/strings.vo
            - modifications of lib/coq/user-contrib/stdpp/strings.v
            - modifications of lib/coq/user-contrib/stdpp/strings.glob
            - modifications of lib/coq/user-contrib/stdpp/stringmap.vo
            - modifications of lib/coq/user-contrib/stdpp/stringmap.v
            - modifications of lib/coq/user-contrib/stdpp/stringmap.glob
            - modifications of lib/coq/user-contrib/stdpp/streams.vo
            - modifications of lib/coq/user-contrib/stdpp/streams.v
            - modifications of lib/coq/user-contrib/stdpp/streams.glob
[...]

Unfortunately, it is entirely unclear (a) what exactly this means, and (b) why it happens. Does this mean it tried to remove the file but failed due to permissions? Does this mean it did not even try to remove the file? Does it mean it actually removed the file but something was odd? Given this is a warning (and not a fatal error), I would assume the files actually do get removed appropriately, but I cannot tell. (This is happening on CI, so interactive debugging is not possible.) Also, nothing is ever touching those files besides opam (and the CI machinery creating/restoring the cache), so it is not clear what the cause of the issue is.

Debugging is made near impossible by opam not even telling me what the actual issue is. As a wild guess, I thought maybe the CI failed to properly restore the mtime of the files in the cache, but the mtime looks fine. So maybe there's something else about these files that is not preserved by CI caching, but without any information from opam I am at a loss about what that could be.

The expected behavior would be for opam to at least explain what is happening so there is some chance of debugging the problem.

We are now seeing some issues on CI that are not reproducible locally, and opam failing to properly clean up might help explain what is going on.

# opam config report
# opam-version      2.0.5 
# self-upgrade      no
# system            arch=x86_64 os=linux os-distribution=debian os-version=9
# solver            builtin-mccs+glpk
# install-criteria  -removed,-count[version-lag,request],-count[version-lag,changed],-changed
# upgrade-criteria  -removed,-count[version-lag,solution],-new
# jobs              20
# repositories      2 (http), 1 (version-controlled) (default repo at d74ac435)
# pinned            1 (rsync), 1 (version)
# current-switch    ocaml-base-compiler.4.07.1

[RalfJung]

I added -vvv, that does not say anything more either.

[rjbou]

opam does some snapshot of its internals. It is used to know what has been installed, but also at removal if installed files were changed or no. In your case, those files has some changes between install and removal. I suppose that you don't use the precise tracking, so the diff is made is made according timestamps, not content. There is a know problem with mtime & docker (cf. #3997).
As suggested in #3997 (comment) you canuse the precise tracking to not depend on docker mtime (but on hashes).

[rjbou]

Closing as duplicate of #3997.

[RalfJung]

Thanks! I have added OPAMPRECISETRACKING=1 to our ever-growing list of opam env vars we need to set.

Having opam -vv spell out some more details about e.g. timestamps that changed would still be very helpful, though. I'd have lost much less time on this if such information was made available.

[rjbou]

@RalfJung cf. #4094 (comment) for better management of this kind of issue.