oobmigrations: Insiders version not parsed properly

efritz commented 1 year ago

When booting an insiders single-server image, we see the following log message, followed by a stream of errors indicating that the tables lsif_data_{whatever} cannot be found.

These tables were recently removed, and the out-of-band migration that writes to them should be disabled since 4.5. It seems that on insiders builds that we are not parsing the version string that we bake into the binary properly:

Invalid Semantic Version","version":"205081_2023-03-09_4.5-7d653173d315"

Some initial hints:

For non-dev environments we do seem to attempt to parse this format, but this might not actually be extracting the correct format string (we should be parsing 4.5 as the version in the example above). Solution could be as easy for writing a failing test case for this function and fixing the parsing logic.

jasonhawkharris commented 1 year ago

relevant PR > https://github.com/sourcegraph/sourcegraph/pull/48623

jasonhawkharris commented 1 year ago

I believe the error in question is coming from semver by way of this function.

There is a comment above this line that further piques my curiosity. @daxmc99 I see you wrote this comment. Do you have any insight you could provide that might lead me toward a solution?

jasonhawkharris commented 1 year ago

additional slack context: https://sourcegraph.slack.com/archives/CHXHX7XAS/p1678355159483899

jasonhawkharris commented 1 year ago

Full log:

φ docker run -it --publish 7080:7080 --rm sourcegraph/server:insiders
WARNING: The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
✱ Sourcegraph is initializing the internal database... (may take 15-20 seconds)
✱ Finished initializing the internal database.
Starting postgres processes
Starting migrator
13:28:51 postgres | 2023-03-09 13:28:51.635 UTC [119] LOG:  starting PostgreSQL 12.10 on x86_64-alpine-linux-musl, compiled by gcc (Alpine 9.3.0) 9.3.0, 64-bit
✱ Sourcegraph migrator 205081_2023-03-09_4.5-7d653173d315
✅ Schema(s) are up-to-date!
✱ Sourcegraph migrator 205081_2023-03-09_4.5-7d653173d315
✅ Schema(s) are up-to-date!
Migrated postgres schemas.
Starting all processes
13:29:00                     nginx | 2023/03/09 13:29:00 [emerg] 367#367: io_setup() failed (38: Function not implemented)
13:29:00        syntax_highlighter | Configured for release.
13:29:01         zoekt-indexserver | {"SeverityText":"WARN","Timestamp":1678368541121541626,"InstrumentationScope":"metricsRegistration.mountPointInfo.deviceNameDiscovery","Caller":"mountinfo@v0.0.0-20230106004439-7026e28cef67/info.go:48","Function":"github.com/sourcegraph/mountinfo.NewCollector","Body":"skipping metric registration","Resource":{"service.name":"zoekt-indexserver","service.instance.id":"127.0.0.1:3070"},"Attributes":{"mountName":"indexDir","mountFilePath":"/var/opt/sourcegraph/zoekt/index","reason":"failed to discover device name","error":"discovering device path: discoverSysfsDevicePath: failed to evaluate sysfs symlink \"/sys/dev/block/0:170\": lstat /sys/dev/block/0:170: no such file or directory"}}
13:29:01           zoekt-webserver | {"SeverityText":"WARN","Timestamp":1678368541525231334,"InstrumentationScope":"metricsRegistration.mountPointInfo.deviceNameDiscovery","Caller":"mountinfo@v0.0.0-20230106004439-7026e28cef67/info.go:48","Function":"github.com/sourcegraph/mountinfo.NewCollector","Body":"skipping metric registration","Resource":{"service.name":"zoekt-webserver","service.instance.id":"94c00ca6b18f"},"Attributes":{"mountName":"indexDir","mountFilePath":"/var/opt/sourcegraph/zoekt/index","reason":"failed to discover device name","error":"discovering device path: discoverSysfsDevicePath: failed to evaluate sysfs symlink \"/sys/dev/block/0:170\": lstat /sys/dev/block/0:170: no such file or directory"}}
13:29:04                  frontend | {"SeverityText":"WARN","Timestamp":1678368544442310877,"InstrumentationScope":"frontend.oobmigration","Caller":"oobmigration/validate.go:28","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.ValidateOutOfBandMigrationRunner","Body":"Skipping out-of-band migrations check","Resource":{"service.name":"frontend","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"Invalid Semantic Version","version":"205081_2023-03-09_4.5-7d653173d315"}}
13:29:05                  frontend |                    ╓╦╬╬╬╦╖
13:29:05                  frontend |                   ╬╬╬╬╬╬╬╬╬
13:29:05                  frontend |                  ╞╬╬╬╬╬╬╬╬╬╬           ╓╦╦╦╦┐
13:29:05                  frontend |                   ╬╬╬╬╬╬╬╬╬╬╕        ╔╪╪╪╪╪╪╪╪╕
13:29:05                  frontend |                   ╘╬╬╬╬╬╬╬╬╬╬      ╔╪╪╪╪╪╪╪╪╪╪╪
13:29:05                  frontend |                    ╬╬╬╬╬╬╬╬╬╬╗   ╔╪╪╪╪╪╪╪╪╪╪╪╪┘
13:29:05                  frontend |       ╓╦╦╖┐         ╬╬╬╬╬╬╬╬╬╬ ╔╝╪╪╪╪╪╪╪╪╪╪╪╜
13:29:05                  frontend |     ╬╪╪╪╪╪╪╪╪╬╗╦╖   ╠╬╬╬╬╬╬╬╬╝╪╪╪╪╪╪╪╪╪╪╪╪╜
13:29:05                  frontend |    ╠╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╝╝╬╬╬╬╝╪╪╪╪╪╪╪╪╪╪╪╪╜
13:29:05                  frontend |    └╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╩
13:29:05                  frontend |      ╙╩╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╖
13:29:05                  frontend |           └╙╩╬╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╬╦╗┐
13:29:05                  frontend |                  ╙╜╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╗╦╖
13:29:05                  frontend |                  ┌╬╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╬
13:29:05                  frontend |                ┌╗╪╪╪╪╪╪╪╪╪╪╪╪╬╬╬╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪╪
13:29:05                  frontend |              ┌╗╪╪╪╪╪╪╪╪╪╪╪╪╬╬╬╬╬╬╬╬╬ ╙╜╩╪╪╪╪╪╪╪╪╪╪╪╪╜
13:29:05                  frontend |            ┌╦╪╪╪╪╪╪╪╪╪╪╪╝╙╬╬╬╬╬╬╬╬╬╬       └╙╩╬╪╪╝╜
13:29:05                  frontend |           ╦╪╪╪╪╪╪╪╪╪╪╪╪┘  ╠╬╬╬╬╬╬╬╬╬╬
13:29:05                  frontend |          ╬╪╪╪╪╪╪╪╪╪╪╪┘     ╬╬╬╬╬╬╬╬╬╬┐
13:29:05                  frontend |          ╙╪╪╪╪╪╪╪╪╪╜       ╘╬╬╬╬╬╬╬╬╬╬
13:29:05                  frontend |           └╩╪╪╪╪╝╙          ╬╬╬╬╬╬╬╬╬╬╕
13:29:05                  frontend |                             └╬╬╬╬╬╬╬╬╬╛
13:29:05                  frontend |                               ╩╬╬╬╬╬╬┘
13:29:06                  searcher | {"SeverityText":"WARN","Timestamp":1678368546112996003,"InstrumentationScope":"Store.mountPointInfo.deviceNameDiscovery","Caller":"mountinfo@v0.0.0-20230106004439-7026e28cef67/info.go:48","Function":"github.com/sourcegraph/mountinfo.NewCollector","Body":"skipping metric registration","Resource":{"service.name":"searcher","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"mountName":"cacheDir","mountFilePath":"/var/opt/sourcegraph/cache/searcher-archives","reason":"failed to discover device name","error":"discovering device path: discoverSysfsDevicePath: failed to evaluate sysfs symlink \"/sys/dev/block/0:170\": lstat /sys/dev/block/0:170: no such file or directory"}}
13:29:06                    worker | {"SeverityText":"WARN","Timestamp":1678368546412030753,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/validate.go:28","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.ValidateOutOfBandMigrationRunner","Body":"Skipping out-of-band migrations check","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"Invalid Semantic Version","version":"205081_2023-03-09_4.5-7d653173d315"}}
13:29:06                 gitserver | {"SeverityText":"WARN","Timestamp":1678368546676965087,"InstrumentationScope":"gitserver.mountPointInfo.deviceNameDiscovery","Caller":"mountinfo@v0.0.0-20230106004439-7026e28cef67/info.go:48","Function":"github.com/sourcegraph/mountinfo.NewCollector","Body":"skipping metric registration","Resource":{"service.name":"gitserver","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"127.0.0.1:3178"},"Attributes":{"mountName":"reposDir","mountFilePath":"/var/opt/sourcegraph/repos","reason":"failed to discover device name","error":"discovering device path: discoverSysfsDevicePath: failed to evaluate sysfs symlink \"/sys/dev/block/0:170\": lstat /sys/dev/block/0:170: no such file or directory"}}
13:29:07                    worker | {"SeverityText":"ERROR","Timestamp":1678368547744535171,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:358","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrator","Body":"Failed to determine migration progress","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:07                    worker | {"SeverityText":"ERROR","Timestamp":1678368547750946921,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration.up","Caller":"oobmigration/runner.go:444","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationUp","Body":"operation.error","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"migrationID":20,"count":1,"elapsed":0.00346875,"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)"}}
13:29:07                    worker | {"SeverityText":"ERROR","Timestamp":1678368547752780879,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:406","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationFunction","Body":"Failed to perform migration","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:07                    worker | {"SeverityText":"ERROR","Timestamp":1678368547953508421,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:383","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrator","Body":"Failed migration action","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:08                    worker | {"SeverityText":"ERROR","Timestamp":1678368548413748838,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration.up","Caller":"oobmigration/runner.go:444","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationUp","Body":"operation.error","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"migrationID":20,"count":1,"elapsed":0.001619708,"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)"}}
13:29:08                    worker | {"SeverityText":"ERROR","Timestamp":1678368548414304463,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:406","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationFunction","Body":"Failed to perform migration","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:08                    worker | {"SeverityText":"ERROR","Timestamp":1678368548442654713,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:383","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrator","Body":"Failed migration action","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:09                    worker | {"SeverityText":"ERROR","Timestamp":1678368549361119005,"InstrumentationScope":"codeintel.upload-store-expirer","Caller":"goroutine/periodic.go:87","Function":"github.com/sourcegraph/sourcegraph/internal/goroutine.(*simpleHandler).HandleError","Body":"An error occurred in a background task","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"handler":"codeintel.upload-store-expirer","error":"failed to create bucket: operation error S3: CreateBucket, exceeded maximum number of attempts, 3, https response error StatusCode: 0, RequestID: , HostID: , request send failed, Put \"http://127.0.0.1:9000/lsif-uploads\": dial tcp 127.0.0.1:9000: connect: connection refused"}}
13:29:09                    worker | {"SeverityText":"ERROR","Timestamp":1678368549414786463,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration.up","Caller":"oobmigration/runner.go:444","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationUp","Body":"operation.error","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"migrationID":20,"count":1,"elapsed":0.001868833,"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)"}}
13:29:09                    worker | {"SeverityText":"ERROR","Timestamp":1678368549415447671,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:406","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationFunction","Body":"Failed to perform migration","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:09                    worker | {"SeverityText":"ERROR","Timestamp":1678368549439305255,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:383","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrator","Body":"Failed migration action","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:10                    worker | {"SeverityText":"ERROR","Timestamp":1678368550414221880,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration.up","Caller":"oobmigration/runner.go:444","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationUp","Body":"operation.error","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"migrationID":20,"count":1,"elapsed":0.001616541,"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)"}}
13:29:10                    worker | {"SeverityText":"ERROR","Timestamp":1678368550414798089,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:406","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationFunction","Body":"Failed to perform migration","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:10                    worker | {"SeverityText":"ERROR","Timestamp":1678368550422544714,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:383","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrator","Body":"Failed migration action","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:10                  postgres | 2023-03-09 13:28:51.638 UTC [119] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
13:29:10                  postgres | 2023-03-09 13:28:51.639 UTC [119] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
13:29:10                  postgres | 2023-03-09 13:28:53.227 UTC [166] ERROR:  relation "schema_migrations" does not exist at character 165
13:29:10                  postgres | 2023-03-09 13:28:53.227 UTC [166] STATEMENT:  -- query hash: 3367603814
13:29:10                  postgres |    -- query length: 64 (0 args)
13:29:10                  postgres |    -- caller: cmd/migrator/shared.Start
13:29:10                  postgres |    -- source: cmd/migrator/shared/main.go:98
13:29:10                  postgres |
13:29:10                  postgres |    SELECT version::integer FROM schema_migrations WHERE NOT dirty
13:29:10                  postgres |
13:29:10                  postgres | 2023-03-09 13:28:53.230 UTC [166] ERROR:  relation "versions" does not exist at character 201
13:29:10                  postgres | 2023-03-09 13:28:53.230 UTC [166] STATEMENT:  -- query hash: 2242856392
13:29:10                  postgres |    -- query length: 49 (1 args)
13:29:10                  postgres |    -- caller: internal/version/upgradestore.(*store).updateServiceVersion
13:29:10                  postgres |    -- source: internal/version/upgradestore/store.go:72
13:29:10                  postgres |
13:29:10                  postgres |    SELECT version FROM versions WHERE service = $1
13:29:10                  postgres |
13:29:10                  postgres | 2023-03-09 13:28:59.089 UTC [184] ERROR:  relation "codeintel_schema_migrations" does not exist at character 165
13:29:11                    worker | {"SeverityText":"ERROR","Timestamp":1678368551413817047,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration.up","Caller":"oobmigration/runner.go:444","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationUp","Body":"operation.error","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"migrationID":20,"count":1,"elapsed":0.001687666,"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)"}}
13:29:11                    worker | {"SeverityText":"ERROR","Timestamp":1678368551414318964,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:406","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationFunction","Body":"Failed to perform migration","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:11                    worker | {"SeverityText":"ERROR","Timestamp":1678368551421687339,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:383","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrator","Body":"Failed migration action","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:11                  postgres | 2023-03-09 13:28:59.089 UTC [184] STATEMENT:  -- query hash: 2284389962
13:29:11                  postgres |    -- query length: 74 (0 args)
13:29:11                  postgres |    -- caller: cmd/migrator/shared.Start
13:29:11                  postgres |    -- source: cmd/migrator/shared/main.go:98
13:29:11                  postgres |
13:29:11                  postgres |    SELECT version::integer FROM codeintel_schema_migrations WHERE NOT dirty
13:29:11                  postgres |
13:29:11                  postgres | 2023-03-09 13:29:07.742 UTC [613] ERROR:  relation "lsif_data_metadata" does not exist at character 449
13:29:11                  postgres | 2023-03-09 13:29:07.742 UTC [613] STATEMENT:  -- query hash: 1562615925
13:29:11                  postgres |    -- query length: 240 (0 args)
13:29:11                  postgres |    -- caller: enterprise/internal/oobmigration/migrations/codeintel.(*scipMigrator).Progress
13:29:11                  postgres |    -- source: enterprise/internal/oobmigration/migrations/codeintel/scip_migrator.go:56
13:29:11                  postgres |
13:29:11                  postgres |    SELECT CASE c1.count + c2.count WHEN 0 THEN 1 ELSE cast(c1.count as float) / cast((c1.count + c2.count) as float) END FROM
13:29:11                  postgres |            (SELECT COUNT(*) as count FROM codeintel_scip_metadata) c1,
13:29:11                  postgres |            (SELECT COUNT(*) as count FROM lsif_data_metadata) c2
13:29:11                  postgres |
13:29:11                  postgres | 2023-03-09 13:29:07.749 UTC [613] ERROR:  relation "lsif_data_metadata" does not exist at character 252
13:29:11                  postgres | 2023-03-09 13:29:07.749 UTC [613] STATEMENT:  -- query hash: 654664450
13:29:12                    worker | {"SeverityText":"ERROR","Timestamp":1678368552425458006,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration.up","Caller":"oobmigration/runner.go:444","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationUp","Body":"operation.error","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"migrationID":20,"count":1,"elapsed":0.008200667,"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)"}}
13:29:12                    worker | {"SeverityText":"ERROR","Timestamp":1678368552427143215,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:406","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrationFunction","Body":"Failed to perform migration","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:12                    worker | {"SeverityText":"ERROR","Timestamp":1678368552444162631,"InstrumentationScope":"worker.out-of-band-migrations.oobmigration","Caller":"oobmigration/runner.go:383","Function":"github.com/sourcegraph/sourcegraph/internal/oobmigration.runMigrator","Body":"Failed migration action","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"ERROR: relation \"lsif_data_metadata\" does not exist (SQLSTATE 42P01)","migrationID":20}}
13:29:12                  postgres |    -- query length: 88 (0 args)
13:29:12                  postgres |    -- caller: enterprise/internal/oobmigration/migrations/codeintel.(*scipMigrator).upSingle
13:29:12                  postgres |    -- source: enterprise/internal/oobmigration/migrations/codeintel/scip_migrator.go:124
13:29:12                  postgres |
13:29:12                  postgres |    SELECT dump_id
13:29:12                  postgres |    FROM lsif_data_metadata
13:29:12                  postgres |    ORDER BY dump_id
13:29:12                  postgres |    FOR UPDATE SKIP LOCKED
13:29:12                  postgres |    LIMIT 1
13:29:12                  postgres |
13:29:12                  postgres | 2023-03-09 13:29:07.953 UTC [613] ERROR:  relation "lsif_data_metadata" does not exist at character 449
13:29:12                  postgres | 2023-03-09 13:29:07.953 UTC [613] STATEMENT:  -- query hash: 1562615925
13:29:12                  postgres |    -- query length: 240 (0 args)
13:29:12                  postgres |    -- caller: enterprise/internal/oobmigration/migrations/codeintel.(*scipMigrator).Progress
13:29:12                  postgres |    -- source: enterprise/internal/oobmigration/migrations/codeintel/scip_migrator.go:56
13:29:12                  postgres |
13:29:12                  postgres |    SELECT CASE c1.count + c2.count WHEN 0 THEN 1 ELSE cast(c1.count as float) / cast((c1.count + c2.count) as float) END FROM
13:29:12                  postgres |            (SELECT COUNT(*) as count FROM codeintel_scip_metadata) c1,
13:29:12                  postgres |            (SELECT COUNT(*) as count FROM lsif_data_metadata) c2
13:29:12                  postgres |
13:29:12                  postgres | 2023-03-09 13:29:08.413 UTC [613] ERROR:  relation "lsif_data_metadata" does not exist at character 252
^C13:29:13                    worker | {"SeverityText":"ERROR","Timestamp":1678368553098553923,"InstrumentationScope":"codeintel.ranking.store.codeintel.ranking.store.VacuumStaleGraphs","Caller":"store/ranking.go:497","Function":"github.com/sourcegraph/sourcegraph/enterprise/internal/codeintel/ranking/internal/store.(*store).VacuumStaleGraphs","Body":"operation.error","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"count":1,"elapsed":0.012641125,"error":"timeout: context canceled"}}
13:29:13        syntax_highlighter | thread 'rocket-worker-thread' panicked at 'failed printing to stdout: Broken pipe (os error 32)', library/std/src/io/stdio.rs:1016:9
13:29:13        syntax_highlighter | note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
13:29:13               redis-store | Terminating redis-store
13:29:13         postgres_exporter | Terminating postgres_exporter
13:29:13              github-proxy | Terminating github-proxy
13:29:13                     nginx | Terminating nginx
13:29:13                prometheus | Terminating prometheus
13:29:13         zoekt-indexserver | Terminating zoekt-indexserver
13:29:13           zoekt-webserver | Terminating zoekt-webserver
13:29:13                    worker | t=2023-03-09T13:29:13+0000 lvl=warn msg="failed to execute redis command" cmd=SETEX error="read tcp 127.0.0.1:54590->127.0.0.1:6380: read: connection reset by peer"
13:29:13                    worker | t=2023-03-09T13:29:13+0000 lvl=warn msg="failed to execute redis command" cmd=SETEX error=EOF
13:29:13               redis-cache | Terminating redis-cache
13:29:13                    worker | {"SeverityText":"ERROR","Timestamp":1678368553203034382,"InstrumentationScope":"worker","Caller":"recorder/recorder.go:138","Function":"github.com/sourcegraph/sourcegraph/internal/goroutine/recorder.(*Recorder).LogRun","Body":"failed to save run","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"save run: failed to execute redis command LTRIM: dial tcp 127.0.0.1:6380: connect: connection refused"}}
13:29:13                    worker | t=2023-03-09T13:29:13+0000 lvl=warn msg="failed to execute redis command" cmd=GET error="dial tcp 127.0.0.1:6380: connect: connection refused"
13:29:13                    worker | t=2023-03-09T13:29:13+0000 lvl=warn msg="failed to execute redis command" cmd=SETEX error="dial tcp 127.0.0.1:6380: connect: connection refused"
13:29:13                    worker | {"SeverityText":"ERROR","Timestamp":1678368553206156632,"InstrumentationScope":"worker","Caller":"recorder/recorder.go:92","Function":"github.com/sourcegraph/sourcegraph/internal/goroutine/recorder.(*Recorder).saveKnownHostName","Body":"failed to save/update known host name","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"dial tcp 127.0.0.1:6380: connect: connection refused","hostName":"worker"}}
13:29:13                    worker | {"SeverityText":"ERROR","Timestamp":1678368553206769048,"InstrumentationScope":"worker","Caller":"recorder/recorder.go:84","Function":"github.com/sourcegraph/sourcegraph/internal/goroutine/recorder.(*Recorder).saveKnownJobName","Body":"failed to save/update known job name","Resource":{"service.name":"worker","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"error":"dial tcp 127.0.0.1:6380: connect: connection refused","jobName":"codeintel-ranking-file-reference-counter"}}
13:29:13                   grafana | Terminating grafana
13:29:13                  postgres | Terminating postgres
13:29:13                 blobstore | Terminating blobstore
13:29:13                  frontend | {"SeverityText":"WARN","Timestamp":1678368553595875757,"InstrumentationScope":"SiteConfigEscapeHatch","Caller":"conf/conf.go:288","Function":"github.com/sourcegraph/sourcegraph/internal/conf.startSiteConfigEscapeHatchWorker.func1","Body":"failed to read config from database(2), trying again in 1s (read error)","Resource":{"service.name":"frontend","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"path":"/root/site-config.json","error":"ConfStore.SiteGetLatest: FATAL: terminating connection due to administrator command (SQLSTATE 57P01)"}}
13:29:13                  frontend | {"SeverityText":"ERROR","Timestamp":1678368553638599798,"InstrumentationScope":"conf.client","Caller":"conf/client.go:290","Function":"github.com/sourcegraph/sourcegraph/internal/conf.(*client).continuouslyUpdate","Body":"received error during background config update","Resource":{"service.name":"frontend","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"triggered_by":"waitForSleep","error":"unable to fetch new configuration: ConfStore.SiteGetLatest: FATAL: terminating connection due to administrator command (SQLSTATE 57P01)"}}
13:29:14                  frontend | {"SeverityText":"WARN","Timestamp":1678368554601135924,"InstrumentationScope":"SiteConfigEscapeHatch","Caller":"conf/conf.go:288","Function":"github.com/sourcegraph/sourcegraph/internal/conf.startSiteConfigEscapeHatchWorker.func1","Body":"failed to read config from database(2), trying again in 1s (read error)","Resource":{"service.name":"frontend","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"path":"/root/site-config.json","error":"ConfStore.SiteGetLatest: FATAL: terminating connection due to administrator command (SQLSTATE 57P01)"}}
13:29:15                  frontend | {"SeverityText":"WARN","Timestamp":1678368555612838258,"InstrumentationScope":"SiteConfigEscapeHatch","Caller":"conf/conf.go:288","Function":"github.com/sourcegraph/sourcegraph/internal/conf.startSiteConfigEscapeHatchWorker.func1","Body":"failed to read config from database(2), trying again in 1s (read error)","Resource":{"service.name":"frontend","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"path":"/root/site-config.json","error":"ConfStore.SiteGetLatest: failed to connect to `host=127.0.0.1 user=postgres database=sourcegraph`: dial error (dial tcp 127.0.0.1:5432: connect: connection refused)"}}
13:29:16                  frontend | {"SeverityText":"WARN","Timestamp":1678368556623296758,"InstrumentationScope":"SiteConfigEscapeHatch","Caller":"conf/conf.go:288","Function":"github.com/sourcegraph/sourcegraph/internal/conf.startSiteConfigEscapeHatchWorker.func1","Body":"failed to read config from database(2), trying again in 1s (read error)","Resource":{"service.name":"frontend","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"path":"/root/site-config.json","error":"ConfStore.SiteGetLatest: failed to connect to `host=127.0.0.1 user=postgres database=sourcegraph`: dial error (dial tcp 127.0.0.1:5432: connect: connection refused)"}}
13:29:17                  frontend | {"SeverityText":"WARN","Timestamp":1678368557637364134,"InstrumentationScope":"SiteConfigEscapeHatch","Caller":"conf/conf.go:288","Function":"github.com/sourcegraph/sourcegraph/internal/conf.startSiteConfigEscapeHatchWorker.func1","Body":"failed to read config from database(2), trying again in 1s (read error)","Resource":{"service.name":"frontend","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"path":"/root/site-config.json","error":"ConfStore.SiteGetLatest: failed to connect to `host=127.0.0.1 user=postgres database=sourcegraph`: dial error (dial tcp 127.0.0.1:5432: connect: connection refused)"}}
13:29:18                  frontend | {"SeverityText":"WARN","Timestamp":1678368558648709759,"InstrumentationScope":"SiteConfigEscapeHatch","Caller":"conf/conf.go:288","Function":"github.com/sourcegraph/sourcegraph/internal/conf.startSiteConfigEscapeHatchWorker.func1","Body":"failed to read config from database(2), trying again in 1s (read error)","Resource":{"service.name":"frontend","service.version":"205081_2023-03-09_4.5-7d653173d315","service.instance.id":"94c00ca6b18f"},"Attributes":{"path":"/root/site-config.json","error":"ConfStore.SiteGetLatest: failed to connect to `host=127.0.0.1 user=postgres database=sourcegraph`: dial error (dial tcp 127.0.0.1:5432: connect: connection refused)"}}

daxmc99 commented 1 year ago

https://sourcegraph.slack.com/archives/CMBA8F926/p1679738254319889

Error checking for updates. But I am unable to trigger the problem with a simple curl: curl -v -XPOST -d '{"site":"x","version":"0.0.0+sqstest"}' https://sourcegraph.com/.api/updates.

curl -v -XPOST -d '{"site":"x","version":"210033_2023-04-23_5.0-0c865"}' https://sourcegraph.com/.api/updates returns HTTP 204...which is different from HTTP 401 above but also strange

keegancsmith commented 7 months ago

Not sure if related but also seeing this error on /site-admin/updates route when testing the rc for 5.3. Also this issue is so old is it still valid and what I am seeing is just a new issue? But it does seem that this page is hitting our backend so I assume this may be the same root cause.

cc @DaedalusG who has also touched the relevant file.

DaedalusG commented 7 months ago

Right the upgrade page there is basically hitting a drift check endpoint as I recall. The semver package has might not like the insiders tag. Will give this a closer look soon and close if it's a non issue.

With regards to the release testing it's likely just the insiders stamp, not sure how the build is happening 👀

DaedalusG commented 7 months ago

Basically the schema drift checking wants a valid release tag as a target though

keegancsmith commented 7 months ago

Is there a way to make the version parser you use to try and extract the bits that are useful? OR atleast update this so it doesn't hard error since these sort of versions are expected. In that case return something more informational.

sourcegraph / sourcegraph-public-snapshot

oobmigrations: Insiders version not parsed properly #49012