semaphore icon indicating copy to clipboard operation
semaphore copied to clipboard
verified publisher icon semaphoreui

No automatic reconnection to the database

Open gcavelier opened this issue 2 years ago • 3 comments

I'm using semaphore with a postgreSQL database backend. When postgreSQL is restarted, semaphore crashes.

Steps to reproduce :

  1. With postgreSQL started, restart semaphore (so that we have a fresh connection to the database)
  2. stop postgresql
  3. wait for the connection(s) to be closed (nothing should show up when executing : ss -tnp | grep 5432)
  4. start postgresql
  5. try to login in semaphore => a stack trace appears in /var/log/daemon.log

This happens in v2.7.22 and v2.8.77

Stack trace example :

2023-02-17 10:03:47.4947 semaphore[7372]: 2023/02/17 10:03:47 http: panic serving 192.168.56.1:52678: write tcp 192.168.56.102:48894->192.168.56.102:5432: write: broken pipe
2023-02-17 10:03:47.4948 semaphore[7372]: goroutine 24 [running]:
2023-02-17 10:03:47.4948 semaphore[7372]: net/http.(*conn).serve.func1(0xc0005b8000)
2023-02-17 10:03:47.4949 semaphore[7372]: #011/usr/local/go/src/net/http/server.go:1804 +0x153
2023-02-17 10:03:47.4949 semaphore[7372]: panic(0x9bc920, 0xc0004e40f0)
2023-02-17 10:03:47.4949 semaphore[7372]: #011/usr/local/go/src/runtime/panic.go:971 +0x499
2023-02-17 10:03:47.4950 semaphore[7372]: github.com/ansible-semaphore/semaphore/api.login(0x17ab2f0, 0xc0002821c0, 0xc00014ac00)
2023-02-17 10:03:47.4950 semaphore[7372]: #011/go/src/github.com/ansible-semaphore/semaphore/api/login.go:143 +0xca5
2023-02-17 10:03:47.4950 semaphore[7372]: net/http.HandlerFunc.ServeHTTP(0x171ee88, 0x17ab2f0, 0xc0002821c0, 0xc00014ac00)
2023-02-17 10:03:47.4951 semaphore[7372]: #011/usr/local/go/src/net/http/server.go:2049 +0x44
2023-02-17 10:03:47.4951 semaphore[7372]: github.com/ansible-semaphore/semaphore/api.JSONMiddleware.func1(0x17ab2f0, 0xc0002821c0, 0xc00014ac00)
2023-02-17 10:03:47.4951 semaphore[7372]: #011/go/src/github.com/ansible-semaphore/semaphore/api/router.go:25 +0x131
2023-02-17 10:03:47.4952 semaphore[7372]: net/http.HandlerFunc.ServeHTTP(0xc0000a0048, 0x17ab2f0, 0xc0002821c0, 0xc00014ac00)
2023-02-17 10:03:47.4952 semaphore[7372]: #011/usr/local/go/src/net/http/server.go:2049 +0x44
2023-02-17 10:03:47.4952 semaphore[7372]: github.com/ansible-semaphore/semaphore/cli/cmd.runService.func1.1(0x17ab2f0, 0xc0002821c0, 0xc00014ac00)
2023-02-17 10:03:47.4953 semaphore[7372]: #011/go/src/github.com/ansible-semaphore/semaphore/cli/cmd/root.go:90 +0x122
2023-02-17 10:03:47.4953 semaphore[7372]: net/http.HandlerFunc.ServeHTTP(0xc00051a480, 0x17ab2f0, 0xc0002821c0, 0xc00014ac00)
2023-02-17 10:03:47.4953 semaphore[7372]: #011/usr/local/go/src/net/http/server.go:2049 +0x44
2023-02-17 10:03:47.4954 semaphore[7372]: github.com/gorilla/mux.CORSMethodMiddleware.func1.1(0x17ab2f0, 0xc0002821c0, 0xc00014ac00)
2023-02-17 10:03:47.4954 semaphore[7372]: #011/go/src/github.com/ansible-semaphore/semaphore/vendor/github.com/gorilla/mux/middleware.go:51 +0xf7
2023-02-17 10:03:47.4954 semaphore[7372]: net/http.HandlerFunc.ServeHTTP(0xc0000d4040, 0x17ab2f0, 0xc0002821c0, 0xc00014ac00)
2023-02-17 10:03:47.4955 semaphore[7372]: #011/usr/local/go/src/net/http/server.go:2049 +0x44
2023-02-17 10:03:47.4955 semaphore[7372]: github.com/gorilla/mux.(*Router).ServeHTTP(0xc0002a0000, 0x17ab2f0, 0xc0002821c0, 0xc00014a700)
2023-02-17 10:03:47.4959 semaphore[7372]: #011/go/src/github.com/ansible-semaphore/semaphore/vendor/github.com/gorilla/mux/mux.go:212 +0xd3
2023-02-17 10:03:47.4960 semaphore[7372]: github.com/gorilla/handlers.ProxyHeaders.func1(0x17ab2f0, 0xc0002821c0, 0xc00014a700)
2023-02-17 10:03:47.4960 semaphore[7372]: #011/go/src/github.com/ansible-semaphore/semaphore/vendor/github.com/gorilla/handlers/proxy_headers.go:59 +0x114
2023-02-17 10:03:47.4960 semaphore[7372]: net/http.HandlerFunc.ServeHTTP(0xc0000a1cf8, 0x17ab2f0, 0xc0002821c0, 0xc00014a700)
2023-02-17 10:03:47.4961 semaphore[7372]: #011/usr/local/go/src/net/http/server.go:2049 +0x44
2023-02-17 10:03:47.4961 semaphore[7372]: github.com/ansible-semaphore/semaphore/cli/cmd.cropTrailingSlashMiddleware.func1(0x17ab2f0, 0xc0002821c0, 0xc00014a700)
2023-02-17 10:03:47.4962 semaphore[7372]: #011/go/src/github.com/ansible-semaphore/semaphore/cli/cmd/service.go:26 +0x97
2023-02-17 10:03:47.4962 semaphore[7372]: net/http.HandlerFunc.ServeHTTP(0xc0000a1d10, 0x17ab2f0, 0xc0002821c0, 0xc00014a700)
2023-02-17 10:03:47.4962 semaphore[7372]: #011/usr/local/go/src/net/http/server.go:2049 +0x44
2023-02-17 10:03:47.4963 semaphore[7372]: net/http.serverHandler.ServeHTTP(0xc0002822a0, 0x17ab2f0, 0xc0002821c0, 0xc00014a700)
2023-02-17 10:03:47.4963 semaphore[7372]: #011/usr/local/go/src/net/http/server.go:2867 +0xa3
2023-02-17 10:03:47.4963 semaphore[7372]: net/http.(*conn).serve(0xc0005b8000, 0x17acc40, 0xc000512000)
2023-02-17 10:03:47.4965 semaphore[7372]: #011/usr/local/go/src/net/http/server.go:1932 +0x8cd
2023-02-17 10:03:47.4966 semaphore[7372]: created by net/http.(*Server).Serve
2023-02-17 10:03:47.4966 semaphore[7372]: #011/usr/local/go/src/net/http/server.go:2993 +0x39b

gcavelier avatar Feb 17 '23 09:02 gcavelier

Also having same issue

Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: time="2023-02-17T20:10:16Z" level=error msg="write tcp y.y.y.y:54872->x.x.x.x:5432: write: broken pipe"
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: 2023/02/17 20:10:16 http: panic serving 127.0.0.1:36638: write tcp y.y.y.y:54872->x.x.x.x:5432: write: broken pipe
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: goroutine 153 [running]:
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: net/http.(*conn).serve.func1()
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/net/http/server.go:1825 +0xbf
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: panic({0x96a4c0, 0xc0005180a0})
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/runtime/panic.go:844 +0x258
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: github.com/ansible-semaphore/semaphore/api.createSession({0x1fc55d0, 0xc00056c2a0}, 0xc00056a500, {0x0, {0x0, 0x0, 0x0}, {0x0, 0x0}, {0x0, ...}, ...})
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /home/runner/work/semaphore/semaphore/api/login.go:140 +0x4a5
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: github.com/ansible-semaphore/semaphore/api.login({0x1fc55d0, 0xc00056c2a0}, 0xc0007ee2c0?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /home/runner/work/semaphore/semaphore/api/login.go:252 +0x4d8
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: net/http.HandlerFunc.ServeHTTP(0x991040?, {0x1fc55d0?, 0xc00056c2a0?}, 0xc?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/net/http/server.go:2084 +0x2f
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: github.com/ansible-semaphore/semaphore/api.JSONMiddleware.func1({0x1fc55d0, 0xc00056c2a0}, 0x17?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /home/runner/work/semaphore/semaphore/api/router.go:35 +0xf4
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: net/http.HandlerFunc.ServeHTTP(0xc0009c3640?, {0x1fc55d0?, 0xc00056c2a0?}, 0xc00002a258?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/net/http/server.go:2084 +0x2f
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: github.com/ansible-semaphore/semaphore/api.StoreMiddleware.func1.1()
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /home/runner/work/semaphore/semaphore/api/router.go:26 +0x2e
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: github.com/ansible-semaphore/semaphore/db.StoreSession({0x1fc9898, 0xc0000ae5f0}, {0xc00002a258, 0x17}, 0xc0009c3698)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /home/runner/work/semaphore/semaphore/db/Store.go:336 +0x68
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: github.com/ansible-semaphore/semaphore/api.StoreMiddleware.func1({0x1fc55d0, 0xc00056c2a0}, 0xc00056a500)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /home/runner/work/semaphore/semaphore/api/router.go:25 +0xfc
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: net/http.HandlerFunc.ServeHTTP(0xc00056a500?, {0x1fc55d0?, 0xc00056c2a0?}, 0x976f80?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/net/http/server.go:2084 +0x2f
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: github.com/ansible-semaphore/semaphore/cli/cmd.runService.func1.1({0x1fc55d0, 0xc00056c2a0}, 0xc0009c3778?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /home/runner/work/semaphore/semaphore/cli/cmd/root.go:79 +0x124
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: net/http.HandlerFunc.ServeHTTP(0x7f183e4f0a68?, {0x1fc55d0?, 0xc00056c2a0?}, 0xc0005225a0?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/net/http/server.go:2084 +0x2f
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: github.com/gorilla/mux.CORSMethodMiddleware.func1.1({0x1fc55d0, 0xc00056c2a0}, 0xc000489080?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /home/runner/work/semaphore/semaphore/vendor/github.com/gorilla/mux/middleware.go:51 +0xaa
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: net/http.HandlerFunc.ServeHTTP(0xc00056a400?, {0x1fc55d0?, 0xc00056c2a0?}, 0x9bf080?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/net/http/server.go:2084 +0x2f
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: github.com/gorilla/mux.(*Router).ServeHTTP(0xc0002ca180, {0x1fc55d0, 0xc00056c2a0}, 0xc00056a300)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /home/runner/work/semaphore/semaphore/vendor/github.com/gorilla/mux/mux.go:212 +0x202
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: github.com/gorilla/handlers.ProxyHeaders.func1({0x1fc55d0, 0xc00056c2a0}, 0xc00056a300)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /home/runner/work/semaphore/semaphore/vendor/github.com/gorilla/handlers/proxy_headers.go:59 +0x142
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: net/http.HandlerFunc.ServeHTTP(0x3b?, {0x1fc55d0?, 0xc00056c2a0?}, 0x0?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/net/http/server.go:2084 +0x2f
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: github.com/ansible-semaphore/semaphore/cli/cmd.cropTrailingSlashMiddleware.func1({0x1fc55d0?, 0xc00056c2a0?}, 0xc00056a300?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /home/runner/work/semaphore/semaphore/cli/cmd/server.go:27 +0xf7
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: net/http.HandlerFunc.ServeHTTP(0x0?, {0x1fc55d0?, 0xc00056c2a0?}, 0x40eea5?)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/net/http/server.go:2084 +0x2f
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: net/http.serverHandler.ServeHTTP({0x1fc3b68?}, {0x1fc55d0, 0xc00056c2a0}, 0xc00056a300)
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/net/http/server.go:2916 +0x43b
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: net/http.(*conn).serve(0xc0003de6e0, {0x1fc59a8, 0xc0007db6b0})
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/net/http/server.go:1966 +0x5d7
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]: created by net/http.(*Server).Serve
Feb 17 20:10:16 sa-prod-integration-sd-78 semaphore[225540]:         /opt/hostedtoolcache/go/1.18.7/x64/src/net/http/server.go:3071 +0x4db
Feb 17 20:12:29 sa-prod-integration-sd-78 semaphore[225540]: 2023/02/17 20:12:29 http: superfluous response.WriteHeader call from github.com/ansible-semaphore/semaphore/api/helpers.WriteJSON (helpers.go:67)

ghost avatar Feb 17 '23 20:02 ghost

Same issue with a mysql database

EtheveDamien avatar Apr 12 '23 11:04 EtheveDamien

Similar issue occurs overnight as a binary with a local mysql container

Apr 13 14:38:04 * semaphore[86031]: [mysql] 2023/04/13 14:38:04 connection.go:196: busy buffer Apr 13 14:38:04 * semaphore[86031]: time="2023-04-13T14:38:04Z" level=error msg="invalid connection" Apr 13 14:38:04 * semaphore[86031]: [mysql] 2023/04/13 14:38:04 connection.go:196: busy buffer Apr 13 14:38:04 * semaphore[86031]: 2023/04/13 14:38:04 http: panic serving 172.30.0.77:63462: invalid connection Apr 13 14:38:04 * semaphore[86031]: goroutine 2275 [running]:

DevlinCrooks avatar Apr 13 '23 14:04 DevlinCrooks

Hi, from what I've investigated it seems that Go's sql drivers do not handle automatic re-connection attempts. And it feels like they really don't want to implement it themselves and want to let it up to the individual developers (see here).

For now the easiest fix for semaphore would be to implement explicit crash condition when this database connection loss is noticed. Semaphore will crash and restart, but at least you'd not have to restart it manually (if using restart: always in Docker).

Caesarovich avatar Jul 22 '23 15:07 Caesarovich

I need to restart semaphore every morning or I cannot login. Binary + mysql docker container. For now a cronjob does the job, but it's a bit annoying that login sessions are never kept. I don't understand why the connection is even lost in the first place? I'm not seeing anything in the logs.

basskitty avatar Oct 09 '23 10:10 basskitty

I need to restart semaphore every morning or I cannot login. Binary + mysql docker container. For now a cronjob does the job, but it's a bit annoying that login sessions are never kept. I don't understand why the connection is even lost in the first place? I'm not seeing anything in the logs.

Same here !

fsainovich avatar Feb 27 '24 16:02 fsainovich

Until there is a better solution we "solved" it with a kubernetes probe :

apiVersion: apps/v1
kind: Deployment
[...]
    spec:
      containers:
        - env:
            - name: SEMAPHORE_API_TOKEN
              valueFrom:
                secretKeyRef:
                  key: api-token
                  name: semaphore-api-token
          image: xxx/ansible-semaphore:yyy
          livenessProbe:
            exec:
              command:
              - sh
              - -c
              - 'curl localhost:3000/api/projects -H "Authorization: Bearer $SEMAPHORE_API_TOKEN" --fail'
            initialDelaySeconds: 300
            periodSeconds: 5

When the API starts to fail, Kubernetes replaces the pod.

rgdev avatar Feb 27 '24 17:02 rgdev