rspec-ee background_migration pg14 3/3
Passed Started
by
@tbulva
Tomas Bulva
215:29:59 on blue-6.private.runners-manager.gitlab.com/gitlab.com/gitlab-org mKJTFBei, system ID: s_90a66139ec06615:29:59Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...715:30:01Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...915:30:01Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...1015:30:01Using 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 ...1115:30:02WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.1215:30:02WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.1315:30:02Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12...1515:30:02Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...1615:30:02Using 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 ...1915:30:03Using docker image sha256:7de0dedd123b8cb2b105ace4e8d00b8bba5ad7be39617dfa229acff315fe4fbf for redis:6.2-alpine with digest redis@sha256:2d1463258f2764328496376f5d965f20c6a67f66ea2b06dc42af351f75248792 ...2015:30:04WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 is already created. Ignoring.2115:30:04WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 is already created. Ignoring.2415:30:04Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 ...2515:30:04Using 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 ...2815:30:05Using docker image sha256:5fad10241ffd65d817ed0ddfaf6e87eee1f7dc2a7db33db1047835560ea71fda for elasticsearch:7.17.6 with digest elasticsearch@sha256:6c128de5d01c0c130a806022d6bd99b3e4c27a9af5bfc33b6b81861ae117d028 ...2915:30:06Starting service registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:v1.15.0...3115:30:06Pulling docker image registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:v1.15.0 ...3215:30:06Using docker image sha256:a30dfbd70a5ce5c22a86589004a91775d1058abbf8fc0d6cf08a3024177a0d8e for registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:v1.15.0 with digest registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway@sha256:067593f7d33000df515b665f8e988768376e97b66123fdcf2e016e23e3a8c5f3 ...3415:30:39*** WARNING: Service runner-mkjtfbei-project-278964-concurrent-0-42257ddd94be0f18-elasticsearch-4 probably didn't start properly.3615:30:39service "runner-mkjtfbei-project-278964-concurrent-0-42257ddd94be0f18-elasticsearch-4-wait-for-service" timeout3815:30:392024-09-20T15:30:08.861412660Z waiting for TCP connection to c16ef72d0ac1 on [9200 9300]...10215:30:392024-09-20T15:30:18.123889181Z {"type": "server", "timestamp": "2024-09-20T15:30:18,087Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "version[7.17.6], pid[8], 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]" }10315:30:392024-09-20T15:30:18.125139161Z {"type": "server", "timestamp": "2024-09-20T15:30:18,124Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "JVM home [/usr/share/elasticsearch/jdk], using bundled JDK [true]" }10415:30:392024-09-20T15:30:18.125337391Z {"type": "server", "timestamp": "2024-09-20T15:30:18,124Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "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-51689093383713125, -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]" }10515:30:392024-09-20T15:30:25.775157261Z {"type": "server", "timestamp": "2024-09-20T15:30:25,774Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [aggs-matrix-stats]" }10615:30:392024-09-20T15:30:25.775856541Z {"type": "server", "timestamp": "2024-09-20T15:30:25,775Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [analysis-common]" }10715:30:392024-09-20T15:30:25.776668381Z {"type": "server", "timestamp": "2024-09-20T15:30:25,775Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [constant-keyword]" }10815:30:392024-09-20T15:30:25.777025281Z {"type": "server", "timestamp": "2024-09-20T15:30:25,776Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [frozen-indices]" }10915:30:392024-09-20T15:30:25.783041680Z {"type": "server", "timestamp": "2024-09-20T15:30:25,777Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [ingest-common]" }11015:30:392024-09-20T15:30:25.783536740Z {"type": "server", "timestamp": "2024-09-20T15:30:25,783Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [ingest-geoip]" }11115:30:392024-09-20T15:30:25.783887989Z {"type": "server", "timestamp": "2024-09-20T15:30:25,783Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [ingest-user-agent]" }11215:30:392024-09-20T15:30:25.784243420Z {"type": "server", "timestamp": "2024-09-20T15:30:25,783Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [kibana]" }11315:30:392024-09-20T15:30:25.784578160Z {"type": "server", "timestamp": "2024-09-20T15:30:25,784Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [lang-expression]" }11415:30:392024-09-20T15:30:25.785020340Z {"type": "server", "timestamp": "2024-09-20T15:30:25,784Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [lang-mustache]" }11515:30:392024-09-20T15:30:25.785370789Z {"type": "server", "timestamp": "2024-09-20T15:30:25,785Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [lang-painless]" }11615:30:392024-09-20T15:30:25.785901339Z {"type": "server", "timestamp": "2024-09-20T15:30:25,785Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [legacy-geo]" }11715:30:392024-09-20T15:30:25.786253419Z {"type": "server", "timestamp": "2024-09-20T15:30:25,785Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [mapper-extras]" }11815:30:392024-09-20T15:30:25.786685739Z {"type": "server", "timestamp": "2024-09-20T15:30:25,786Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [mapper-version]" }11915:30:392024-09-20T15:30:25.786999619Z {"type": "server", "timestamp": "2024-09-20T15:30:25,786Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [parent-join]" }12015:30:392024-09-20T15:30:25.787684989Z {"type": "server", "timestamp": "2024-09-20T15:30:25,787Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [percolator]" }12115:30:392024-09-20T15:30:25.788181709Z {"type": "server", "timestamp": "2024-09-20T15:30:25,787Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [rank-eval]" }12215:30:392024-09-20T15:30:25.788517569Z {"type": "server", "timestamp": "2024-09-20T15:30:25,788Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [reindex]" }12315:30:392024-09-20T15:30:25.788910279Z {"type": "server", "timestamp": "2024-09-20T15:30:25,788Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [repositories-metering-api]" }12415:30:392024-09-20T15:30:25.789182289Z {"type": "server", "timestamp": "2024-09-20T15:30:25,788Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [repository-encrypted]" }12515:30:392024-09-20T15:30:25.789966199Z {"type": "server", "timestamp": "2024-09-20T15:30:25,789Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [repository-url]" }12615:30:392024-09-20T15:30:25.790467799Z {"type": "server", "timestamp": "2024-09-20T15:30:25,789Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [runtime-fields-common]" }12715:30:392024-09-20T15:30:25.790819979Z {"type": "server", "timestamp": "2024-09-20T15:30:25,790Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [search-business-rules]" }12815:30:392024-09-20T15:30:25.791117909Z {"type": "server", "timestamp": "2024-09-20T15:30:25,790Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [searchable-snapshots]" }12915:30:392024-09-20T15:30:25.791428869Z {"type": "server", "timestamp": "2024-09-20T15:30:25,791Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [snapshot-repo-test-kit]" }13015:30:392024-09-20T15:30:25.791773339Z {"type": "server", "timestamp": "2024-09-20T15:30:25,791Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [spatial]" }13115:30:392024-09-20T15:30:25.792048148Z {"type": "server", "timestamp": "2024-09-20T15:30:25,791Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [transform]" }13215:30:392024-09-20T15:30:25.792318779Z {"type": "server", "timestamp": "2024-09-20T15:30:25,791Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [transport-netty4]" }13315:30:392024-09-20T15:30:25.792598719Z {"type": "server", "timestamp": "2024-09-20T15:30:25,792Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [unsigned-long]" }13415:30:392024-09-20T15:30:25.792837928Z {"type": "server", "timestamp": "2024-09-20T15:30:25,792Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [vector-tile]" }13515:30:392024-09-20T15:30:25.793121188Z {"type": "server", "timestamp": "2024-09-20T15:30:25,792Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [vectors]" }13615:30:392024-09-20T15:30:25.793390048Z {"type": "server", "timestamp": "2024-09-20T15:30:25,793Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [wildcard]" }13715:30:392024-09-20T15:30:25.793664958Z {"type": "server", "timestamp": "2024-09-20T15:30:25,793Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-aggregate-metric]" }13815:30:392024-09-20T15:30:25.793934158Z {"type": "server", "timestamp": "2024-09-20T15:30:25,793Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-analytics]" }13915:30:392024-09-20T15:30:25.794213808Z {"type": "server", "timestamp": "2024-09-20T15:30:25,793Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-async]" }14015:30:392024-09-20T15:30:25.794501388Z {"type": "server", "timestamp": "2024-09-20T15:30:25,794Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-async-search]" }14115:30:392024-09-20T15:30:25.794764568Z {"type": "server", "timestamp": "2024-09-20T15:30:25,794Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-autoscaling]" }14215:30:392024-09-20T15:30:25.795021878Z {"type": "server", "timestamp": "2024-09-20T15:30:25,794Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-ccr]" }14315:30:392024-09-20T15:30:25.795327738Z {"type": "server", "timestamp": "2024-09-20T15:30:25,794Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-core]" }14415:30:392024-09-20T15:30:25.795607338Z {"type": "server", "timestamp": "2024-09-20T15:30:25,795Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-data-streams]" }14515:30:392024-09-20T15:30:25.795883838Z {"type": "server", "timestamp": "2024-09-20T15:30:25,795Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-deprecation]" }14615:30:392024-09-20T15:30:25.796139128Z {"type": "server", "timestamp": "2024-09-20T15:30:25,795Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-enrich]" }14715:30:392024-09-20T15:30:25.796395728Z {"type": "server", "timestamp": "2024-09-20T15:30:25,796Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-eql]" }14815:30:392024-09-20T15:30:25.796660478Z {"type": "server", "timestamp": "2024-09-20T15:30:25,796Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-fleet]" }14915:30:392024-09-20T15:30:25.796926468Z {"type": "server", "timestamp": "2024-09-20T15:30:25,796Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-graph]" }15015:30:392024-09-20T15:30:25.797247188Z {"type": "server", "timestamp": "2024-09-20T15:30:25,796Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-identity-provider]" }15115:30:392024-09-20T15:30:25.797559618Z {"type": "server", "timestamp": "2024-09-20T15:30:25,797Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-ilm]" }15215:30:392024-09-20T15:30:25.797812918Z {"type": "server", "timestamp": "2024-09-20T15:30:25,797Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-logstash]" }15315:30:392024-09-20T15:30:25.798074048Z {"type": "server", "timestamp": "2024-09-20T15:30:25,797Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-ml]" }15415:30:392024-09-20T15:30:25.798384878Z {"type": "server", "timestamp": "2024-09-20T15:30:25,798Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-monitoring]" }15515:30:392024-09-20T15:30:25.798667908Z {"type": "server", "timestamp": "2024-09-20T15:30:25,798Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-ql]" }15615:30:392024-09-20T15:30:25.798917098Z {"type": "server", "timestamp": "2024-09-20T15:30:25,798Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-rollup]" }15715:30:392024-09-20T15:30:25.799170038Z {"type": "server", "timestamp": "2024-09-20T15:30:25,798Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-security]" }15815:30:392024-09-20T15:30:25.799467598Z {"type": "server", "timestamp": "2024-09-20T15:30:25,799Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-shutdown]" }15915:30:392024-09-20T15:30:25.799719158Z {"type": "server", "timestamp": "2024-09-20T15:30:25,799Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-sql]" }16015:30:392024-09-20T15:30:25.799975887Z {"type": "server", "timestamp": "2024-09-20T15:30:25,799Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-stack]" }16115:30:392024-09-20T15:30:25.800252518Z {"type": "server", "timestamp": "2024-09-20T15:30:25,799Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-text-structure]" }16215:30:392024-09-20T15:30:25.800527778Z {"type": "server", "timestamp": "2024-09-20T15:30:25,800Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-voting-only-node]" }16315:30:392024-09-20T15:30:25.800777597Z {"type": "server", "timestamp": "2024-09-20T15:30:25,800Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "loaded module [x-pack-watcher]" }16415:30:392024-09-20T15:30:25.801554207Z {"type": "server", "timestamp": "2024-09-20T15:30:25,801Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "no plugins loaded" }16515:30:392024-09-20T15:30:25.949741197Z {"type": "server", "timestamp": "2024-09-20T15:30:25,948Z", "level": "INFO", "component": "o.e.e.NodeEnvironment", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "using [1] data paths, mounts [[/ (overlay)]], net usable_space [72gb], net total_space [94.2gb], types [overlay]" }16615:30:392024-09-20T15:30:25.950538027Z {"type": "server", "timestamp": "2024-09-20T15:30:25,950Z", "level": "INFO", "component": "o.e.e.NodeEnvironment", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "heap size [256mb], compressed ordinary object pointers [true]" }16715:30:392024-09-20T15:30:25.994711892Z {"type": "server", "timestamp": "2024-09-20T15:30:25,994Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "node name [c16ef72d0ac1], node ID [MXnex3uqT6qtYGFYDTQfmg], cluster name [docker-cluster], roles [transform, data_frozen, master, remote_cluster_client, data, ml, data_content, data_hot, data_warm, data_cold, ingest]" }16815:30:392024-09-20T15:30:39.160057205Z {"type": "server", "timestamp": "2024-09-20T15:30:39,159Z", "level": "INFO", "component": "o.e.x.m.p.l.CppLogMessageHandler", "cluster.name": "docker-cluster", "node.name": "c16ef72d0ac1", "message": "[controller/211] [Main.cc@122] controller (64 bit): Version 7.17.6 (Build ea0305ae2a3b09) Copyright (c) 2022 Elasticsearch BV" }17115:30:39Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...17215:30:40Using docker image sha256:72c427a29f80c5ff14e5cd83601d7507c7de71ce18b2ccd8a04667fdd0d6aba0 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.45-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.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14@sha256:ba1a3d49eae4bc906535413ec79e7efdb3497247de3e53f23a928039672611a1 ...17415:30:40Running on runner-mkjtfbei-project-278964-concurrent-0 via runner-mkjtfbei-private-1726819986-f51b2bd6...18115:30:42Downloading cache from https://storage.googleapis.com/gitlab-com-runners-cache/project/278964/ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-19 ETag="d6173d7713ba56a585725be3648044d8"18515:31:13Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7879697722 responseStatus=200 OK token=glcbt-6618915:31:29Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7879697836 responseStatus=200 OK token=glcbt-6619115:31:33Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7879697861 responseStatus=200 OK token=glcbt-6619315:31:39Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7879697871 responseStatus=200 OK token=glcbt-6619515:31:43Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7879697842 responseStatus=200 OK token=glcbt-6619715:31:53Using docker image sha256:72c427a29f80c5ff14e5cd83601d7507c7de71ce18b2ccd8a04667fdd0d6aba0 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.45-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.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14@sha256:ba1a3d49eae4bc906535413ec79e7efdb3497247de3e53f23a928039672611a1 ...19915:31:53$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb32215:33:28$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"33115:33:36$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"33715:33:36KNAPSACK_TEST_FILE_PATTERN: {ee/}spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb34115:33:36FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec-ee_background_migration_pg14_3_3_278964_report.json34215:33:36NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec-ee_background_migration_pg14_3_3_278964_report.json35315:33:36/builds/gitlab-org/gitlab/vendor/ruby/3.2.0/gems/io-event-1.6.5/lib/io/event/support.rb:27: warning: IO::Buffer is experimental and both the Ruby and C interface may change in the future!35415:34:46warning: parser/current is loading parser/ruby32, which recognizes 3.2.4-compliant syntax, but you are running 3.2.5.35615:35:02/builds/gitlab-org/gitlab/vendor/ruby/3.2.0/gems/io-event-1.6.5/lib/io/event/support.rb:27: warning: IO::Buffer is experimental and both the Ruby and C interface may change in the future!36015:35:49unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.36115:35:50unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.36315:35:57# [RSpecRunTime] Starting example group ee/spec/lib/ee/gitlab/background_migration/backfill_project_statistics_storage_size_without_pipeline_artifacts_size_job_spec.rb. Expected to take 2 minutes 34.77 seconds.36415:35:57Gitlab::BackgroundMigration::BackfillProjectStatisticsStorageSizeWithoutPipelineArtifactsSizeJob37115:38:23# [RSpecRunTime] RSpec elapsed time: 2 minutes 33.27 seconds. Current RSS: ~1207M. Threads: 1. load average: 1.04 1.23 1.27 1/392 39837515:38:41INFO: "ci_runner_machine_builds_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows37715:38:41INFO: "ci_runner_machine_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows37915:38:41INFO: "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows38215:38:41INFO: "ci_job_annotations_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows38415:38:41INFO: "ci_job_annotations_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows38615:38:41INFO: "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows38915:38:41INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows39115:38:41INFO: "ci_builds_metadata_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows39315:38:41INFO: "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows39615:38:41INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows39815:38:41INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows40015:38:41INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows40115:38:41I, [2024-09-20T15:38:41.997918 #333] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes40215:39:03I, [2024-09-20T15:39:03.244789 #333] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes40515:39:04INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows40615:39:04I, [2024-09-20T15:39:04.910339 #333] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes40715:39:04I, [2024-09-20T15:39:04.911619 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}40815:39:04I, [2024-09-20T15:39:04.912517 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}41115:39:06INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows41415:39:11INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows41515:39:11I, [2024-09-20T15:39:11.353525 #333] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes41615:39:11I, [2024-09-20T15:39:11.354671 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}41715:39:11I, [2024-09-20T15:39:11.355531 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}42015:39:14INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows42115:39:14I, [2024-09-20T15:39:14.809761 #333] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes42215:39:14I, [2024-09-20T15:39:14.810952 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}42315:39:14I, [2024-09-20T15:39:14.811801 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}42415:39:16I, [2024-09-20T15:39:16.018481 #333] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes42515:39:22I, [2024-09-20T15:39:22.833707 #333] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes42615:39:37I, [2024-09-20T15:39:37.537390 #333] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes42715:39:37I, [2024-09-20T15:39:37.538761 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}42815:39:37I, [2024-09-20T15:39:37.539714 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}42915:39:50I, [2024-09-20T15:39:50.741530 #333] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes43015:39:58I, [2024-09-20T15:39:58.082663 #333] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes43115:40:06I, [2024-09-20T15:40:06.584449 #333] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes43215:40:09I, [2024-09-20T15:40:09.365547 #333] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes43515:40:13INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows43615:40:13I, [2024-09-20T15:40:13.466639 #333] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes43715:40:13I, [2024-09-20T15:40:13.467759 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}43815:40:13I, [2024-09-20T15:40:13.468526 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}43915:40:19I, [2024-09-20T15:40:19.769499 #333] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes44015:40:31# [RSpecRunTime] Finishing example group ee/spec/lib/ee/gitlab/background_migration/backfill_project_statistics_storage_size_without_pipeline_artifacts_size_job_spec.rb. It took 4 minutes 33.94 seconds. Expected to take 2 minutes 34.77 seconds.44115:40:31# [RSpecRunTime] RSpec elapsed time: 4 minutes 41.36 seconds. Current RSS: ~1212M. Threads: 1. load average: 0.95 1.14 1.23 1/390 39944315:40:31# [RSpecRunTime] Starting example group ee/spec/lib/ee/gitlab/background_migration/delete_orphaned_transferred_project_approval_rules_spec.rb. Expected to take 2 minutes 30.18 seconds.44815:42:51# [RSpecRunTime] RSpec elapsed time: 7 minutes 1.28 seconds. Current RSS: ~1221M. Threads: 1. load average: 1.23 1.20 1.25 1/392 40045215:43:08INFO: "ci_runner_machine_builds_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows45415:43:08INFO: "ci_runner_machine_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows45615:43:08INFO: "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows45915:43:08INFO: "ci_job_annotations_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows46115:43:08INFO: "ci_job_annotations_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows46315:43:08INFO: "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows46615:43:08INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows46815:43:08INFO: "ci_builds_metadata_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows47015:43:08INFO: "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows47315:43:08INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows47515:43:08INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows47715:43:08INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows47815:43:09I, [2024-09-20T15:43:09.078048 #333] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes47915:43:30I, [2024-09-20T15:43:30.825189 #333] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes48215:43:32INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows48315:43:32I, [2024-09-20T15:43:32.565816 #333] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes48415:43:32I, [2024-09-20T15:43:32.566980 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}48515:43:32I, [2024-09-20T15:43:32.567808 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}48815:43:34INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows49115:43:39INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows49215:43:39I, [2024-09-20T15:43:39.278437 #333] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes49315:43:39I, [2024-09-20T15:43:39.279652 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}49415:43:39I, [2024-09-20T15:43:39.280602 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}49715:43:42INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows49815:43:42I, [2024-09-20T15:43:42.748494 #333] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes49915:43:42I, [2024-09-20T15:43:42.749907 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}50015:43:42I, [2024-09-20T15:43:42.750881 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}50115:43:44I, [2024-09-20T15:43:44.113974 #333] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes50215:43:51I, [2024-09-20T15:43:51.272487 #333] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes50315:44:05I, [2024-09-20T15:44:05.470925 #333] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes50415:44:05I, [2024-09-20T15:44:05.472117 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}50515:44:05I, [2024-09-20T15:44:05.472911 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}50615:44:18I, [2024-09-20T15:44:18.297535 #333] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes50715:44:25I, [2024-09-20T15:44:25.786513 #333] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes50815:44:34I, [2024-09-20T15:44:34.217507 #333] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes50915:44:37I, [2024-09-20T15:44:37.026241 #333] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes51215:44:41INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows51315:44:41I, [2024-09-20T15:44:41.210316 #333] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes51415:44:41I, [2024-09-20T15:44:41.211726 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}51515:44:41I, [2024-09-20T15:44:41.212612 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}51615:44:46I, [2024-09-20T15:44:46.954685 #333] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes51715:44:58# [RSpecRunTime] Finishing example group ee/spec/lib/ee/gitlab/background_migration/delete_orphaned_transferred_project_approval_rules_spec.rb. It took 4 minutes 27.29 seconds. Expected to take 2 minutes 30.18 seconds.51815:44:58# [RSpecRunTime] RSpec elapsed time: 9 minutes 8.7 seconds. Current RSS: ~1221M. Threads: 1. load average: 1.22 1.17 1.23 1/393 40152015:44:58# [RSpecRunTime] Starting example group ee/spec/lib/ee/gitlab/background_migration/migrate_approver_to_approval_rules_spec.rb. Expected to take 2 minutes 1.96 seconds.52915:45:11# [RSpecRunTime] RSpec elapsed time: 9 minutes 21.72 seconds. Current RSS: ~1255M. Threads: 4. load average: 1.17 1.16 1.22 1/405 41453315:45:18# [RSpecRunTime] RSpec elapsed time: 9 minutes 28.88 seconds. Current RSS: ~1264M. Threads: 4. load average: 1.15 1.16 1.22 1/405 41553715:45:25# [RSpecRunTime] RSpec elapsed time: 9 minutes 35.19 seconds. Current RSS: ~1253M. Threads: 4. load average: 1.14 1.16 1.22 1/405 41654115:45:30# [RSpecRunTime] RSpec elapsed time: 9 minutes 41.06 seconds. Current RSS: ~1246M. Threads: 4. load average: 1.12 1.15 1.22 1/405 41754515:45:36# [RSpecRunTime] RSpec elapsed time: 9 minutes 46.76 seconds. Current RSS: ~1252M. Threads: 4. load average: 1.19 1.17 1.22 1/405 41854915:45:42# [RSpecRunTime] RSpec elapsed time: 9 minutes 52.76 seconds. Current RSS: ~1254M. Threads: 4. load average: 1.25 1.18 1.23 1/405 41955315:45:48# [RSpecRunTime] RSpec elapsed time: 9 minutes 58.6 seconds. Current RSS: ~1257M. Threads: 4. load average: 1.31 1.19 1.23 1/405 42055715:45:54# [RSpecRunTime] RSpec elapsed time: 10 minutes 4.34 seconds. Current RSS: ~1264M. Threads: 4. load average: 1.37 1.21 1.23 1/405 42156215:46:01# [RSpecRunTime] RSpec elapsed time: 10 minutes 11.16 seconds. Current RSS: ~1273M. Threads: 4. load average: 1.23 1.18 1.23 1/406 45356615:46:06# [RSpecRunTime] RSpec elapsed time: 10 minutes 16.76 seconds. Current RSS: ~1257M. Threads: 4. load average: 1.13 1.16 1.22 1/406 45457215:46:17# [RSpecRunTime] RSpec elapsed time: 10 minutes 28.1 seconds. Current RSS: ~1256M. Threads: 4. load average: 1.19 1.18 1.22 1/406 45558015:46:29# [RSpecRunTime] RSpec elapsed time: 10 minutes 39.3 seconds. Current RSS: ~1263M. Threads: 4. load average: 1.15 1.17 1.22 1/406 45658415:46:35# [RSpecRunTime] RSpec elapsed time: 10 minutes 45.52 seconds. Current RSS: ~1276M. Threads: 4. load average: 1.22 1.18 1.22 1/406 45758815:46:41# [RSpecRunTime] RSpec elapsed time: 10 minutes 51.48 seconds. Current RSS: ~1258M. Threads: 4. load average: 1.35 1.21 1.23 1/406 45859215:46:47# [RSpecRunTime] RSpec elapsed time: 10 minutes 57.35 seconds. Current RSS: ~1255M. Threads: 4. load average: 1.32 1.21 1.23 1/406 45959615:46:53# [RSpecRunTime] RSpec elapsed time: 11 minutes 4.09 seconds. Current RSS: ~1260M. Threads: 4. load average: 1.21 1.19 1.22 1/406 46059815:47:04# [RSpecRunTime] Finishing example group ee/spec/lib/ee/gitlab/background_migration/migrate_approver_to_approval_rules_spec.rb. It took 2 minutes 6.17 seconds. Expected to take 2 minutes 1.96 seconds.59915:47:04# [RSpecRunTime] RSpec elapsed time: 11 minutes 14.92 seconds. Current RSS: ~1239M. Threads: 4. load average: 1.18 1.18 1.22 1/406 46160115:47:04# [RSpecRunTime] Starting example group ee/spec/lib/ee/gitlab/background_migration/migrate_vulnerabilities_feedback_to_vulnerabilities_state_transition_spec.rb. Expected to take 1 minute 34.54 seconds.60215:47:04Gitlab::BackgroundMigration::MigrateVulnerabilitiesFeedbackToVulnerabilitiesStateTransition61015:47:24# [RSpecRunTime] RSpec elapsed time: 11 minutes 34.5 seconds. Current RSS: ~1251M. Threads: 4. load average: 1.13 1.17 1.22 1/406 46261815:47:45# [RSpecRunTime] RSpec elapsed time: 11 minutes 55.35 seconds. Current RSS: ~1237M. Threads: 4. load average: 1.24 1.19 1.22 1/406 46362215:47:50# [RSpecRunTime] RSpec elapsed time: 12 minutes 0.57 second. Current RSS: ~1239M. Threads: 4. load average: 1.22 1.18 1.22 1/407 46462915:48:03# [RSpecRunTime] RSpec elapsed time: 12 minutes 13.96 seconds. Current RSS: ~1238M. Threads: 4. load average: 1.31 1.21 1.23 1/406 46563515:48:12# [RSpecRunTime] RSpec elapsed time: 12 minutes 22.83 seconds. Current RSS: ~1239M. Threads: 4. load average: 1.41 1.23 1.23 1/406 46664115:48:21# [RSpecRunTime] RSpec elapsed time: 12 minutes 31.85 seconds. Current RSS: ~1240M. Threads: 4. load average: 1.50 1.26 1.24 1/406 46764715:48:30# [RSpecRunTime] RSpec elapsed time: 12 minutes 41.0 seconds. Current RSS: ~1242M. Threads: 4. load average: 1.50 1.27 1.25 1/406 46864915:48:41# [RSpecRunTime] Finishing example group ee/spec/lib/ee/gitlab/background_migration/migrate_vulnerabilities_feedback_to_vulnerabilities_state_transition_spec.rb. It took 1 minute 36.76 seconds. Expected to take 1 minute 34.54 seconds.65015:48:41# [RSpecRunTime] RSpec elapsed time: 12 minutes 51.73 seconds. Current RSS: ~1235M. Threads: 4. load average: 1.34 1.24 1.24 1/406 46965215:48:41# [RSpecRunTime] Starting example group ee/spec/lib/ee/gitlab/background_migration/delete_invalid_epic_issues_spec.rb. Expected to take 1 minute 7.96 seconds.65815:49:42# [RSpecRunTime] RSpec elapsed time: 13 minutes 52.61 seconds. Current RSS: ~1249M. Threads: 4. load average: 1.14 1.20 1.22 1/406 47066015:49:44I, [2024-09-20T15:49:44.778983 #333] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes66115:49:44I, [2024-09-20T15:49:44.780133 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}66215:49:44I, [2024-09-20T15:49:44.781111 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}66315:49:56I, [2024-09-20T15:49:56.700017 #333] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes66415:50:04I, [2024-09-20T15:50:04.004106 #333] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes66515:50:12I, [2024-09-20T15:50:12.609265 #333] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes66615:50:15I, [2024-09-20T15:50:15.503054 #333] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes66915:50:19INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows67015:50:19I, [2024-09-20T15:50:19.707286 #333] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes67115:50:19I, [2024-09-20T15:50:19.708605 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}67215:50:19I, [2024-09-20T15:50:19.709559 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}67315:50:25I, [2024-09-20T15:50:25.566756 #333] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes67415:50:36# [RSpecRunTime] Finishing example group ee/spec/lib/ee/gitlab/background_migration/delete_invalid_epic_issues_spec.rb. It took 1 minute 54.98 seconds. Expected to take 1 minute 7.96 seconds.67515:50:36# [RSpecRunTime] RSpec elapsed time: 14 minutes 46.76 seconds. Current RSS: ~1252M. Threads: 4. load average: 1.11 1.18 1.21 1/405 47167715:50:36# [RSpecRunTime] Starting example group ee/spec/lib/ee/gitlab/background_migration/backfill_zoekt_replicas_spec.rb. Expected to take 34.88 seconds.68115:51:14I, [2024-09-20T15:51:14.290546 #333] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes68215:51:23I, [2024-09-20T15:51:23.912971 #333] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes68315:51:26I, [2024-09-20T15:51:26.689685 #333] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes68615:51:30INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows68715:51:30I, [2024-09-20T15:51:30.954718 #333] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes68815:51:30I, [2024-09-20T15:51:30.955940 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}68915:51:30I, [2024-09-20T15:51:30.956789 #333] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}69015:51:36I, [2024-09-20T15:51:36.841215 #333] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes69115:51:47# [RSpecRunTime] Finishing example group ee/spec/lib/ee/gitlab/background_migration/backfill_zoekt_replicas_spec.rb. It took 1 minute 11.16 seconds. Expected to take 34.88 seconds.69215:51:47# [RSpecRunTime] RSpec elapsed time: 15 minutes 57.98 seconds. Current RSS: ~1246M. Threads: 4. load average: 1.40 1.26 1.24 1/405 47269415:51:47# [RSpecRunTime] Starting example group ee/spec/lib/gitlab/background_migration/update_workspaces_config_version3_spec.rb. Expected to take 10.21 seconds.69715:51:52 updates config_version and force_include_all_resources for existing non-terminated workspaces69915:51:57# [RSpecRunTime] RSpec elapsed time: 16 minutes 7.45 seconds. Current RSS: ~1244M. Threads: 4. load average: 1.49 1.28 1.24 1/405 47370115:52:07# [RSpecRunTime] Finishing example group ee/spec/lib/gitlab/background_migration/update_workspaces_config_version3_spec.rb. It took 19.98 seconds. Expected to take 10.21 seconds.70215:52:07# [RSpecRunTime] RSpec elapsed time: 16 minutes 18.01 seconds. Current RSS: ~1233M. Threads: 4. load average: 1.50 1.29 1.25 1/405 47470415:52:07# [RSpecRunTime] Starting example group ee/spec/lib/ee/gitlab/background_migration/migrate_approver_to_approval_rules_in_batch_spec.rb. Expected to take 10.12 seconds.70815:52:17# [RSpecRunTime] RSpec elapsed time: 16 minutes 27.19 seconds. Current RSS: ~1312M. Threads: 4. load average: 1.42 1.28 1.24 1/408 60271015:52:27# [RSpecRunTime] Finishing example group ee/spec/lib/ee/gitlab/background_migration/migrate_approver_to_approval_rules_in_batch_spec.rb. It took 19.63 seconds. Expected to take 10.12 seconds.71115:52:27# [RSpecRunTime] RSpec elapsed time: 16 minutes 37.69 seconds. Current RSS: ~1232M. Threads: 4. load average: 1.36 1.27 1.24 1/408 60371315:52:27# [RSpecRunTime] Starting example group ee/spec/lib/ee/gitlab/background_migration/set_project_vulnerability_count_spec.rb. Expected to take 6.34 seconds.71615:52:42# [RSpecRunTime] Finishing example group ee/spec/lib/ee/gitlab/background_migration/set_project_vulnerability_count_spec.rb. It took 15.22 seconds. Expected to take 6.34 seconds.71715:52:42# [RSpecRunTime] RSpec elapsed time: 16 minutes 53.03 seconds. Current RSS: ~1237M. Threads: 4. load average: 1.41 1.29 1.25 1/408 60471915:52:42# [RSpecRunTime] Starting example group ee/spec/lib/ee/gitlab/background_migration/sync_scan_result_policies_spec.rb. Expected to take 4.93 seconds.72315:52:47# [RSpecRunTime] RSpec elapsed time: 16 minutes 57.67 seconds. Current RSS: ~1252M. Threads: 4. load average: 1.38 1.28 1.25 1/408 60572515:52:57# [RSpecRunTime] Finishing example group ee/spec/lib/ee/gitlab/background_migration/sync_scan_result_policies_spec.rb. It took 15.05 seconds. Expected to take 4.93 seconds.72615:52:58# [RSpecRunTime] RSpec elapsed time: 17 minutes 8.14 seconds. Current RSS: ~1240M. Threads: 4. load average: 1.24 1.26 1.24 1/408 60672815:53:20auto_explain log contains 1228 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-ee-background-migration-pg14-3-3.333.main.ndjson.gz73015:53:41auto_explain log contains 1229 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-ee-background-migration-pg14-3-3.333.ci.ndjson.gz73615:53:41Gitlab::Backg...tifactsSizeJob (./ee/spec/lib/ee/gitlab/background_migration/backfill_project_statistics_storage_size_without_pipeline_artifacts_size_job_spec.rb:5) – 03:02.288 (113540 / 2) of 04:33.911 (66.55%)73715:53:41Gitlab::Backg...tApprovalRules (./ee/spec/lib/ee/gitlab/background_migration/delete_orphaned_transferred_project_approval_rules_spec.rb:5) – 02:59.688 (111821 / 2) of 04:27.338 (67.21%)73815:53:41Gitlab::Backg...alidEpicIssues (./ee/spec/lib/ee/gitlab/background_migration/delete_invalid_epic_issues_spec.rb:6) – 01:14.598 (50227 / 3) of 01:55.031 (64.85%)73915:53:41Gitlab::Backg...oApprovalRules (./ee/spec/lib/ee/gitlab/background_migration/migrate_approver_to_approval_rules_spec.rb:6) – 00:52.367 (56033 / 19) of 02:06.219 (41.49%)74015:53:41Gitlab::Backg...lZoektReplicas (./ee/spec/lib/ee/gitlab/background_migration/backfill_zoekt_replicas_spec.rb:5) – 00:47.432 (32207 / 2) of 01:11.213 (66.61%)74315:53:41 "ee/spec/lib/ee/gitlab/background_migration/backfill_project_statistics_storage_size_without_pipeline_artifacts_size_job_spec.rb": 146.3067330390004,74415:53:41 "ee/spec/lib/ee/gitlab/background_migration/delete_orphaned_transferred_project_approval_rules_spec.rb": 139.94315244500103,74515:53:41 "ee/spec/lib/ee/gitlab/background_migration/migrate_approver_to_approval_rules_spec.rb": 115.39723536800011,74615:53:41 "ee/spec/lib/ee/gitlab/background_migration/migrate_vulnerabilities_feedback_to_vulnerabilities_state_transition_spec.rb": 86.10404748899964,74715:53:41 "ee/spec/lib/ee/gitlab/background_migration/delete_invalid_epic_issues_spec.rb": 60.895062624000275,74815:53:41 "ee/spec/lib/ee/gitlab/background_migration/backfill_zoekt_replicas_spec.rb": 34.25808770900039,74915:53:41 "ee/spec/lib/gitlab/background_migration/update_workspaces_config_version3_spec.rb": 9.495319126002869,75015:53:41 "ee/spec/lib/ee/gitlab/background_migration/migrate_approver_to_approval_rules_in_batch_spec.rb": 9.193393885998375,75115:53:41 "ee/spec/lib/ee/gitlab/background_migration/set_project_vulnerability_count_spec.rb": 5.054174389999389,75215:53:41 "ee/spec/lib/ee/gitlab/background_migration/sync_scan_result_policies_spec.rb": 4.65375472999949182415:54:00$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command82715:54:00$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command83315:54:00$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command83715:54:02$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command84515:54:10Not uploading cache ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-19 due to policy85115:54:11WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab) 85415:54:11WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab) 85615:54:12WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7879699800/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com85815:54:14Uploading artifacts as "archive" to coordinator... 201 Created id=7879699800 responseStatus=201 Created token=glcbt-6686115:54:14WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7879699800/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com86315:54:27Uploading artifacts as "junit" to coordinator... 201 Created id=7879699800 responseStatus=201 Created token=glcbt-66