rspec-ee migration pg14 no_gitaly_transactions 2/2
Passed Started
by
@gitlab-bot
🤖 GitLab Bot 🤖
1Running with gitlab-runner 17.0.0~pre.88.g761ae5dd (761ae5dd)2 on green-5.private.runners-manager.gitlab.com/gitlab.com/gitlab-org Zi_8oswQ, system ID: s_8a4f217c24b63 feature flags: FF_NETWORK_PER_BUILD:true4Resolving secrets6Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...7Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...8Authenticating with credentials from job payload (GitLab Registry)9Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...10Using docker image sha256:82f132c22567f8ce17cc132c14b2f9aa3eaf9bb5424d91c2d966912433f0257d for registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:c55e1364ee4327b244a9cfa1750f19feea14fc774eaf792b725967d146eb45f5 ...11WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.12WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.13Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...14Authenticating with credentials from job payload (GitLab Registry)15Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...16Using docker image sha256:5c5ba5b83d6c60cb0b225bd670b7a43be8c238cc72347d24af57e5027c3648f3 for registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:46aceab84c42d0e819c8e7940f2f98ce9e184785cd7b22d95872024a35f52407 ...17Starting service redis:6.2-alpine ...18Pulling docker image redis:6.2-alpine ...19Using docker image sha256:36c1d3cfe18f4b12d4640576f7048068acbfc3625027b6bbb46bba0e31b11831 for redis:6.2-alpine with digest redis@sha256:e3b17ba9479deec4b7d1eeec1548a253acc5374d68d3b27937fcfe4df8d18c7e ...20WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 is already created. Ignoring.21WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 is already created. Ignoring.22Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 ...23Authenticating with credentials from job payload (GitLab Registry)24Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 ...25Using docker image sha256:df819140e3df737cdc7b8d6fb73ce804b05058c790e025b5f52840956feb1734 for registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:7bdf349fc3dd9da64bc6581d44c0e906bffd38977ddbd2668ba34adb5dedfe38 ...26Starting service elasticsearch:7.17.6 ...27Pulling docker image elasticsearch:7.17.6 ...28Using docker image sha256:5fad10241ffd65d817ed0ddfaf6e87eee1f7dc2a7db33db1047835560ea71fda for elasticsearch:7.17.6 with digest elasticsearch@sha256:6c128de5d01c0c130a806022d6bd99b3e4c27a9af5bfc33b6b81861ae117d028 ...29Starting service registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:v1.12.0 ...30Authenticating with credentials from job payload (GitLab Registry)31Pulling docker image registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:v1.12.0 ...32Using docker image sha256:9e2a46104bf429c88386efd9133e58584ef5a27c27cc4435f97778e05847e0e2 for registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:v1.12.0 with digest registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway@sha256:d8f985b0841bd08b3505c9e6ed003f095af36f91b05849f6262ccec4278b9b53 ...33Waiting for services to be up and running (timeout 30 seconds)...34*** WARNING: Service runner-zi8oswq-project-278964-concurrent-0-616c08d7e789ee17-registry.gitlab.com__gitlab-org__modelops__applied-ml__code-suggestions__ai-assist__model-gateway-5 probably didn't start properly.35Health check error:36service "runner-zi8oswq-project-278964-concurrent-0-616c08d7e789ee17-registry.gitlab.com__gitlab-org__modelops__applied-ml__code-suggestions__ai-assist__model-gateway-5-wait-for-service" timeout37Health check container logs:382024-07-31T10:12:24.971363157Z waiting for TCP connection to 37566cd229a4 on [5052]...392024-07-31T10:12:24.983686696Z dialing 37566cd229a4:5052...402024-07-31T10:12:25.986575914Z dialing 37566cd229a4:5052...412024-07-31T10:12:26.987701792Z dialing 37566cd229a4:5052...422024-07-31T10:12:27.988690471Z dialing 37566cd229a4:5052...432024-07-31T10:12:28.989369269Z dialing 37566cd229a4:5052...442024-07-31T10:12:29.990527267Z dialing 37566cd229a4:5052...452024-07-31T10:12:30.991361455Z dialing 37566cd229a4:5052...462024-07-31T10:12:31.992458983Z dialing 37566cd229a4:5052...472024-07-31T10:12:32.995535092Z dialing 37566cd229a4:5052...482024-07-31T10:12:33.997440019Z dialing 37566cd229a4:5052...492024-07-31T10:12:34.999006657Z dialing 37566cd229a4:5052...502024-07-31T10:12:36.001025406Z dialing 37566cd229a4:5052...512024-07-31T10:12:37.002976485Z dialing 37566cd229a4:5052...522024-07-31T10:12:38.004752143Z dialing 37566cd229a4:5052...532024-07-31T10:12:39.006869691Z dialing 37566cd229a4:5052...542024-07-31T10:12:40.008724889Z dialing 37566cd229a4:5052...552024-07-31T10:12:41.009743207Z dialing 37566cd229a4:5052...562024-07-31T10:12:42.011733205Z dialing 37566cd229a4:5052...572024-07-31T10:12:43.012509263Z dialing 37566cd229a4:5052...582024-07-31T10:12:44.013852282Z dialing 37566cd229a4:5052...592024-07-31T10:12:45.015646139Z dialing 37566cd229a4:5052...602024-07-31T10:12:46.016943238Z dialing 37566cd229a4:5052...612024-07-31T10:12:47.018605796Z dialing 37566cd229a4:5052...622024-07-31T10:12:48.019444435Z dialing 37566cd229a4:5052...632024-07-31T10:12:49.021414963Z dialing 37566cd229a4:5052...642024-07-31T10:12:50.022369322Z dialing 37566cd229a4:5052...652024-07-31T10:12:51.024493220Z dialing 37566cd229a4:5052...662024-07-31T10:12:52.026163679Z dialing 37566cd229a4:5052...672024-07-31T10:12:53.027895037Z dialing 37566cd229a4:5052...682024-07-31T10:12:54.029907835Z dialing 37566cd229a4:5052...692024-07-31T10:12:55.031547313Z dialing 37566cd229a4:5052...702024-07-31T10:12:55.034853983Z dial succeeded on 37566cd229a4:5052. Exiting...71Service container logs:722024-07-31T10:12:29.711001546Z Warning: 'ai_gateway' is an entry point defined in pyproject.toml, but it's not installed as a script. You may get improper `sys.argv[0]`.732024-07-31T10:12:29.711081835Z 742024-07-31T10:12:29.711090346Z The support to run uninstalled scripts will be removed in a future release.752024-07-31T10:12:29.711096466Z 762024-07-31T10:12:29.711103095Z Run `poetry install` to resolve and get rid of this message.772024-07-31T10:12:29.711108606Z 782024-07-31T10:12:50.663140377Z None of PyTorch, TensorFlow >= 2.0, or Flax have been found. Models won't be available and only tokenizers, configuration and file/data utilities can be used.792024-07-31T10:12:52.343901906Z {"logger": "main", "level": "info", "type": "mlops", "stage": "main", "timestamp": "2024-07-31T10:12:52.343679Z", "message": "Metrics HTTP server running on http://0.0.0.0:8082"}802024-07-31T10:12:52.990281371Z {"logger": "uvicorn.error", "level": "info", "type": "mlops", "stage": "main", "timestamp": "2024-07-31T10:12:52.985345Z", "message": "Started server process [7]"}812024-07-31T10:12:52.990318321Z {"logger": "uvicorn.error", "level": "info", "type": "mlops", "stage": "main", "timestamp": "2024-07-31T10:12:52.985567Z", "message": "Waiting for application startup."}822024-07-31T10:12:53.245432485Z {"api_endpoint": "us-central1-aiplatform.googleapis.com", "logger": "codesuggestions", "level": "info", "type": "mlops", "stage": "main", "timestamp": "2024-07-31T10:12:53.245086Z", "message": "Initializing Vertex AI client"}832024-07-31T10:12:54.399929907Z {"logger": "uvicorn.error", "level": "info", "type": "mlops", "stage": "main", "timestamp": "2024-07-31T10:12:54.399614Z", "message": "Application startup complete."}842024-07-31T10:12:54.474754160Z {"logger": "uvicorn.error", "level": "info", "type": "mlops", "stage": "main", "timestamp": "2024-07-31T10:12:54.474471Z", "message": "Uvicorn running on http://0.0.0.0:5052 (Press CTRL+C to quit)"}85*********86*** WARNING: Service runner-zi8oswq-project-278964-concurrent-0-616c08d7e789ee17-elasticsearch-4 probably didn't start properly.87Health check error:88service "runner-zi8oswq-project-278964-concurrent-0-616c08d7e789ee17-elasticsearch-4-wait-for-service" timeout89Health check container logs:902024-07-31T10:12:26.193412533Z waiting for TCP connection to 46fea1d49747 on [9200 9300]...912024-07-31T10:12:26.193580683Z dialing 46fea1d49747:9300...922024-07-31T10:12:26.193737913Z dialing 46fea1d49747:9200...932024-07-31T10:12:27.195220251Z dialing 46fea1d49747:9200...942024-07-31T10:12:27.195277701Z dialing 46fea1d49747:9300...952024-07-31T10:12:28.196869100Z dialing 46fea1d49747:9200...962024-07-31T10:12:28.196911389Z dialing 46fea1d49747:9300...972024-07-31T10:12:29.198073258Z dialing 46fea1d49747:9300...982024-07-31T10:12:29.198154518Z dialing 46fea1d49747:9200...992024-07-31T10:12:30.199829516Z dialing 46fea1d49747:9200...1002024-07-31T10:12:30.199880336Z dialing 46fea1d49747:9300...1012024-07-31T10:12:31.201529494Z dialing 46fea1d49747:9300...1022024-07-31T10:12:31.201578663Z dialing 46fea1d49747:9200...1032024-07-31T10:12:32.202763292Z dialing 46fea1d49747:9200...1042024-07-31T10:12:32.202825942Z dialing 46fea1d49747:9300...1052024-07-31T10:12:33.203379840Z dialing 46fea1d49747:9200...1062024-07-31T10:12:33.203436050Z dialing 46fea1d49747:9300...1072024-07-31T10:12:34.204434808Z dialing 46fea1d49747:9300...1082024-07-31T10:12:34.204784058Z dialing 46fea1d49747:9200...1092024-07-31T10:12:35.206662946Z dialing 46fea1d49747:9200...1102024-07-31T10:12:35.206705186Z dialing 46fea1d49747:9300...1112024-07-31T10:12:36.208226164Z dialing 46fea1d49747:9300...1122024-07-31T10:12:36.208275124Z dialing 46fea1d49747:9200...1132024-07-31T10:12:37.209386113Z dialing 46fea1d49747:9300...1142024-07-31T10:12:37.209704203Z dialing 46fea1d49747:9200...1152024-07-31T10:12:38.210669461Z dialing 46fea1d49747:9200...1162024-07-31T10:12:38.210713271Z dialing 46fea1d49747:9300...1172024-07-31T10:12:39.214489530Z dialing 46fea1d49747:9200...1182024-07-31T10:12:39.214580990Z dialing 46fea1d49747:9300...1192024-07-31T10:12:40.216647618Z dialing 46fea1d49747:9300...1202024-07-31T10:12:40.216710238Z dialing 46fea1d49747:9200...1212024-07-31T10:12:41.218149206Z dialing 46fea1d49747:9300...1222024-07-31T10:12:41.218197006Z dialing 46fea1d49747:9200...1232024-07-31T10:12:42.219637984Z dialing 46fea1d49747:9200...1242024-07-31T10:12:42.219705054Z dialing 46fea1d49747:9300...1252024-07-31T10:12:43.220807472Z dialing 46fea1d49747:9300...1262024-07-31T10:12:43.220853732Z dialing 46fea1d49747:9200...1272024-07-31T10:12:44.222197570Z dialing 46fea1d49747:9300...1282024-07-31T10:12:44.222543580Z dialing 46fea1d49747:9200...1292024-07-31T10:12:45.224727678Z dialing 46fea1d49747:9200...1302024-07-31T10:12:45.224780638Z dialing 46fea1d49747:9300...1312024-07-31T10:12:46.225481467Z dialing 46fea1d49747:9300...1322024-07-31T10:12:46.226249857Z dialing 46fea1d49747:9200...1332024-07-31T10:12:47.226512175Z dialing 46fea1d49747:9300...1342024-07-31T10:12:47.226667695Z dialing 46fea1d49747:9200...1352024-07-31T10:12:48.228864684Z dialing 46fea1d49747:9300...1362024-07-31T10:12:48.228921134Z dialing 46fea1d49747:9200...1372024-07-31T10:12:49.230233042Z dialing 46fea1d49747:9300...1382024-07-31T10:12:49.230284952Z dialing 46fea1d49747:9200...1392024-07-31T10:12:50.231783950Z dialing 46fea1d49747:9200...1402024-07-31T10:12:50.231829010Z dialing 46fea1d49747:9300...1412024-07-31T10:12:51.234320279Z dialing 46fea1d49747:9300...1422024-07-31T10:12:51.234379469Z dialing 46fea1d49747:9200...1432024-07-31T10:12:52.235888137Z dialing 46fea1d49747:9200...1442024-07-31T10:12:52.235944857Z dialing 46fea1d49747:9300...1452024-07-31T10:12:53.237892896Z dialing 46fea1d49747:9300...1462024-07-31T10:12:53.237943776Z dialing 46fea1d49747:9200...1472024-07-31T10:12:54.240017534Z dialing 46fea1d49747:9300...1482024-07-31T10:12:54.240060614Z dialing 46fea1d49747:9200...1492024-07-31T10:12:55.241050742Z dialing 46fea1d49747:9300...1502024-07-31T10:12:55.241081952Z dialing 46fea1d49747:9200...1512024-07-31T10:12:56.244926130Z dialing 46fea1d49747:9200...1522024-07-31T10:12:56.244980450Z dialing 46fea1d49747:9300...153Service container logs:1542024-07-31T10:12:39.286683562Z {"type": "server", "timestamp": "2024-07-31T10:12:39,270Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "version[7.17.6], pid[7], build[default/docker/f65e9d338dc1d07b642e14a27f338990148ee5b6/2022-08-23T11:08:48.893373482Z], OS[Linux/5.15.154+/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/18.0.2/18.0.2+9-61]" }1552024-07-31T10:12:39.288269252Z {"type": "server", "timestamp": "2024-07-31T10:12:39,287Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "JVM home [/usr/share/elasticsearch/jdk], using bundled JDK [true]" }1562024-07-31T10:12:39.289177942Z {"type": "server", "timestamp": "2024-07-31T10:12:39,288Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "JVM arguments [-Xshare:auto, -Des.networkaddress.cache.ttl=60, -Des.networkaddress.cache.negative.ttl=10, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -XX:-OmitStackTraceInFastThrow, -XX:+ShowCodeDetailsInExceptionMessages, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Dio.netty.allocator.numDirectArenas=0, -Dlog4j.shutdownHookEnabled=false, -Dlog4j2.disable.jmx=true, -Dlog4j2.formatMsgNoLookups=true, -Djava.locale.providers=SPI,COMPAT, --add-opens=java.base/java.io=ALL-UNNAMED, -Djava.security.manager=allow, -XX:+UseG1GC, -Djava.io.tmpdir=/tmp/elasticsearch-1165347937197773960, -XX:+HeapDumpOnOutOfMemoryError, -XX:+ExitOnOutOfMemoryError, -XX:HeapDumpPath=data, -XX:ErrorFile=logs/hs_err_pid%p.log, -Xlog:gc*,gc+age=trace,safepoint:file=logs/gc.log:utctime,pid,tags:filecount=32,filesize=64m, -Des.cgroups.hierarchy.override=/, -Xms256m, -Xmx256m, -XX:MaxDirectMemorySize=134217728, -XX:G1HeapRegionSize=4m, -XX:InitiatingHeapOccupancyPercent=30, -XX:G1ReservePercent=15, -Des.path.home=/usr/share/elasticsearch, -Des.path.conf=/usr/share/elasticsearch/config, -Des.distribution.flavor=default, -Des.distribution.type=docker, -Des.bundled_jdk=true]" }1572024-07-31T10:12:50.009545313Z {"type": "server", "timestamp": "2024-07-31T10:12:50,008Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [aggs-matrix-stats]" }1582024-07-31T10:12:50.010084353Z {"type": "server", "timestamp": "2024-07-31T10:12:50,009Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [analysis-common]" }1592024-07-31T10:12:50.010989573Z {"type": "server", "timestamp": "2024-07-31T10:12:50,010Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [constant-keyword]" }1602024-07-31T10:12:50.011764753Z {"type": "server", "timestamp": "2024-07-31T10:12:50,011Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [frozen-indices]" }1612024-07-31T10:12:50.018508432Z {"type": "server", "timestamp": "2024-07-31T10:12:50,011Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [ingest-common]" }1622024-07-31T10:12:50.019236972Z {"type": "server", "timestamp": "2024-07-31T10:12:50,018Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [ingest-geoip]" }1632024-07-31T10:12:50.019702952Z {"type": "server", "timestamp": "2024-07-31T10:12:50,019Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [ingest-user-agent]" }1642024-07-31T10:12:50.020083842Z {"type": "server", "timestamp": "2024-07-31T10:12:50,019Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [kibana]" }1652024-07-31T10:12:50.020716682Z {"type": "server", "timestamp": "2024-07-31T10:12:50,020Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [lang-expression]" }1662024-07-31T10:12:50.021066572Z {"type": "server", "timestamp": "2024-07-31T10:12:50,020Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [lang-mustache]" }1672024-07-31T10:12:50.021416092Z {"type": "server", "timestamp": "2024-07-31T10:12:50,021Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [lang-painless]" }1682024-07-31T10:12:50.021723242Z {"type": "server", "timestamp": "2024-07-31T10:12:50,021Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [legacy-geo]" }1692024-07-31T10:12:50.022057252Z {"type": "server", "timestamp": "2024-07-31T10:12:50,021Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [mapper-extras]" }1702024-07-31T10:12:50.025517722Z {"type": "server", "timestamp": "2024-07-31T10:12:50,022Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [mapper-version]" }1712024-07-31T10:12:50.026213511Z {"type": "server", "timestamp": "2024-07-31T10:12:50,025Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [parent-join]" }1722024-07-31T10:12:50.026850311Z {"type": "server", "timestamp": "2024-07-31T10:12:50,026Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [percolator]" }1732024-07-31T10:12:50.027167331Z {"type": "server", "timestamp": "2024-07-31T10:12:50,026Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [rank-eval]" }1742024-07-31T10:12:50.027692901Z {"type": "server", "timestamp": "2024-07-31T10:12:50,027Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [reindex]" }1752024-07-31T10:12:50.028683181Z {"type": "server", "timestamp": "2024-07-31T10:12:50,027Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [repositories-metering-api]" }1762024-07-31T10:12:50.028999311Z {"type": "server", "timestamp": "2024-07-31T10:12:50,028Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [repository-encrypted]" }1772024-07-31T10:12:50.029672991Z {"type": "server", "timestamp": "2024-07-31T10:12:50,029Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [repository-url]" }1782024-07-31T10:12:50.030092711Z {"type": "server", "timestamp": "2024-07-31T10:12:50,029Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [runtime-fields-common]" }1792024-07-31T10:12:50.030956701Z {"type": "server", "timestamp": "2024-07-31T10:12:50,030Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [search-business-rules]" }1802024-07-31T10:12:50.031278161Z {"type": "server", "timestamp": "2024-07-31T10:12:50,030Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [searchable-snapshots]" }1812024-07-31T10:12:50.031565921Z {"type": "server", "timestamp": "2024-07-31T10:12:50,031Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [snapshot-repo-test-kit]" }1822024-07-31T10:12:50.032348501Z {"type": "server", "timestamp": "2024-07-31T10:12:50,031Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [spatial]" }1832024-07-31T10:12:50.032631261Z {"type": "server", "timestamp": "2024-07-31T10:12:50,032Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [transform]" }1842024-07-31T10:12:50.032913001Z {"type": "server", "timestamp": "2024-07-31T10:12:50,032Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [transport-netty4]" }1852024-07-31T10:12:50.033329111Z {"type": "server", "timestamp": "2024-07-31T10:12:50,033Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [unsigned-long]" }1862024-07-31T10:12:50.033601770Z {"type": "server", "timestamp": "2024-07-31T10:12:50,033Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [vector-tile]" }1872024-07-31T10:12:50.033884690Z {"type": "server", "timestamp": "2024-07-31T10:12:50,033Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [vectors]" }1882024-07-31T10:12:50.034179510Z {"type": "server", "timestamp": "2024-07-31T10:12:50,033Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [wildcard]" }1892024-07-31T10:12:50.034472810Z {"type": "server", "timestamp": "2024-07-31T10:12:50,034Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-aggregate-metric]" }1902024-07-31T10:12:50.034744990Z {"type": "server", "timestamp": "2024-07-31T10:12:50,034Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-analytics]" }1912024-07-31T10:12:50.035228980Z {"type": "server", "timestamp": "2024-07-31T10:12:50,034Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-async]" }1922024-07-31T10:12:50.035848410Z {"type": "server", "timestamp": "2024-07-31T10:12:50,035Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-async-search]" }1932024-07-31T10:12:50.036153520Z {"type": "server", "timestamp": "2024-07-31T10:12:50,035Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-autoscaling]" }1942024-07-31T10:12:50.036460250Z {"type": "server", "timestamp": "2024-07-31T10:12:50,036Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-ccr]" }1952024-07-31T10:12:50.036949460Z {"type": "server", "timestamp": "2024-07-31T10:12:50,036Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-core]" }1962024-07-31T10:12:50.037783800Z {"type": "server", "timestamp": "2024-07-31T10:12:50,037Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-data-streams]" }1972024-07-31T10:12:50.038088980Z {"type": "server", "timestamp": "2024-07-31T10:12:50,037Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-deprecation]" }1982024-07-31T10:12:50.038364460Z {"type": "server", "timestamp": "2024-07-31T10:12:50,038Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-enrich]" }1992024-07-31T10:12:50.038911400Z {"type": "server", "timestamp": "2024-07-31T10:12:50,038Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-eql]" }2002024-07-31T10:12:50.039204920Z {"type": "server", "timestamp": "2024-07-31T10:12:50,038Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-fleet]" }2012024-07-31T10:12:50.039509010Z {"type": "server", "timestamp": "2024-07-31T10:12:50,039Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-graph]" }2022024-07-31T10:12:50.039791380Z {"type": "server", "timestamp": "2024-07-31T10:12:50,039Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-identity-provider]" }2032024-07-31T10:12:50.040261020Z {"type": "server", "timestamp": "2024-07-31T10:12:50,039Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-ilm]" }2042024-07-31T10:12:50.040776920Z {"type": "server", "timestamp": "2024-07-31T10:12:50,040Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-logstash]" }2052024-07-31T10:12:50.041229700Z {"type": "server", "timestamp": "2024-07-31T10:12:50,040Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-ml]" }2062024-07-31T10:12:50.041829770Z {"type": "server", "timestamp": "2024-07-31T10:12:50,041Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-monitoring]" }2072024-07-31T10:12:50.043986000Z {"type": "server", "timestamp": "2024-07-31T10:12:50,041Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-ql]" }2082024-07-31T10:12:50.044315249Z {"type": "server", "timestamp": "2024-07-31T10:12:50,044Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-rollup]" }2092024-07-31T10:12:50.044609980Z {"type": "server", "timestamp": "2024-07-31T10:12:50,044Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-security]" }2102024-07-31T10:12:50.045444049Z {"type": "server", "timestamp": "2024-07-31T10:12:50,044Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-shutdown]" }2112024-07-31T10:12:50.046189979Z {"type": "server", "timestamp": "2024-07-31T10:12:50,045Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-sql]" }2122024-07-31T10:12:50.046846199Z {"type": "server", "timestamp": "2024-07-31T10:12:50,046Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-stack]" }2132024-07-31T10:12:50.047162409Z {"type": "server", "timestamp": "2024-07-31T10:12:50,046Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-text-structure]" }2142024-07-31T10:12:50.047441519Z {"type": "server", "timestamp": "2024-07-31T10:12:50,047Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-voting-only-node]" }2152024-07-31T10:12:50.047722589Z {"type": "server", "timestamp": "2024-07-31T10:12:50,047Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "loaded module [x-pack-watcher]" }2162024-07-31T10:12:50.048618099Z {"type": "server", "timestamp": "2024-07-31T10:12:50,048Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "no plugins loaded" }2172024-07-31T10:12:50.272184156Z {"type": "server", "timestamp": "2024-07-31T10:12:50,270Z", "level": "INFO", "component": "o.e.e.NodeEnvironment", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "using [1] data paths, mounts [[/ (overlay)]], net usable_space [76.9gb], net total_space [94.2gb], types [overlay]" }2182024-07-31T10:12:50.272228806Z {"type": "server", "timestamp": "2024-07-31T10:12:50,271Z", "level": "INFO", "component": "o.e.e.NodeEnvironment", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "heap size [256mb], compressed ordinary object pointers [true]" }2192024-07-31T10:12:50.481831665Z {"type": "server", "timestamp": "2024-07-31T10:12:50,481Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "46fea1d49747", "message": "node name [46fea1d49747], node ID [2ihz-3w3S_msaVD2RW6Umg], cluster name [docker-cluster], roles [transform, data_frozen, master, remote_cluster_client, data, ml, data_content, data_hot, data_warm, data_cold, ingest]" }220*********221Authenticating with credentials from job payload (GitLab Registry)222Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...223Using docker image sha256:b26253b493531cada33f45ef568f38c50a310442d05c39f517656e0f7d305dc7 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14@sha256:543339542a02edc250c2c0424c5077b673f1fca2877024fdc5fb670eff44f8cf ...225Running on runner-zi8oswq-project-278964-concurrent-0 via runner-zi8oswq-private-1722407107-093b1fa2...227Skipping Git repository setup228Skipping Git checkout229Skipping Git submodules setup231Checking cache for ruby-gems-debian-bookworm-ruby-3.1.5-17...232Downloading cache from https://storage.googleapis.com/gitlab-com-runners-cache/project/278964/ruby-gems-debian-bookworm-ruby-3.1.5-17 233Successfully extracted cache235Downloading artifacts for clone-gitlab-repo (7471344368)...236Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344368 responseStatus=200 OK token=glcbt-66237WARNING: Part of .git directory is on the list of files to extract 238WARNING: This may introduce unexpected problems 239Downloading artifacts for compile-test-assets (7471344747)...240Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344747 responseStatus=200 OK token=glcbt-66241Downloading artifacts for retrieve-tests-metadata (7471344898)...242Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344898 responseStatus=200 OK token=glcbt-66243Downloading artifacts for setup-test-env (7471344810)...244Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344810 responseStatus=200 OK token=glcbt-66 245 Executing "step_script" stage of the job script 246Using docker image sha256:b26253b493531cada33f45ef568f38c50a310442d05c39f517656e0f7d305dc7 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14@sha256:543339542a02edc250c2c0424c5077b673f1fca2877024fdc5fb670eff44f8cf ...247$ echo $FOSS_ONLY248$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb249$ export GOPATH=$CI_PROJECT_DIR/.go250$ mkdir -p $GOPATH251$ source scripts/utils.sh252$ source scripts/prepare_build.sh282Using decomposed database config (config/database.yml.decomposed-postgresql)283Geo DB will be set up.284Embedding DB will be set up.300$ source ./scripts/rspec_helpers.sh301$ run_timed_command "gem install knapsack --no-document"302$ gem install knapsack --no-document303Successfully installed knapsack-4.0.03041 gem installed305==> 'gem install knapsack --no-document' succeeded in 1 seconds.306$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"311$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"312$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"313$ tooling/bin/create_job_metrics_file || true314[job-metrics] Creating the job metrics file for the CI/CD job.315$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"317[10:17:40] Starting rspec_parallelized_job318RETRY_FAILED_TESTS_IN_NEW_PROCESS: true319KNAPSACK_GENERATE_REPORT: true320FLAKY_RSPEC_GENERATE_REPORT: true321KNAPSACK_TEST_FILE_PATTERN: {ee/}spec/{migrations}{,/**/}*_spec.rb322KNAPSACK_LOG_LEVEL: debug323KNAPSACK_REPORT_PATH: knapsack/rspec-ee_migration_pg14_no_gitaly_transactions_2_2_278964_report.json324FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json325FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec-ee_migration_pg14_no_gitaly_transactions_2_2_278964_report.json326NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec-ee_migration_pg14_no_gitaly_transactions_2_2_278964_report.json327RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-7471346877.txt328CRYSTALBALL: true329RSPEC_TESTS_MAPPING_ENABLED: 330RSPEC_TESTS_FILTER_FILE: 331Shell set options (set -o) enabled:332braceexpand on333hashall on334interactive-comments on335pipefail on336Knapsack report generator started!337warning: parser/current is loading parser/ruby31, which recognizes 3.1.6-compliant syntax, but you are running 3.1.5.339Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}340# [RSpecRunTime] Starting RSpec timer...341[TEST PROF INFO] EventProf enabled (sql.active_record)342unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.343unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.344Test environment set up in 3.653878916 seconds345# [RSpecRunTime] Starting example group ee/spec/migrations/20240209153920_queue_purge_security_scans_with_empty_finding_data_spec.rb. Expected to take 1 minute 41.99 seconds.346QueuePurgeSecurityScansWithEmptyFindingData347 for scheduling based on data348 when there is no succeeded scan349WARNING: Active Record does not support composite primary key.350p_ci_builds has composite primary key. Composite primary key is ignored.351WARNING: Active Record does not support composite primary key.352security_findings has composite primary key. Composite primary key is ignored.353main: == [advisory_lock_connection] object_id: 12674900, pg_backend_pid: 194354main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrating ======355main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrated (0.0145s) 356main: == [advisory_lock_connection] object_id: 12674900, pg_backend_pid: 194357 does not schedule a new batched migration358 when there is a succeeded scan359 when there is no associated finding with the security scan360WARNING: Active Record does not support composite primary key.361p_ci_builds has composite primary key. Composite primary key is ignored.362main: == [advisory_lock_connection] object_id: 14900880, pg_backend_pid: 198363main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrating ======364WARNING: Active Record does not support composite primary key.365security_findings has composite primary key. Composite primary key is ignored.366main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrated (0.1034s) 367main: == [advisory_lock_connection] object_id: 14900880, pg_backend_pid: 198368 schedules a new batched migration369# [RSpecRunTime] RSpec elapsed time: 1 minute 23.44 seconds. Current RSS: ~1404M. Threads: 2. load average: 1.00 1.34 1.59 1/399 410370.371 when the first associated finding has `finding_data`372WARNING: Active Record does not support composite primary key.373p_ci_builds has composite primary key. Composite primary key is ignored.374WARNING: Active Record does not support composite primary key.375security_findings has composite primary key. Composite primary key is ignored.376main: == [advisory_lock_connection] object_id: 15523760, pg_backend_pid: 202377main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrating ======378main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrated (0.0259s) 379main: == [advisory_lock_connection] object_id: 15523760, pg_backend_pid: 202380 does not schedule a new batched migration381# [RSpecRunTime] RSpec elapsed time: 1 minute 33.11 seconds. Current RSS: ~1441M. Threads: 2. load average: 1.00 1.33 1.59 1/400 412382.383 when the first associated finding does not have `finding_data`384WARNING: Active Record does not support composite primary key.385p_ci_builds has composite primary key. Composite primary key is ignored.386WARNING: Active Record does not support composite primary key.387security_findings has composite primary key. Composite primary key is ignored.388main: == [advisory_lock_connection] object_id: 16062880, pg_backend_pid: 205389main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrating ======390main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrated (0.0787s) 391main: == [advisory_lock_connection] object_id: 16062880, pg_backend_pid: 205392 schedules a new batched migration393# [RSpecRunTime] RSpec elapsed time: 1 minute 42.68 seconds. Current RSS: ~1440M. Threads: 2. load average: 1.00 1.32 1.58 1/400 413394.395 for scheduling based on environment396 when it is on GitLab.com397WARNING: Active Record does not support composite primary key.398p_ci_builds has composite primary key. Composite primary key is ignored.399WARNING: Active Record does not support composite primary key.400security_findings has composite primary key. Composite primary key is ignored.401main: == [advisory_lock_connection] object_id: 16785380, pg_backend_pid: 209402main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrating ======403main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrated (0.0109s) 404main: == [advisory_lock_connection] object_id: 16785380, pg_backend_pid: 209405 does not schedule a new batched migration406# [RSpecRunTime] RSpec elapsed time: 1 minute 52.0 seconds. Current RSS: ~1432M. Threads: 2. load average: 1.00 1.31 1.57 1/400 414407.408 when it is not on GitLab.com409WARNING: Active Record does not support composite primary key.410p_ci_builds has composite primary key. Composite primary key is ignored.411WARNING: Active Record does not support composite primary key.412security_findings has composite primary key. Composite primary key is ignored.413main: == [advisory_lock_connection] object_id: 17536540, pg_backend_pid: 213414main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrating ======415main: == 20240209153920 QueuePurgeSecurityScansWithEmptyFindingData: migrated (0.0792s) 416main: == [advisory_lock_connection] object_id: 17536540, pg_backend_pid: 213417 schedules a new batched migration418# [RSpecRunTime] RSpec elapsed time: 2 minutes 1.18 seconds. Current RSS: ~1427M. Threads: 2. load average: 1.00 1.30 1.57 1/400 415419.420INFO: analyzing "public.p_ci_stages" inheritance tree421INFO: analyzing "public.ci_stages"422INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows423I, [2024-07-31T10:22:11.735411 #330] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes424I, [2024-07-31T10:22:11.736934 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}425I, [2024-07-31T10:22:11.738022 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}426I, [2024-07-31T10:22:13.049998 #330] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes427I, [2024-07-31T10:22:20.275818 #330] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes428I, [2024-07-31T10:22:35.795553 #330] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes429I, [2024-07-31T10:22:35.796779 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}430I, [2024-07-31T10:22:35.797662 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}431I, [2024-07-31T10:22:49.555395 #330] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes432I, [2024-07-31T10:22:57.449947 #330] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes433# [RSpecRunTime] Finishing example group ee/spec/migrations/20240209153920_queue_purge_security_scans_with_empty_finding_data_spec.rb. It took 2 minutes 58.15 seconds. Expected to take 1 minute 41.99 seconds.434# [RSpecRunTime] RSpec elapsed time: 3 minutes 5.64 seconds. Current RSS: ~1361M. Threads: 2. load average: 0.95 1.22 1.52 1/400 416435.436# [RSpecRunTime] Starting example group ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb. Expected to take 1 minute 27.62 seconds.437QueueUpdateWorkspacesConfigVersion438main: == [advisory_lock_connection] object_id: 50364700, pg_backend_pid: 250439main: == 20230910120000 QueueUpdateWorkspacesConfigVersion: migrating ===============440main: == 20230910120000 QueueUpdateWorkspacesConfigVersion: migrated (0.0811s) ======441main: == [advisory_lock_connection] object_id: 50364700, pg_backend_pid: 250442 schedules a new batched migration443I, [2024-07-31T10:24:51.153837 #330] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes444I, [2024-07-31T10:25:13.653898 #330] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes445INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree446INFO: analyzing "public.ci_pipeline_variables"447INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows448I, [2024-07-31T10:25:15.472302 #330] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes449I, [2024-07-31T10:25:15.473454 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}450I, [2024-07-31T10:25:15.474271 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}451INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree452INFO: analyzing "public.ci_pipeline_variables"453INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows454INFO: analyzing "public.p_ci_job_artifacts" inheritance tree455INFO: analyzing "public.ci_job_artifacts"456INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows457I, [2024-07-31T10:25:22.549534 #330] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes458I, [2024-07-31T10:25:22.550958 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}459I, [2024-07-31T10:25:22.553015 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}460INFO: analyzing "public.p_ci_stages" inheritance tree461INFO: analyzing "public.ci_stages"462INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows463I, [2024-07-31T10:25:26.414488 #330] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes464I, [2024-07-31T10:25:26.415876 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}465I, [2024-07-31T10:25:26.416787 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}466I, [2024-07-31T10:25:27.883347 #330] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes467I, [2024-07-31T10:25:35.198895 #330] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes468I, [2024-07-31T10:25:51.043398 #330] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes469I, [2024-07-31T10:25:51.044792 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}470I, [2024-07-31T10:25:51.045777 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}471I, [2024-07-31T10:26:04.535231 #330] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes472I, [2024-07-31T10:26:12.610503 #330] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes473# [RSpecRunTime] Finishing example group ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb. It took 3 minutes 14.9 seconds. Expected to take 1 minute 27.62 seconds.474# [RSpecRunTime] RSpec elapsed time: 6 minutes 20.61 seconds. Current RSS: ~1359M. Threads: 2. load average: 1.03 1.17 1.45 1/398 417475.476# [RSpecRunTime] Starting example group ee/spec/migrations/20240104085448_queue_update_workspaces_config_version3_spec.rb. Expected to take 1 minute 4.77 seconds.477QueueUpdateWorkspacesConfigVersion3478main: == [advisory_lock_connection] object_id: 86336380, pg_backend_pid: 288479main: == 20240104085448 QueueUpdateWorkspacesConfigVersion3: migrating ==============480main: == 20240104085448 QueueUpdateWorkspacesConfigVersion3: migrated (0.0752s) =====481main: == [advisory_lock_connection] object_id: 86336380, pg_backend_pid: 288482 schedules a new batched migration483I, [2024-07-31T10:27:43.108525 #330] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes484INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree485INFO: analyzing "public.ci_pipeline_variables"486INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows487I, [2024-07-31T10:27:44.933908 #330] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes488I, [2024-07-31T10:27:44.935466 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}489I, [2024-07-31T10:27:44.936486 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}490INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree491INFO: analyzing "public.ci_pipeline_variables"492INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows493INFO: analyzing "public.p_ci_job_artifacts" inheritance tree494INFO: analyzing "public.ci_job_artifacts"495INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows496I, [2024-07-31T10:27:51.826716 #330] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes497I, [2024-07-31T10:27:51.827889 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}498I, [2024-07-31T10:27:51.828730 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}499INFO: analyzing "public.p_ci_stages" inheritance tree500INFO: analyzing "public.ci_stages"501INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows502I, [2024-07-31T10:27:55.748526 #330] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes503I, [2024-07-31T10:27:55.749846 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}504I, [2024-07-31T10:27:55.750781 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}505I, [2024-07-31T10:27:57.279904 #330] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes506I, [2024-07-31T10:28:04.688792 #330] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes507I, [2024-07-31T10:28:20.272643 #330] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes508I, [2024-07-31T10:28:20.274827 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}509I, [2024-07-31T10:28:20.275711 #330] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}510I, [2024-07-31T10:28:33.695084 #330] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes511I, [2024-07-31T10:28:41.635266 #330] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes512# [RSpecRunTime] Finishing example group ee/spec/migrations/20240104085448_queue_update_workspaces_config_version3_spec.rb. It took 2 minutes 29.2 seconds. Expected to take 1 minute 4.77 seconds.513# [RSpecRunTime] RSpec elapsed time: 8 minutes 49.87 seconds. Current RSS: ~1356M. Threads: 2. load average: 1.06 1.13 1.39 1/399 418514.515# [RSpecRunTime] Starting example group ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb. Expected to take 31.99 seconds.516ResyncDirectUploadJobArtifactRegistry517 #up518 when direct upload is enabled for job artifacts519 when the site is a Geo secondary520 when sync_object_storage is enabled for the current Geo site521 with job artifact registry rows522geo: == [advisory_lock_connection] object_id: 105003860, pg_backend_pid: 324523geo: == 20230808031211 ResyncDirectUploadJobArtifactRegistry: migrating ============524geo: -- Enqueuing Geo::ResyncDirectUploadJobArtifactRegistryWorker jobs to mark artifacts pending526geo: -- Enqueuing Geo::ResyncDirectUploadJobArtifactRegistryWorker for range 1..2527geo: -- Enqueued 1 Geo::ResyncDirectUploadJobArtifactRegistryWorker job528geo: == 20230808031211 ResyncDirectUploadJobArtifactRegistry: migrated (0.1276s) ===529geo: == [advisory_lock_connection] object_id: 105003860, pg_backend_pid: 324530 marks pending if synced between 2023-06-22 and 2024-02-03531geo: == [advisory_lock_connection] object_id: 105480640, pg_backend_pid: 331532geo: == 20230808031211 ResyncDirectUploadJobArtifactRegistry: migrating ============533geo: -- Enqueuing Geo::ResyncDirectUploadJobArtifactRegistryWorker jobs to mark artifacts pending535geo: -- Enqueuing Geo::ResyncDirectUploadJobArtifactRegistryWorker for range 3..4536geo: -- Enqueued 1 Geo::ResyncDirectUploadJobArtifactRegistryWorker job537geo: == 20230808031211 ResyncDirectUploadJobArtifactRegistry: migrated (0.0897s) ===538geo: == [advisory_lock_connection] object_id: 105480640, pg_backend_pid: 331539 does not update if not synced540geo: == [advisory_lock_connection] object_id: 105711060, pg_backend_pid: 338541geo: == 20230808031211 ResyncDirectUploadJobArtifactRegistry: migrating ============542geo: -- Enqueuing Geo::ResyncDirectUploadJobArtifactRegistryWorker jobs to mark artifacts pending544geo: -- Enqueuing Geo::ResyncDirectUploadJobArtifactRegistryWorker for range 5..5545geo: -- Enqueued 1 Geo::ResyncDirectUploadJobArtifactRegistryWorker job546geo: == 20230808031211 ResyncDirectUploadJobArtifactRegistry: migrated (0.0894s) ===547geo: == [advisory_lock_connection] object_id: 105711060, pg_backend_pid: 338548 does not update if synced before 2023-06-22549geo: == [advisory_lock_connection] object_id: 106376980, pg_backend_pid: 346550geo: == 20230808031211 ResyncDirectUploadJobArtifactRegistry: migrating ============551geo: -- Enqueuing Geo::ResyncDirectUploadJobArtifactRegistryWorker jobs to mark artifacts pending553geo: -- Enqueuing Geo::ResyncDirectUploadJobArtifactRegistryWorker for range 6..6554geo: -- Enqueued 1 Geo::ResyncDirectUploadJobArtifactRegistryWorker job555geo: == 20230808031211 ResyncDirectUploadJobArtifactRegistry: migrated (0.0905s) ===556geo: == [advisory_lock_connection] object_id: 106376980, pg_backend_pid: 346557 does not update if synced after 2024-02-03558# [RSpecRunTime] RSpec elapsed time: 9 minutes 8.87 seconds. Current RSS: ~1483M. Threads: 2. load average: 1.04 1.12 1.38 1/400 419559.560 when sync_object_storage is disabled for the current Geo site561 does not update job artifact registry562# [RSpecRunTime] RSpec elapsed time: 9 minutes 13.17 seconds. Current RSS: ~1506M. Threads: 2. load average: 1.04 1.12 1.38 1/400 420563.564 when the site is a Geo primary565 does not update job artifact registry566# [RSpecRunTime] RSpec elapsed time: 9 minutes 17.38 seconds. Current RSS: ~1547M. Threads: 2. load average: 0.96 1.10 1.37 1/400 421567.568 when direct upload is disabled for job artifacts569 does not update job artifact registry570# [RSpecRunTime] RSpec elapsed time: 9 minutes 21.56 seconds. Current RSS: ~1547M. Threads: 2. load average: 0.96 1.10 1.37 1/400 422571.572 when object storage is disabled for job artifacts573 does not update job artifact registry574# [RSpecRunTime] RSpec elapsed time: 9 minutes 25.84 seconds. Current RSS: ~1546M. Threads: 2. load average: 0.97 1.09 1.36 1/400 423575.576# [RSpecRunTime] Finishing example group ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb. It took 44.4 seconds. Expected to take 31.99 seconds.577# [RSpecRunTime] RSpec elapsed time: 9 minutes 34.34 seconds. Current RSS: ~1480M. Threads: 2. load average: 0.97 1.09 1.36 1/400 424578.579# [RSpecRunTime] Starting example group ee/spec/migrations/geo/migrate_lfs_objects_to_separate_registry_spec.rb. Expected to take 21.12 seconds.580MigrateLfsObjectsToSeparateRegistry581 #up582geo: == [advisory_lock_connection] object_id: 110209280, pg_backend_pid: 406583== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrating ==============584-- execute("LOCK TABLE file_registry IN EXCLUSIVE MODE")585 -> 0.0015s586-- execute("INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\nSELECT created_at, retry_at, file_id, bytes, retry_count, missing_on_primary, success, sha256::bytea\nFROM file_registry WHERE file_type = 'lfs'\n")587 -> 0.0033s588-- execute("CREATE OR REPLACE FUNCTION replicate_lfs_object_registry()\nRETURNS trigger AS\n$BODY$\nBEGIN\n IF (TG_OP = 'UPDATE') THEN\n UPDATE lfs_object_registry\n SET (retry_at, bytes, retry_count, missing_on_primary, success, sha256) =\n (NEW.retry_at, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea)\n WHERE lfs_object_id = NEW.file_id;\n ELSEIF (TG_OP = 'INSERT') THEN\n INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\n VALUES (NEW.created_at, NEW.retry_at, NEW.file_id, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea);\nEND IF;\nRETURN NEW;\nEND;\n$BODY$\nLANGUAGE 'plpgsql'\nVOLATILE;\n")589 -> 0.0043s590-- execute("CREATE TRIGGER replicate_lfs_object_registry\nAFTER INSERT OR UPDATE ON file_registry\nFOR EACH ROW WHEN (NEW.file_type = 'lfs') EXECUTE PROCEDURE replicate_lfs_object_registry();\n")591 -> 0.0031s592== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrated (0.0283s) =====593geo: == [advisory_lock_connection] object_id: 110209280, pg_backend_pid: 406594 migrates all file registries for LFS objects to its own data table595geo: == [advisory_lock_connection] object_id: 110292020, pg_backend_pid: 413596== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrating ==============597-- execute("LOCK TABLE file_registry IN EXCLUSIVE MODE")598 -> 0.0012s599-- execute("INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\nSELECT created_at, retry_at, file_id, bytes, retry_count, missing_on_primary, success, sha256::bytea\nFROM file_registry WHERE file_type = 'lfs'\n")600 -> 0.0043s601-- execute("CREATE OR REPLACE FUNCTION replicate_lfs_object_registry()\nRETURNS trigger AS\n$BODY$\nBEGIN\n IF (TG_OP = 'UPDATE') THEN\n UPDATE lfs_object_registry\n SET (retry_at, bytes, retry_count, missing_on_primary, success, sha256) =\n (NEW.retry_at, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea)\n WHERE lfs_object_id = NEW.file_id;\n ELSEIF (TG_OP = 'INSERT') THEN\n INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\n VALUES (NEW.created_at, NEW.retry_at, NEW.file_id, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea);\nEND IF;\nRETURN NEW;\nEND;\n$BODY$\nLANGUAGE 'plpgsql'\nVOLATILE;\n")602 -> 0.0044s603-- execute("CREATE TRIGGER replicate_lfs_object_registry\nAFTER INSERT OR UPDATE ON file_registry\nFOR EACH ROW WHEN (NEW.file_type = 'lfs') EXECUTE PROCEDURE replicate_lfs_object_registry();\n")604 -> 0.0024s605== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrated (0.0302s) =====606geo: == [advisory_lock_connection] object_id: 110292020, pg_backend_pid: 413607 creates a new lfs object registry with the trigger608geo: == [advisory_lock_connection] object_id: 110519620, pg_backend_pid: 419609== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrating ==============610-- execute("LOCK TABLE file_registry IN EXCLUSIVE MODE")611 -> 0.0013s612-- execute("INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\nSELECT created_at, retry_at, file_id, bytes, retry_count, missing_on_primary, success, sha256::bytea\nFROM file_registry WHERE file_type = 'lfs'\n")613 -> 0.0037s614-- execute("CREATE OR REPLACE FUNCTION replicate_lfs_object_registry()\nRETURNS trigger AS\n$BODY$\nBEGIN\n IF (TG_OP = 'UPDATE') THEN\n UPDATE lfs_object_registry\n SET (retry_at, bytes, retry_count, missing_on_primary, success, sha256) =\n (NEW.retry_at, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea)\n WHERE lfs_object_id = NEW.file_id;\n ELSEIF (TG_OP = 'INSERT') THEN\n INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\n VALUES (NEW.created_at, NEW.retry_at, NEW.file_id, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea);\nEND IF;\nRETURN NEW;\nEND;\n$BODY$\nLANGUAGE 'plpgsql'\nVOLATILE;\n")615 -> 0.0027s616-- execute("CREATE TRIGGER replicate_lfs_object_registry\nAFTER INSERT OR UPDATE ON file_registry\nFOR EACH ROW WHEN (NEW.file_type = 'lfs') EXECUTE PROCEDURE replicate_lfs_object_registry();\n")617 -> 0.0014s618== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrated (0.0259s) =====619geo: == [advisory_lock_connection] object_id: 110519620, pg_backend_pid: 419620 updates a new lfs object with the trigger621geo: == [advisory_lock_connection] object_id: 111233860, pg_backend_pid: 425622== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrating ==============623-- execute("LOCK TABLE file_registry IN EXCLUSIVE MODE")624 -> 0.0014s625-- execute("INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\nSELECT created_at, retry_at, file_id, bytes, retry_count, missing_on_primary, success, sha256::bytea\nFROM file_registry WHERE file_type = 'lfs'\n")626 -> 0.0034s627-- execute("CREATE OR REPLACE FUNCTION replicate_lfs_object_registry()\nRETURNS trigger AS\n$BODY$\nBEGIN\n IF (TG_OP = 'UPDATE') THEN\n UPDATE lfs_object_registry\n SET (retry_at, bytes, retry_count, missing_on_primary, success, sha256) =\n (NEW.retry_at, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea)\n WHERE lfs_object_id = NEW.file_id;\n ELSEIF (TG_OP = 'INSERT') THEN\n INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\n VALUES (NEW.created_at, NEW.retry_at, NEW.file_id, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea);\nEND IF;\nRETURN NEW;\nEND;\n$BODY$\nLANGUAGE 'plpgsql'\nVOLATILE;\n")628 -> 0.0030s629-- execute("CREATE TRIGGER replicate_lfs_object_registry\nAFTER INSERT OR UPDATE ON file_registry\nFOR EACH ROW WHEN (NEW.file_type = 'lfs') EXECUTE PROCEDURE replicate_lfs_object_registry();\n")630 -> 0.0015s631== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrated (0.0265s) =====632geo: == [advisory_lock_connection] object_id: 111233860, pg_backend_pid: 425633 creates a new lfs object using the next ID634# [RSpecRunTime] RSpec elapsed time: 9 minutes 51.63 seconds. Current RSS: ~1545M. Threads: 2. load average: 1.13 1.12 1.37 1/400 425635.636 #down637geo: == [advisory_lock_connection] object_id: 111900060, pg_backend_pid: 432638== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrating ==============639-- execute("LOCK TABLE file_registry IN EXCLUSIVE MODE")640 -> 0.0016s641-- execute("INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\nSELECT created_at, retry_at, file_id, bytes, retry_count, missing_on_primary, success, sha256::bytea\nFROM file_registry WHERE file_type = 'lfs'\n")642 -> 0.0033s643-- execute("CREATE OR REPLACE FUNCTION replicate_lfs_object_registry()\nRETURNS trigger AS\n$BODY$\nBEGIN\n IF (TG_OP = 'UPDATE') THEN\n UPDATE lfs_object_registry\n SET (retry_at, bytes, retry_count, missing_on_primary, success, sha256) =\n (NEW.retry_at, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea)\n WHERE lfs_object_id = NEW.file_id;\n ELSEIF (TG_OP = 'INSERT') THEN\n INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\n VALUES (NEW.created_at, NEW.retry_at, NEW.file_id, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea);\nEND IF;\nRETURN NEW;\nEND;\n$BODY$\nLANGUAGE 'plpgsql'\nVOLATILE;\n")644 -> 0.0026s645-- execute("CREATE TRIGGER replicate_lfs_object_registry\nAFTER INSERT OR UPDATE ON file_registry\nFOR EACH ROW WHEN (NEW.file_type = 'lfs') EXECUTE PROCEDURE replicate_lfs_object_registry();\n")646 -> 0.0018s647== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrated (0.0261s) =====648geo: == [advisory_lock_connection] object_id: 111900060, pg_backend_pid: 432649 rolls back data properly650# [RSpecRunTime] RSpec elapsed time: 9 minutes 55.95 seconds. Current RSS: ~1543M. Threads: 2. load average: 1.12 1.12 1.36 1/400 426651.652# [RSpecRunTime] Finishing example group ee/spec/migrations/geo/migrate_lfs_objects_to_separate_registry_spec.rb. It took 31.13 seconds. Expected to take 21.12 seconds.653# [RSpecRunTime] RSpec elapsed time: 10 minutes 5.54 seconds. Current RSS: ~1475M. Threads: 2. load average: 1.02 1.10 1.35 1/400 427654.655auto_explain log contains 954 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-ee-migration-pg14-no-gitaly-transactions-2-2.330.main.ndjson.gz656took 14.382865654657auto_explain log contains 955 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-ee-migration-pg14-no-gitaly-transactions-2-2.330.ci.ndjson.gz658took 12.151196617659[TEST PROF INFO] EventProf results for sql.active_record660Total time: 06:13.163 of 09:58.091 (62.39%)661Total events: 280562662Top 5 slowest suites (by time):663QueueUpdateWo...sConfigVersion (./ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb:6) – 02:11.103 (88068 / 1) of 03:14.965 (67.24%)664QueueUpdateWo...ConfigVersion3 (./ee/spec/migrations/20240104085448_queue_update_workspaces_config_version3_spec.rb:6) – 01:42.089 (71152 / 1) of 02:29.261 (68.4%)665QueuePurgeSec...ptyFindingData (./ee/spec/migrations/20240209153920_queue_purge_security_scans_with_empty_finding_data_spec.rb:6) – 01:40.826 (74271 / 6) of 02:58.182 (56.59%)666ResyncDirectU...tifactRegistry (./ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb:6) – 00:22.483 (26102 / 8) of 00:44.475 (50.55%)667MigrateLfsObj...parateRegistry (./ee/spec/migrations/geo/migrate_lfs_objects_to_separate_registry_spec.rb:6) – 00:16.660 (20969 / 5) of 00:31.206 (53.39%)668Knapsack report was generated. Preview:669{670 "ee/spec/migrations/20240209153920_queue_purge_security_scans_with_empty_finding_data_spec.rb": 113.869698384,671 "ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb": 97.83052196599965,672 "ee/spec/migrations/20240104085448_queue_update_workspaces_config_version3_spec.rb": 72.6320020259991,673 "ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb": 36.13124523499937,674 "ee/spec/migrations/geo/migrate_lfs_objects_to_separate_registry_spec.rb": 21.751680074999967675}676Knapsack global time execution for tests: 05m 42s677Finished in 10 minutes 32 seconds (files took 2 minutes 22.2 seconds to load)67821 examples, 0 failures679Randomized with seed 32135680[TEST PROF INFO] Time spent in factories: 00:00.073 (0.01% of total time)681RSpec exited with 0.682No examples to retry, congrats!684Running after script...685$ source scripts/utils.sh686$ bundle exec gem list gitlab_quality-test_tooling687gitlab_quality-test_tooling (1.33.0)688$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command692$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command695$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command699$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command702$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command706$ tooling/bin/push_job_metrics || true707[job-metrics] Pushing job metrics file for the CI/CD job.708[job-metrics] Pushed 4 CI job metric entries to InfluxDB.710Not uploading cache ruby-gems-debian-bookworm-ruby-3.1.5-17 due to policy712Uploading artifacts...713auto_explain/: found 3 matching artifact files and directories 714coverage/: found 5 matching artifact files and directories 715crystalball/: found 5 matching artifact files and directories 716WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab) 717knapsack/: found 4 matching artifact files and directories 718rspec/: found 12 matching artifact files and directories 719WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab) 720log/*.log: found 13 matching artifact files and directories 721WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7471346877/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com722WARNING: Retrying... context=artifacts-uploader error=request redirected723Uploading artifacts as "archive" to coordinator... 201 Created id=7471346877 responseStatus=201 Created token=glcbt-66724Uploading artifacts...725rspec/rspec-*.xml: found 1 matching artifact files and directories 726WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7471346877/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com727WARNING: Retrying... context=artifacts-uploader error=request redirected728Uploading artifacts as "junit" to coordinator... 201 Created id=7471346877 responseStatus=201 Created token=glcbt-66730Job succeeded