summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorJhon Honce <jhonce@redhat.com>2021-10-11 18:07:49 -0700
committerJhon Honce <jhonce@redhat.com>2021-10-12 09:53:19 -0700
commit0459484bdf51b3aabc51f2ae82136b6b0f3d88ba (patch)
tree63251819c8a2fd7b61480aa761f7e761c66c9b1c
parent2fcec59445267e8c8e06005539701a172d3db8a5 (diff)
downloadpodman-0459484bdf51b3aabc51f2ae82136b6b0f3d88ba.tar.gz
podman-0459484bdf51b3aabc51f2ae82136b6b0f3d88ba.tar.bz2
podman-0459484bdf51b3aabc51f2ae82136b6b0f3d88ba.zip
Fix CI flake on time of shutdown for API service
* Increase timeout for tests to 10s * To aid in debugging add PID to shutdown package logging * Added new message for forced service shutdown * Always wait for HTTP server to shutdown, duration of 0 not friendly to clients Note: The log event "IdleTracker: StateClosed transition by connection marked un-managed" denotes a TCP connection has been initiated but no HTTP request was sent. And is expected during these tests. Fixes #11921 Signed-off-by: Jhon Honce <jhonce@redhat.com>
-rw-r--r--cmd/podman/system/service_abi.go2
-rw-r--r--libpod/shutdown/handler.go18
-rw-r--r--pkg/api/server/server.go23
-rw-r--r--test/e2e/system_service_test.go8
4 files changed, 31 insertions, 20 deletions
diff --git a/cmd/podman/system/service_abi.go b/cmd/podman/system/service_abi.go
index 0a4be6aea..b9bd7538f 100644
--- a/cmd/podman/system/service_abi.go
+++ b/cmd/podman/system/service_abi.go
@@ -93,7 +93,7 @@ func restService(flags *pflag.FlagSet, cfg *entities.PodmanConfig, opts entities
return err
}
defer func() {
- if err := server.Shutdown(false); err != nil {
+ if err := server.Shutdown(true); err != nil {
logrus.Warnf("Error when stopping API service: %s", err)
}
}()
diff --git a/libpod/shutdown/handler.go b/libpod/shutdown/handler.go
index b0feafa0b..9add05c9c 100644
--- a/libpod/shutdown/handler.go
+++ b/libpod/shutdown/handler.go
@@ -5,9 +5,10 @@ import (
"os/signal"
"sync"
"syscall"
+ "time"
"github.com/pkg/errors"
- "github.com/sirupsen/logrus"
+ logrusImport "github.com/sirupsen/logrus"
)
var (
@@ -25,6 +26,7 @@ var (
// Ordering that on-shutdown handlers will be invoked.
handlerOrder []string
shutdownInhibit sync.RWMutex
+ logrus = logrusImport.WithField("PID", os.Getpid())
)
// Start begins handling SIGTERM and SIGINT and will run the given on-signal
@@ -44,25 +46,31 @@ func Start() error {
go func() {
select {
case <-cancelChan:
+ logrus.Infof("Received shutdown.Stop(), terminating!")
signal.Stop(sigChan)
close(sigChan)
close(cancelChan)
stopped = true
return
case sig := <-sigChan:
- logrus.Infof("Received shutdown signal %v, terminating!", sig)
+ logrus.Infof("Received shutdown signal %q, terminating!", sig.String())
shutdownInhibit.Lock()
handlerLock.Lock()
+
for _, name := range handlerOrder {
handler, ok := handlers[name]
if !ok {
- logrus.Errorf("Shutdown handler %s definition not found!", name)
+ logrus.Errorf("Shutdown handler %q definition not found!", name)
continue
}
- logrus.Infof("Invoking shutdown handler %s", name)
+
+ logrus.Infof("Invoking shutdown handler %q", name)
+ start := time.Now()
if err := handler(sig); err != nil {
- logrus.Errorf("Running shutdown handler %s: %v", name, err)
+ logrus.Errorf("Running shutdown handler %q: %v", name, err)
}
+ logrus.Debugf("Completed shutdown handler %q, duration %v", name,
+ time.Since(start).Round(time.Second))
}
handlerLock.Unlock()
shutdownInhibit.Unlock()
diff --git a/pkg/api/server/server.go b/pkg/api/server/server.go
index 6e9578cd1..8c5c7aeeb 100644
--- a/pkg/api/server/server.go
+++ b/pkg/api/server/server.go
@@ -207,7 +207,7 @@ func (s *APIServer) setupSystemd() {
func (s *APIServer) Serve() error {
s.setupPprof()
- if err := shutdown.Register("server", func(sig os.Signal) error {
+ if err := shutdown.Register("service", func(sig os.Signal) error {
return s.Shutdown(true)
}); err != nil {
return err
@@ -272,20 +272,24 @@ func (s *APIServer) setupPprof() {
// Shutdown is a clean shutdown waiting on existing clients
func (s *APIServer) Shutdown(halt bool) error {
- if s.idleTracker.Duration == UnlimitedServiceDuration && !halt {
- logrus.Debug("API service shutdown request ignored as Duration is UnlimitedService")
+ switch {
+ case halt:
+ logrus.Debug("API service forced shutdown, ignoring timeout Duration")
+ case s.idleTracker.Duration == UnlimitedServiceDuration:
+ logrus.Debug("API service shutdown request ignored as timeout Duration is UnlimitedService")
return nil
}
shutdownOnce.Do(func() {
- if logrus.IsLevelEnabled(logrus.DebugLevel) {
- _, file, line, _ := runtime.Caller(1)
- logrus.Debugf("API service shutdown by %s:%d, %d/%d connection(s)",
- file, line, s.idleTracker.ActiveConnections(), s.idleTracker.TotalConnections())
- }
+ logrus.Debugf("API service shutdown, %d/%d connection(s)",
+ s.idleTracker.ActiveConnections(), s.idleTracker.TotalConnections())
// Gracefully shutdown server(s), duration of wait same as idle window
- ctx, cancel := context.WithTimeout(context.Background(), s.idleTracker.Duration)
+ deadline := 1 * time.Second
+ if s.idleTracker.Duration > 0 {
+ deadline = s.idleTracker.Duration
+ }
+ ctx, cancel := context.WithTimeout(context.Background(), deadline)
go func() {
defer cancel()
@@ -296,7 +300,6 @@ func (s *APIServer) Shutdown(halt bool) error {
}()
<-ctx.Done()
})
-
return nil
}
diff --git a/test/e2e/system_service_test.go b/test/e2e/system_service_test.go
index 684ac56b4..9a4d687c3 100644
--- a/test/e2e/system_service_test.go
+++ b/test/e2e/system_service_test.go
@@ -65,7 +65,7 @@ var _ = Describe("podman system service", func() {
pprofPort := randomPort()
session := podmanTest.Podman([]string{
- "system", "service", "--log-level=info", "--time=0",
+ "system", "service", "--log-level=debug", "--time=0",
"--pprof-address=localhost:" + pprofPort, address.String(),
})
defer session.Kill()
@@ -91,7 +91,7 @@ var _ = Describe("podman system service", func() {
Expect(body).ShouldNot(BeEmpty())
session.Interrupt().Wait(2 * time.Second)
- Eventually(session, 2).Should(Exit(1))
+ Eventually(session).Should(Exit(1))
})
It("are not available", func() {
@@ -103,7 +103,7 @@ var _ = Describe("podman system service", func() {
}
session := podmanTest.Podman([]string{
- "system", "service", "--log-level=info", "--time=0", address.String(),
+ "system", "service", "--log-level=debug", "--time=0", address.String(),
})
defer session.Kill()
@@ -113,7 +113,7 @@ var _ = Describe("podman system service", func() {
Expect(session.Err.Contents()).ShouldNot(ContainSubstring(magicComment))
session.Interrupt().Wait(2 * time.Second)
- Eventually(session, 2).Should(Exit(1))
+ Eventually(session).Should(Exit(1))
})
})
})