"Unhealthy Readiness probe failed: Get "http://xx.xx.xx.xx:8080/ping": dial tcp xx.xx.xx.xx:8080: connect: connection refused" #bug #280

Puvendhan · 2024-04-25T16:07:20Z

I am getting the below error in the devlake-lake pod, the UI is up , but after clicking on "Proceed Database Migration" , the devlake pod is going down and giving the below error.

Pod is having this event
"Unhealthy Readiness probe failed: Get "http://xx.xx.xx.xx:8080/ping": dial tcp xx.xx.xx.xx:8080: connect: connection refused"

I am using gcp Cloudsql mysql instance and used the below arguments to enable external mysql server

mysql: useExternal: true externalServer: xxxxxxxx externalPort: 3306 username: testuser password: xxxxxx database: devlake option: autoCreateSecret: true

time="2024-04-25 15:43:38" level=info msg=" [migrator] applying migration script modify component type to varchar(500):20231007145127"
time="2024-04-25 15:43:39" level=info msg="\x1b[31;1m/app/impls/dalgorm/dalgorm.go:146 \x1b[35;1mError 1054 (42S22): Unknown column 'component' in '_tool_sonarqube_issues'\n\x1b[0m\x1b[33m[0.838ms] \x1b[34;1m[rows:0]\x1b[0m ALTER TABLE `_tool_sonarqube_issues` RENAME COLUMN `component` TO `component_FC59F7072BF9A4479E6A1AA0AFFDB630`"
fatal error: sync: unlock of unlocked mutex

goroutine 84 [running]:
sync.fatal({0x18c5963?, 0xc0001e3608?})
        /usr/local/go/src/runtime/panic.go:1031 +0x1e
sync.(*Mutex).unlockSlow(0x2c0b430, 0xffffffff)
        /usr/local/go/src/sync/mutex.go:229 +0x3c
sync.(*Mutex).Unlock(0xc0006de120?)
        /usr/local/go/src/sync/mutex.go:223 +0x29
github.com/apache/incubator-devlake/server/services.ExecuteMigration()
        /app/server/services/init.go:138 +0x2fa
github.com/apache/incubator-devlake/server/api.SetupApiServer.func1(0xc0000bf400?)
        /app/server/api/api.go:100 +0x25
github.com/gin-gonic/gin.(*Context).Next(...)
        /go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
github.com/apache/incubator-devlake/server/api.OAuth2ProxyAuthentication.func1(0xc0000bf400)
        /app/server/api/middlewares.go:95 +0x143
github.com/gin-gonic/gin.(*Context).Next(...)
        /go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
github.com/apache/incubator-devlake/server/api.RestAuthentication.func1(0xc0000bf400)
        /app/server/api/middlewares.go:117 +0x2bb
github.com/gin-gonic/gin.(*Context).Next(...)
        /go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
github.com/gin-gonic/gin.CustomRecoveryWithWriter.func1(0xc0000bf400)
        /go/pkg/mod/github.com/gin-gonic/[email protected]/recovery.go:102 +0x82
github.com/gin-gonic/gin.(*Context).Next(...)
        /go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
github.com/gin-gonic/gin.LoggerWithConfig.func1(0xc0000bf400)
        /go/pkg/mod/github.com/gin-gonic/[email protected]/logger.go:240 +0xe7
github.com/gin-gonic/gin.(*Context).Next(...)
        /go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:174
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest(0xc000605520, 0xc0000bf400)
        /go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:620 +0x66b
github.com/gin-gonic/gin.(*Engine).ServeHTTP(0xc000605520, {0x1b34640?, 0xc0006f20e0}, 0xc0006e4100)
        /go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:576 +0x1dd
net/http.serverHandler.ServeHTTP({0xc0006e0120?}, {0x1b34640, 0xc0006f20e0}, 0xc0006e4100)
        /usr/local/go/src/net/http/server.go:2936 +0x316
net/http.(*conn).serve(0xc002f3e360, {0x1b35600, 0xc002f14c90})
        /usr/local/go/src/net/http/server.go:1995 +0x612
created by net/http.(*Server).Serve
        /usr/local/go/src/net/http/server.go:3089 +0x5ed

goroutine 1 [IO wait]:
internal/poll.runtime_pollWait(0x7eaf6c986978, 0x72)
        /usr/local/go/src/runtime/netpoll.go:306 +0x89
internal/poll.(*pollDesc).wait(0xc0000b1b00?, 0x4?, 0x0)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x32
internal/poll.(*pollDesc).waitRead(...)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Accept(0xc0000b1b00)
        /usr/local/go/src/internal/poll/fd_unix.go:614 +0x2bd
net.(*netFD).accept(0xc0000b1b00)
        /usr/local/go/src/net/fd_unix.go:172 +0x35
net.(*TCPListener).accept(0xc0000173b0)
        /usr/local/go/src/net/tcpsock_posix.go:148 +0x25
net.(*TCPListener).Accept(0xc0000173b0)
        /usr/local/go/src/net/tcpsock.go:297 +0x3d
net/http.(*Server).Serve(0xc002d21ef0, {0x1b34430, 0xc0000173b0})
        /usr/local/go/src/net/http/server.go:3059 +0x385
net/http.(*Server).ListenAndServe(0xc002d21ef0)
        /usr/local/go/src/net/http/server.go:2988 +0x7d
net/http.ListenAndServe(...)
        /usr/local/go/src/net/http/server.go:3242
github.com/gin-gonic/gin.(*Engine).Run(0xc000605520, {0xc001087ee8, 0x1, 0x1})
        /go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:386 +0x20e
github.com/apache/incubator-devlake/server/api.RunApiServer(0xc000605520?)
        /app/server/api/api.go:172 +0xdb
github.com/apache/incubator-devlake/server/api.CreateAndRunApiServer()
        /app/server/api/api.go:73 +0x67
main.main()
        /app/server/main.go:33 +0x36

goroutine 8 [chan receive]:
github.com/panjf2000/ants/v2.(*Pool).purgePeriodically(0xc0001f8620)
        /go/pkg/mod/github.com/panjf2000/ants/[email protected]/pool.go:69 +0x8b
created by github.com/panjf2000/ants/v2.NewPool
        /go/pkg/mod/github.com/panjf2000/ants/[email protected]/pool.go:137 +0x365

goroutine 9 [select, 1 minutes]:
database/sql.(*DB).connectionOpener(0xc0001a11e0, {0x1b35558, 0xc0004e47d0})
        /usr/local/go/src/database/sql/sql.go:1218 +0x8d
created by database/sql.OpenDB
        /usr/local/go/src/database/sql/sql.go:791 +0x18d

goroutine 35 [select, 1 minutes]:
github.com/go-sql-driver/mysql.(*mysqlConn).startWatcher.func1()
        /go/pkg/mod/github.com/go-sql-driver/[email protected]/connection.go:614 +0xaa
created by github.com/go-sql-driver/mysql.(*mysqlConn).startWatcher
        /go/pkg/mod/github.com/go-sql-driver/[email protected]/connection.go:611 +0x10a

goroutine 10 [select, 1 minutes]:
database/sql.(*DB).connectionCleaner(0xc0001a11e0, 0x0?)
        /usr/local/go/src/database/sql/sql.go:1061 +0xa7
created by database/sql.(*DB).startCleanerLocked
        /usr/local/go/src/database/sql/sql.go:1048 +0x105

goroutine 11 [chan receive, 1 minutes]:
database/sql.(*Tx).awaitDone(0xc0004f1d80)
        /usr/local/go/src/database/sql/sql.go:2167 +0x31
created by database/sql.(*DB).beginDC
        /usr/local/go/src/database/sql/sql.go:1887 +0x23b

goroutine 67 [IO wait]:
internal/poll.runtime_pollWait(0x7eaf6c986d38, 0x72)
        /usr/local/go/src/runtime/netpoll.go:306 +0x89
internal/poll.(*pollDesc).wait(0xc0000b1f80?, 0xc0006e0131?, 0x0)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x32
internal/poll.(*pollDesc).waitRead(...)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc0000b1f80, {0xc0006e0131, 0x1, 0x1})
        /usr/local/go/src/internal/poll/fd_unix.go:167 +0x299
net.(*netFD).Read(0xc0000b1f80, {0xc0006e0131?, 0x173c920?, 0xc00060cf48?})
        /usr/local/go/src/net/fd_posix.go:55 +0x29
net.(*conn).Read(0xc002f1a0e8, {0xc0006e0131?, 0xc002f11590?, 0xc00009aff0?})
        /usr/local/go/src/net/net.go:183 +0x45
net/http.(*connReader).backgroundRead(0xc0006e0120)
        /usr/local/go/src/net/http/server.go:674 +0x3f
created by net/http.(*connReader).startBackgroundRead
        /usr/local/go/src/net/http/server.go:670 +0xca

goroutine 13 [select, 1 minutes]:
github.com/go-sql-driver/mysql.(*mysqlConn).startWatcher.func1()
        /go/pkg/mod/github.com/go-sql-driver/[email protected]/connection.go:614 +0xaa
created by github.com/go-sql-driver/mysql.(*mysqlConn).startWatcher
        /go/pkg/mod/github.com/go-sql-driver/[email protected]/connection.go:611 +0x10a

The text was updated successfully, but these errors were encountered:

d4x1 · 2024-04-26T01:36:31Z

@Puvendhan what's the version you are using?

Puvendhan · 2024-04-26T04:02:17Z

Here's the version 1.0.0-beta5

Puvendhan · 2024-04-29T04:30:43Z

Hi, Any update on this?

klesh · 2024-05-06T04:06:25Z

Seems like a compatibility problem of the gcp Cloudsql mysql, try using mysql or mariadb instead.

hayk96 · 2024-07-12T09:11:45Z

Hello I'm experiencing this issue as well, starting from 1.0.0-beta3.
Database: MySQL (bitnami), Version: 8.0.37

d4x1 · 2024-07-12T09:17:36Z

@hayk96 You can try the latest version.

hayk96 · 2024-07-12T10:42:17Z

Thanks for your response @d4x1 I've just tried the latest version: 1.0.0 and the same issue there

hayk96 · 2024-07-12T10:50:10Z

I've tried the 1.0.1-beta1 version as well. Here the error looks like different

time="2024-07-12 10:46:53" level=error msg="failed to execute migration\n\tcaused by: Error 1406 (22001): Data too long for column 'file_path' at row 3191 (500)\n\tWraps: (2) Error 1406 (22001): Data too long for column 'file_path' at row 3191\n\tError types: (1) *hintdetail.withDetail (2) *mysql.MySQLError"

d4x1 · 2024-07-15T09:44:21Z

@hayk96 Please paste more logs so we can find which migration script failed with this error message.
And meanwhile you can check the field's length in your database(I am not sure which table, maybe cq_file_metrics or commits or commit_files or others).

hayk96 · 2024-07-15T11:28:08Z

sure, in that time the pod was printing the following logs:

database is ready
time="2024-07-12T10:45:12Z" level=info msg="no [.env] file, devlake will read configuration from environment, please make sure you have set correct environment variable."
Version:  v1.0.1-beta1@4cdd754
[GIN-debug] [WARNING] Creating an Engine instance with the Logger and Recovery middleware already attached.
[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:	export GIN_MODE=release
 - using code:	gin.SetMode(gin.ReleaseMode)
[GIN-debug] GET    /ping                     --> github.com/apache/incubator-devlake/server/api/ping.Get (4 handlers)
[GIN-debug] GET    /ready                    --> github.com/apache/incubator-devlake/server/api/ping.Ready (4 handlers)
[GIN-debug] GET    /health                   --> github.com/apache/incubator-devlake/server/api/ping.Health (4 handlers)
[GIN-debug] GET    /version                  --> github.com/apache/incubator-devlake/server/api/version.Get (4 handlers)
[GIN-debug] GET    /proceed-db-migration     --> github.com/apache/incubator-devlake/server/api.SetupApiServer.func1 (6 handlers)
[GIN-debug] GET    /swagger/*any             --> github.com/swaggo/gin-swagger.CustomWrapHandler.func1 (8 handlers)
[GIN-debug] GET    /plugins/swagger/azuredevops/*any --> github.com/swaggo/gin-swagger.CustomWrapHandler.func1 (7 handlers)
[GIN-debug] [WARNING] You trusted all proxies, this is NOT safe. We recommend you to set a value.
Please check https://pkg.go.dev/github.com/gin-gonic/gin#readme-don-t-trust-all-proxies for details.
[GIN-debug] Listening and serving HTTP on :8080
[GIN] 2024/07/12 - 10:46:28 | 200 |       7.447µs |   172.25.41.121 | GET      "/ping"
time="2024-07-12 10:46:31" level=error msg="HTTP 428 error\n\tcaused by: \n\tNew migration scripts detected. Database migration is required to launch DevLake.\n\tWARNING: Performing migration may wipe collected data for consistency and re-collecting data may be required.\n\tTo proceed, please send a request to <config-ui-endpoint>/api/proceed-db-migration (or <devlake-endpoint>/proceed-db-migration).\n\tAlternatively, you may downgrade back to the previous DevLake version.\n\t (428)"
[GIN] 2024/07/12 - 10:46:31 | 428 |     863.029µs |      10.42.39.0 | GET      "/store/onboard"
[GIN] 2024/07/12 - 10:46:33 | 200 |       3.447µs |   172.25.41.121 | GET      "/ping"
[GIN] 2024/07/12 - 10:46:33 | 200 |         719ns |   172.25.41.121 | GET      "/ping"
[GIN] 2024/07/12 - 10:46:38 | 200 |       3.379µs |   172.25.41.121 | GET      "/ping"
[GIN] 2024/07/12 - 10:46:53 | 200 |       2.073µs |   172.25.41.121 | GET      "/ping"
time="2024-07-12 10:46:53" level=error msg="failed to execute migration\n\tcaused by: Error 1406 (22001): Data too long for column 'file_path' at row 3191 (500)\n\tWraps: (2) Error 1406 (22001): Data too long for column 'file_path' at row 3191\n\tError types: (1) *hintdetail.withDetail (2) *mysql.MySQLError"
time="2024-07-12 10:46:53" level=error msg="HTTP 500 error\n\tcaused by: error executing migration (500)\n\tWraps: (2) Error 1406 (22001): Data too long for column 'file_path' at row 3191 (500)\n\tWraps: (3) Error 1406 (22001): Data too long for column 'file_path' at row 3191\n\tError types: (1) *hintdetail.withDetail (2) *hintdetail.withDetail (3) *mysql.MySQLError"
[GIN] 2024/07/12 - 10:46:53 | 500 |  280.721364ms |      10.42.39.0 | GET      "/proceed-db-migration"
[GIN] 2024/07/12 - 10:46:58 | 200 |       3.538µs |   172.25.41.121 | GET      "/ping"
[GIN] 2024/07/12 - 10:46:58 | 200 |       1.111µs |   172.25.41.121 | GET      "/ping"
time="2024-07-12 10:47:00" level=error msg="HTTP 400 error\n\tcaused by: error executing migration (400)\n\tWraps: (2) already migrating (400)\n\tError types: (1) *hintdetail.withDetail (2) *errors.errorString"
[GIN] 2024/07/12 - 10:47:00 | 400 |     302.657µs |      10.42.38.0 | GET      "/proceed-db-migration"
[GIN] 2024/07/12 - 10:47:03 | 200 |       5.526µs |   172.25.41.121 | GET      "/ping"

d4x1 · 2024-07-16T13:04:14Z

@hayk96 I've tried v1.0.1-beta1 with am empty database, there is no error.
Is your devlake upgraded from an old version?
If yes, check your database's data in column file_path. It seems the actual data length is bigger than expected column length.

hayk96 · 2024-07-16T13:08:42Z

yes, all DevLeke versions work fine with an empty database. These errors have been raised during upgrades. Will check.

hayk96 · 2024-07-16T13:35:04Z

tables that have file_path column

mysql> SELECT DISTINCT TABLE_NAME
    ->     FROM INFORMATION_SCHEMA.COLUMNS
    ->     WHERE COLUMN_NAME IN ('file_path')
    ->         AND TABLE_SCHEMA='lake';
+------------------------------+
| TABLE_NAME                   |
+------------------------------+
| _tool_sonarqube_file_metrics |
| commit_files                 |
| cq_file_metrics              |
| repo_snapshot                |
+------------------------------+
4 rows in set (0.01 sec)

length of the columns

mysql> SELECT CHARACTER_MAXIMUM_LENGTH FROM information_schema.COLUMNS WHERE TABLE_SCHEMA = 'lake' AND TABLE_NAME = '_tool_sonarqube_file_metrics' AND COLUMN_NAME = 'file_path';
+--------------------------+
| CHARACTER_MAXIMUM_LENGTH |
+--------------------------+
|               4294967295 |
+--------------------------+
1 row in set (0.00 sec)

mysql> SELECT CHARACTER_MAXIMUM_LENGTH FROM information_schema.COLUMNS WHERE TABLE_SCHEMA = 'lake' AND TABLE_NAME = 'commit_files' AND COLUMN_NAME = 'file_path';
+--------------------------+
| CHARACTER_MAXIMUM_LENGTH |
+--------------------------+
|                     1024 |
+--------------------------+
1 row in set (0.01 sec)

mysql> SELECT CHARACTER_MAXIMUM_LENGTH FROM information_schema.COLUMNS WHERE TABLE_SCHEMA = 'lake' AND TABLE_NAME = 'cq_file_metrics' AND COLUMN_NAME = 'file_path';
+--------------------------+
| CHARACTER_MAXIMUM_LENGTH |
+--------------------------+
|               4294967295 |
+--------------------------+
1 row in set (0.00 sec)

mysql> SELECT CHARACTER_MAXIMUM_LENGTH FROM information_schema.COLUMNS WHERE TABLE_SCHEMA = 'lake' AND TABLE_NAME = 'repo_snapshot' AND COLUMN_NAME = 'file_path';
+--------------------------+
| CHARACTER_MAXIMUM_LENGTH |
+--------------------------+
|                      255 |
+--------------------------+
1 row in set (0.00 sec)

d4x1 · 2024-07-17T06:00:20Z

@hayk96 I cannot find which scipr fialed from you logs. You can change the log level and if something went wrong, we can find the script id from this line: https://github.com/apache/incubator-devlake/blob/main/backend/core/migration/migrator.go#L99

hayk96 · 2024-07-18T14:08:00Z

I have deleted the entire stack, so can not reproduce it.

Startrekzky assigned ZhangNing10 Apr 30, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

"Unhealthy Readiness probe failed: Get "http://xx.xx.xx.xx:8080/ping": dial tcp xx.xx.xx.xx:8080: connect: connection refused" #bug #280

"Unhealthy Readiness probe failed: Get "http://xx.xx.xx.xx:8080/ping": dial tcp xx.xx.xx.xx:8080: connect: connection refused" #bug #280

Puvendhan commented Apr 25, 2024 •

edited

Loading

d4x1 commented Apr 26, 2024

Puvendhan commented Apr 26, 2024

Puvendhan commented Apr 29, 2024

klesh commented May 6, 2024

hayk96 commented Jul 12, 2024

d4x1 commented Jul 12, 2024

hayk96 commented Jul 12, 2024

hayk96 commented Jul 12, 2024

d4x1 commented Jul 15, 2024 •

edited

Loading

hayk96 commented Jul 15, 2024 •

edited

Loading

d4x1 commented Jul 16, 2024

hayk96 commented Jul 16, 2024

hayk96 commented Jul 16, 2024

d4x1 commented Jul 17, 2024

hayk96 commented Jul 18, 2024

"Unhealthy Readiness probe failed: Get "http://xx.xx.xx.xx:8080/ping": dial tcp xx.xx.xx.xx:8080: connect: connection refused" #bug #280

"Unhealthy Readiness probe failed: Get "http://xx.xx.xx.xx:8080/ping": dial tcp xx.xx.xx.xx:8080: connect: connection refused" #bug #280

Comments

Puvendhan commented Apr 25, 2024 • edited Loading

d4x1 commented Apr 26, 2024

Puvendhan commented Apr 26, 2024

Puvendhan commented Apr 29, 2024

klesh commented May 6, 2024

hayk96 commented Jul 12, 2024

d4x1 commented Jul 12, 2024

hayk96 commented Jul 12, 2024

hayk96 commented Jul 12, 2024

d4x1 commented Jul 15, 2024 • edited Loading

hayk96 commented Jul 15, 2024 • edited Loading

d4x1 commented Jul 16, 2024

hayk96 commented Jul 16, 2024

hayk96 commented Jul 16, 2024

d4x1 commented Jul 17, 2024

hayk96 commented Jul 18, 2024

Puvendhan commented Apr 25, 2024 •

edited

Loading

d4x1 commented Jul 15, 2024 •

edited

Loading

hayk96 commented Jul 15, 2024 •

edited

Loading