regression in v1.23.1

[vrothberg]

v1.23.1 is causing regressions in Podman's apiv2 tests. I do not have the time to track it down but need to get work done that's currently blocked by the regression so I first revert the bump in c/image (see containers/image#1031).

[+0064s] not ok 291 [40-pods] POST libpod/pods/bar/start [] : status
[+0064s] #  expected: 200
[+0064s] #    actual: 500
[+0064s]   expected: 200

[vrothberg]

It looks like commit 7005d07 causes it.

[vrothberg]

$ POST libpod/pods/bar/start []                                          
HTTP/1.1 500 Internal Server Error                                       
Content-Type: application/json                                           
Date: Thu, 20 Aug 2020 12:11:03 GMT                                      
Content-Length: 117                                                      
                                                                         
{                                                                        
  "cause": "some containers failed",                                     
  "message": "error starting some containers: some containers failed",   
  "response": 500                                                        
}                                                                        
not ok 277 [40-pods] POST libpod/pods/bar/start [] : status              

[vrothberg]

What I am seeing on the server side:

time="2020-08-20T14:27:33+02:00" level=debug msg="Received: -1"
time="2020-08-20T14:27:33+02:00" level=debug msg="Cleaning up container c6c60358e96e7ebf8ce7953644fef5a2bbb10ddeac9fd9c1b019162f59b51bc5"
``

[vrothberg]

@giuseppe @nalind @rhatdan ... no idea what's going on here. The only thing I noticed is that the error only occurs when we're locking the graphlock before the layer store. If we lock after, CI passes again.

[rhatdan]

@zvier PTAL

[vrothberg]

Note that it might very well be a bug in Podman. At least we cannot rule that out.

[nalind]

@giuseppe @nalind @rhatdan ... no idea what's going on here. The only thing I noticed is that the error only occurs when we're locking the graphlock before the layer store. If we lock after, CI passes again.

That differs from the order in which they're acquired in Shutdown(), which would be a potential lock ordering problem.

[giuseppe]

I don't think there is a regression in v1.23.1, IMO it only showed a race condition that already existed.

I think the issue is that podman performs the unmount from the cleanup process, and that confuses the mounts RefCounter. So next time the podman daemon tries to do a mount, nothing happens because the RefCounter believes it is already mounted, while in reality it was unmounted by the cleanup process.

[giuseppe]

I've tried with:

diff --git a/vendor/github.com/containers/storage/drivers/counter.go b/vendor/github.com/containers/storage/drivers/counter.go
index 72551a38d..ec7a6090a 100644
--- a/vendor/github.com/containers/storage/drivers/counter.go
+++ b/vendor/github.com/containers/storage/drivers/counter.go
@@ -51,6 +51,8 @@ func (c *RefCounter) incdec(path string, infoOp func(minfo *minfo)) int {
                if c.checker.IsMounted(path) {
                        m.count++
                }
+       } else if !c.checker.IsMounted(path) {
+               m.count = 0
        }
        infoOp(m)
        count := m.count

Not sure if it is the best fix, but at least the tests pass now.

[giuseppe]

PR here: #698