search

opea-project / GenAIComps

GenAI components at micro-service level; GenAI service composer to create mega-service
Apache License 2.0
160 stars 198 forks source link

[Bug] Milvus microservice throwing a "context deadline exceeded" error #1564

Closed siddhivelankar23 closed 2 days ago

siddhivelankar23 commented 2 months ago

Priority

P3-Medium

OS type

Ubuntu

Hardware type

Xeon-EMR

Installation method

Deploy method

Running nodes

Single Node

What's the version?

N/A

Description

Context deadline exceeded error while running milvus

Reproduce steps

https://github.com/opea-project/GenAIComps/tree/main/comps/third_parties/milvus/src

Raw log

docker compose milvus-standalone error [2025/04/11 17:03:46.577 +00:00] [DEBUG] [rootcoord/service.go:198] ["RootCoord connect to etcd failed"] [error="context deadline exceeded"] [2025/04/11 17:03:46.578 +00:00] [ERROR] [components/root_coord.go:55] ["RootCoord starts error"] [error="context deadline exceeded"] [stack="github.com/milvus-io/milvus/cmd/components.(*RootCoord).Run\n\t/workspace/source/cmd/components/root_coord.go:55\ngithub.com/milvus-io/milvus/cmd/roles.runComponent[...].func1\n\t/workspace/source/cmd/roles/roles.go:114"]

Attachments

No response

mkbhanda commented 2 months ago

This is a big puzzling, the milvus compose file lists versioned images and not changed in 2 months. image: quay.io/coreos/etcd:v3.5.5 image: milvusdb/milvus:v2.4.6 image: minio/minio:RELEASE.2023-03-20T20-16-18Z

and the associated milvus.yaml not changed in 3 months.

When was the last time this combination was ever used/tested?

chensuyue commented 2 months ago

The latest Microservice test with milvus should be this one, and test pass, https://github.com/opea-project/GenAIComps/actions/runs/14370726185/job/40293209524.
Also the nightly example test pass: https://github.com/opea-project/GenAIExamples/actions/runs/14448514239/job/40515052691

mkbhanda commented 2 months ago

@chensuyue says tests all passing, @siddhivelankar23 what is different in your (or customer) environment? For the sake of argument could they test the lastest greatest. Were they earlier using a tagged release such as V1.2?

xiguiw commented 2 months ago

@siddhivelankar23

I did not run into any issues to start Milvus. Please check you environment.

GenAIComp main branch DOCKER_VOLUME_DIRECTORY is not set, use the default "." in compose.yaml.

(base) sdp@ce290db97ba0:~/xigui/GenAIComps/comps/third_parties/milvus/deployment/docker_compose$ docker compose up -d
[+] Running 24/24
 ✔ etcd Pulled                                                                                              12.7s
   ✔ dbba69284b27 Pull complete                                                                              8.7s
   ✔ 270b322b3c62 Pull complete                                                                              9.0s
   ✔ 7c21e2da1038 Pull complete                                                                              9.2s
   ✔ cb4f77bfee6c Pull complete                                                                              9.4s
   ✔ e5485096ca5d Pull complete                                                                              9.5s
   ✔ 3ea3736f61e1 Pull complete                                                                              9.5s
   ✔ 1e815a2c4f55 Pull complete                                                                              9.5s
 ✔ minio Pulled                                                                                              6.9s
   ✔ c7e856e03741 Pull complete                                                                              2.5s
   ✔ c1ff217ec952 Pull complete                                                                              2.5s
   ✔ b12cc8972a67 Pull complete                                                                              2.5s
   ✔ 4324e307ea00 Pull complete                                                                              2.5s
   ✔ 152089595ebc Pull complete                                                                              2.5s
   ✔ 05f217fb8612 Pull complete                                                                              4.7s
 ✔ standalone Pulled                                                                                        26.1s
   ✔ d5fd17ec1767 Pull complete                                                                              3.4s
   ✔ 85363d033edd Pull complete                                                                              5.4s
   ✔ 3afc5eab6fa2 Pull complete                                                                              7.6s
   ✔ 026164df1c1b Pull complete                                                                              7.7s
   ✔ c97efd2bfe20 Pull complete                                                                             23.9s
   ✔ 535376b75c84 Pull complete                                                                             23.9s
   ✔ eb2f8229d375 Pull complete                                                                             23.9s
   ✔ 4f4fb700ef54 Pull complete                                                                             23.9s
[+] Running 3/3
 ✔ Container milvus-etcd        Started                                                                      1.6s
 ✔ Container milvus-minio       Started                                                                      1.7s
 ✔ Container milvus-standalone  Started    

(base) sdp@ce290db97ba0:~/xigui/GenAIComps/comps/third_parties/milvus/deployment/docker_compose$ docker ps -a
CONTAINER ID   IMAGE                                                   COMMAND                  CREATED         STATUS                    PORTS                                                                                      NAMES
b3d726d1ac67   milvusdb/milvus:v2.4.6                                  "/tini -- milvus run…"   8 minutes ago   Up 8 minutes (healthy)    0.0.0.0:9091->9091/tcp, :::9091->9091/tcp, 0.0.0.0:19530->19530/tcp, :::19530->19530/tcp   milvus-standalone
17eb9b2ddf97   minio/minio:RELEASE.2023-03-20T20-16-18Z                "/usr/bin/docker-ent…"   8 minutes ago   Up 8 minutes (healthy)    0.0.0.0:5043->9000/tcp, :::5043->9000/tcp, 0.0.0.0:5044->9001/tcp, :::5044->9001/tcp       milvus-minio
3711452a4745   quay.io/coreos/etcd:v3.5.5                              "etcd -advertise-cli…"   8 minutes ago   Up 8 minutes (healthy)    2379-2380/tcp                                                                              milvus-etcd

docker images info:

milvusdb/milvus                                 v2.4.6                         636269526977   9 months ago    1.79GB
minio/minio                                     RELEASE.2023-03-20T20-16-18Z   400c20c8aac0   2 years ago     252MB
quay.io/coreos/etcd                             v3.5.5                         673f29d03de9   2 years ago     182MB

docker logs

(base) sdp@ce290db97ba0:~/xigui/GenAIComps/comps/third_parties/milvus/deployment/docker_compose$ docker logs milvus-standalone
[2025/04/16 03:42:51.905 +00:00] [INFO] [distance/calc_distance_amd64.go:14] ["Hook avx for go simd distance computation"]
2025/04/16 03:42:51 maxprocs: Leaving GOMAXPROCS=128: CPU quota undefined

    __  _________ _   ____  ______
   /  |/  /  _/ /| | / / / / / __/
  / /|_/ // // /_| |/ / /_/ /\ \
 /_/  /_/___/____/___/\____/___/

Welcome to use Milvus!
Version:   v2.4.6
Built:     Tue Jul 16 05:16:09 UTC 2024
GitCommit: ce9ab52
GoVersion: go version go1.21.10 linux/amd64

TotalMem: 540695515136
UsedMem: 39292928

open pid file: /run/milvus/standalone.pid
lock pid file: /run/milvus/standalone.pid
[2025/04/16 03:42:51.961 +00:00] [INFO] [roles/roles.go:307] ["starting running Milvus components"]
[2025/04/16 03:42:51.961 +00:00] [INFO] [roles/roles.go:170] ["Enable Jemalloc"] ["Jemalloc Path"=/milvus/lib/libjemalloc.so]
[2025/04/16 03:42:51.976 +00:00] [DEBUG] [config/refresher.go:67] ["start refreshing configurations"] [source=FileSource]
[2025/04/16 03:42:51.978 +00:00] [DEBUG] [config/etcd_source.go:52] ["init etcd source"] [etcdInfo="{\"UseEmbed\":false,\"EnableAuth\":false,\"UserName\":\"\",\"PassWord\":\"\",\"UseSSL\":false,\"Endpoints\":[\"etcd:2379\"],\"KeyPrefix\":\"by-dev\",\"CertFile\":\"/path/to/etcd-client.pem\",\"KeyFile\":\"/path/to/etcd-client-key.pem\",\"CaCertFile\":\"/path/to/ca.pem\",\"MinVersion\":\"1.3\",\"RefreshInterval\":5000000000}"]
[2025/04/16 03:42:51.979 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3]
[2025/04/16 03:42:51.984 +00:00] [DEBUG] [config/etcd_source.go:91] ["etcd refreshConfigurations"] [prefix=by-dev/config] [endpoints="[etcd:2379]"]
[2025/04/16 03:42:51.988 +00:00] [DEBUG] [config/refresher.go:67] ["start refreshing configurations"] [source=EtcdSource]
[2025/04/16 03:42:51.991 +00:00] [INFO] [paramtable/hook_config.go:21] ["hook config"] [hook={}]
[2025/04/16 03:42:51.991 +00:00] [DEBUG] [config/refresher.go:67] ["start refreshing configurations"] [source=FileSource]
[2025/04/16 03:42:51.992 +00:00] [INFO] [roles/roles.go:256] [setupPrometheusHTTPServer]
[2025/04/16 03:42:51.992 +00:00] [INFO] [http/server.go:152] ["management listen"] [addr=:9091]
[2025/04/16 03:42:51.992 +00:00] [INFO] [rootcoord/root_coord.go:154] ["update rootcoord state"] [state=Abnormal]
[2025/04/16 03:42:51.992 +00:00] [DEBUG] [rootcoord/service.go:184] ["init params done.."]
[2025/04/16 03:42:51.992 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3]
[2025/04/16 03:42:51.992 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3]
[2025/04/16 03:42:51.993 +00:00] [INFO] [components/index_coord.go:38] ["IndexCoord running ..."]
[2025/04/16 03:42:51.993 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3]
[2025/04/16 03:42:51.993 +00:00] [DEBUG] [querynode/service.go:104] [QueryNode] [port=21123]
[2025/04/16 03:42:51.994 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3]
[2025/04/16 03:42:51.998 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3]
[2025/04/16 03:42:51.998 +00:00] [DEBUG] [indexnode/indexnode.go:115] ["New IndexNode ..."]
[2025/04/16 03:42:52.001 +00:00] [DEBUG] [rootcoord/service.go:204] ["etcd connect done ..."]
[2025/04/16 03:42:52.001 +00:00] [DEBUG] [rootcoord/service.go:264] ["start grpc "] [port=53100]
[2025/04/16 03:42:52.001 +00:00] [DEBUG] [indexnode/service.go:87] [IndexNode] ["network address"=172.18.0.4:21121] ["network port: "=21121]
[2025/04/16 03:42:52.001 +00:00] [DEBUG] [datacoord/service.go:150] ["network port"] [port=13333]
[2025/04/16 03:42:52.002 +00:00] [INFO] [proxy/lb_policy.go:78] ["use look_aside policy on replica selection"]
[2025/04/16 03:42:52.002 +00:00] [INFO] [runtime/asm_amd64.s:1650] ["Start check query node health loop"]
[2025/04/16 03:42:52.002 +00:00] [DEBUG] [proxy/simple_rate_limiter.go:225] ["RateLimiter register for rateType"] [rateType=DMLUpsert] [rateLimit=+inf] [burst=1.7976931348623157e+308]
[2025/04/16 03:42:52.002 +00:00] [DEBUG] [proxy/simple_rate_limiter.go:225] ["RateLimiter register for rateType"] [rateType=DMLDelete] [rateLimit=+inf] [burst=1.7976931348623157e+308]
[2025/04/16 03:42:52.002 +00:00] [DEBUG] [querycoord/service.go:218] [network] [port=19531]
[2025/04/16 03:42:52.002 +00:00] [DEBUG] [querynode/service.go:124] ["QueryNode connect to etcd successfully"]
[2025/04/16 03:42:52.003 +00:00] [INFO] [hookutil/hook.go:46] ["empty so path, skip to load plugin"]
[2025/04/16 03:42:52.003 +00:00] [DEBUG] [proxy/service.go:122] ["create a new Proxy instance"] [state=2]
[2025/04/16 03:42:52.003 +00:00] [DEBUG] [proxy/service.go:423] ["init Proxy server"]
[2025/04/16 03:42:52.003 +00:00] [DEBUG] [proxy/service.go:454] ["Proxy init service's parameter table done"]
[2025/04/16 03:42:52.003 +00:00] [DEBUG] [proxy/service.go:456] ["Proxy init http server's parameter table done"]
[2025/04/16 03:42:52.003 +00:00] [DEBUG] [proxy/service.go:463] ["init Proxy's parameter table done"] [internalAddress=172.18.0.4:19529] [externalAddress=172.18.0.4:19530]
[2025/04/16 03:42:52.003 +00:00] [INFO] [accesslog/global.go:145] ["Init access logger success"]
[2025/04/16 03:42:52.003 +00:00] [DEBUG] [proxy/service.go:470] ["init Proxy's tracer done"] ["service name"="Proxy ip: 172.18.0.4, port: 19530"]
[2025/04/16 03:42:52.003 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3]
[2025/04/16 03:42:52.003 +00:00] [INFO] [datanode/service.go:256] ["DataNode address"] [address=172.18.0.4:21124]
[2025/04/16 03:42:52.004 +00:00] [INFO] [datanode/service.go:257] ["DataNode serverID"] [serverID=0]
[2025/04/16 03:42:52.006 +00:00] [INFO] [proxy/service.go:370] ["Proxy internal server listen on tcp"] [port=19529]
[2025/04/16 03:42:52.007 +00:00] [INFO] [proxy/service.go:377] ["Proxy internal server already listen on tcp"] [port=19529]
[2025/04/16 03:42:52.007 +00:00] [INFO] [proxy/service.go:409] ["create Proxy internal grpc server"] ["enforcement policy"="{\"MinTime\":5000000000,\"PermitWithoutStream\":true}"] ["server parameters"="{\"MaxConnectionIdle\":0,\"MaxConnectionAge\":0,\"MaxConnectionAgeGrace\":0,\"Time\":60000000000,\"Timeout\":10000000000}"]
[2025/04/16 03:42:52.007 +00:00] [INFO] [proxy/service.go:502] ["Proxy server listen on tcp"] [port=19530]
[2025/04/16 03:42:52.007 +00:00] [INFO] [proxy/service.go:505] ["Proxy server already listen on tcp"] [port=19530]
[2025/04/16 03:42:52.007 +00:00] [DEBUG] [proxy/service.go:266] ["Get proxy rate limiter done"] [port=19530]
[2025/04/16 03:42:52.007 +00:00] [DEBUG] [proxy/service.go:345] ["create Proxy grpc server"] ["enforcement policy"="{\"MinTime\":5000000000,\"PermitWithoutStream\":true}"] ["server parameters"="{\"MaxConnectionIdle\":0,\"MaxConnectionAge\":0,\"MaxConnectionAgeGrace\":0,\"Time\":60000000000,\"Timeout\":10000000000}"]
[2025/04/16 03:42:52.007 +00:00] [INFO] [proxy/service.go:586] ["register Proxy http server"]
[2025/04/16 03:42:52.007 +00:00] [DEBUG] [proxy/service.go:593] ["create RootCoord client for Proxy"]
[2025/04/16 03:42:52.007 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3]
[2025/04/16 03:42:52.011 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.012 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.012 +00:00] [DEBUG] [proxy/service.go:599] ["create RootCoord client for Proxy done"]
[2025/04/16 03:42:52.012 +00:00] [DEBUG] [proxy/service.go:602] ["Proxy wait for RootCoord to be healthy"]
[2025/04/16 03:42:52.013 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord]
[2025/04/16 03:42:52.013 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.013 +00:00] [WARN] [grpcclient/client.go:557] ["fail to get grpc client"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.013 +00:00] [WARN] [retry/retry.go:104] ["grpc client is nil, maybe fail to get client in the retry state"] [client_role=rootcoord] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.014 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord]
[2025/04/16 03:42:52.014 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.014 +00:00] [WARN] [grpcclient/client.go:479] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.014 +00:00] [WARN] [grpcclient/client.go:470] ["retry func failed"] [retried=0] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.103 +00:00] [DEBUG] [rootcoord/service.go:221] ["grpc init done ..."]
[2025/04/16 03:42:52.103 +00:00] [DEBUG] [rootcoord/service.go:224] ["RootCoord start to create DataCoord client"]
[2025/04/16 03:42:52.103 +00:00] [DEBUG] [querynode/service.go:134] [QueryNode] [State=Initializing]
[2025/04/16 03:42:52.103 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.103 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3]
[2025/04/16 03:42:52.103 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.103 +00:00] [INFO] [querynodev2/server.go:286] ["QueryNode session info"] [metaPath=by-dev/meta]
[2025/04/16 03:42:52.103 +00:00] [INFO] [dependency/factory.go:86] ["try to init mq"] [standalone=true] [mqType=rocksmq]
[2025/04/16 03:42:52.103 +00:00] [DEBUG] [server/global_rmq.go:39] ["initializing global rmq"] [path=/var/lib/milvus/rdb_data]
[2025/04/16 03:42:52.103 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.104 +00:00] [INFO] [datanode/service.go:266] ["initializing RootCoord client for DataNode"]
[2025/04/16 03:42:52.104 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.104 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.104 +00:00] [DEBUG] [rootcoord/service.go:233] ["RootCoord start to create QueryCoord client"]
[2025/04/16 03:42:52.104 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.104 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.105 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.105 +00:00] [DEBUG] [querycoord/service.go:168] ["QueryCoord try to wait for RootCoord ready"]
[2025/04/16 03:42:52.105 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.106 +00:00] [DEBUG] [server/rocksmq_impl.go:177] ["Start rocksmq"] ["max proc"=128] [parallism=4] ["lru cache"=4294967296]
[2025/04/16 03:42:52.106 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.106 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord]
[2025/04/16 03:42:52.106 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.106 +00:00] [WARN] [grpcclient/client.go:557] ["fail to get grpc client"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.106 +00:00] [INFO] [dependency/factory.go:86] ["try to init mq"] [standalone=true] [mqType=rocksmq]
[2025/04/16 03:42:52.106 +00:00] [WARN] [retry/retry.go:104] ["grpc client is nil, maybe fail to get client in the retry state"] [client_role=rootcoord] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.106 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord]
[2025/04/16 03:42:52.106 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.107 +00:00] [WARN] [grpcclient/client.go:557] ["fail to get grpc client"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.107 +00:00] [WARN] [retry/retry.go:104] ["grpc client is nil, maybe fail to get client in the retry state"] [client_role=rootcoord] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.107 +00:00] [INFO] [indexnode/indexnode.go:207] ["IndexNode init"] [state=Initializing]
[2025/04/16 03:42:52.107 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true]
[2025/04/16 03:42:52.107 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.108 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord]
[2025/04/16 03:42:52.108 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord]
[2025/04/16 03:42:52.108 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.108 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.108 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.108 +00:00] [WARN] [grpcclient/client.go:479] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.108 +00:00] [WARN] [grpcclient/client.go:470] ["retry func failed"] [retried=0] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.108 +00:00] [WARN] [grpcclient/client.go:479] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.108 +00:00] [WARN] [grpcclient/client.go:470] ["retry func failed"] [retried=0] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.109 +00:00] [DEBUG] [sessionutil/session_util.go:373] ["Session get serverID success"] [key=id] [ServerId=1]
[2025/04/16 03:42:52.109 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=querynode] [address=172.18.0.4:21123] [id=1]
[2025/04/16 03:42:52.109 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true]
[2025/04/16 03:42:52.110 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=indexnode] [address=172.18.0.4:21121] [id=1]
[2025/04/16 03:42:52.110 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="querynode-1\n"] [filePath=/tmp/milvus/server_id_8]
[2025/04/16 03:42:52.110 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="indexnode-1\n"] [filePath=/tmp/milvus/server_id_8]
[2025/04/16 03:42:52.110 +00:00] [INFO] [querynodev2/server.go:160] ["QueryNode init session"] [nodeID=1] ["node address"=172.18.0.4:21123]
[2025/04/16 03:42:52.110 +00:00] [INFO] [indexnode/indexnode.go:214] ["IndexNode init session successful"] [serverID=1]
[2025/04/16 03:42:52.110 +00:00] [INFO] [dependency/factory.go:86] ["try to init mq"] [standalone=true] [mqType=rocksmq]
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20250416 03:42:52.110697    76 knowhere_config.cc:107] [KNOWHERE][SetBlasThreshold][milvus] Set faiss::distance_compute_blas_threshold to 16384
I20250416 03:42:52.110987    76 knowhere_config.cc:118] [KNOWHERE][SetEarlyStopThreshold][milvus] Set faiss::early_stop_threshold to 0
I20250416 03:42:52.111069    76 knowhere_config.cc:54] [KNOWHERE][ShowVersion][milvus] Knowhere Version: v2.3.5-hotfix
I20250416 03:42:52.111503    76 knowhere_config.cc:64] [KNOWHERE][SetSimdType][milvus] FAISS expect simdType::AUTO
I20250416 03:42:52.111527    76 knowhere_config.cc:89] [KNOWHERE][SetSimdType][milvus] FAISS hook AVX512
I20250416 03:42:52.111609    76 Common.cpp:35] [SERVER][SetIndexSliceSize][milvus] set config index slice size (byte): 16777216
I20250416 03:42:52.111701    76 Common.cpp:41] [SERVER][SetHighPriorityThreadCoreCoefficient][milvus] set high priority thread pool core coefficient: 10
I20250416 03:42:52.111738    76 Common.cpp:48] [SERVER][SetMiddlePriorityThreadCoreCoefficient][milvus] set middle priority thread pool core coefficient: 5
I20250416 03:42:52.111773    76 Common.cpp:55] [SERVER][SetLowPriorityThreadCoreCoefficient][milvus] set low priority thread pool core coefficient: 1
I20250416 03:42:52.112161    76 thread_pool.h:152] [KNOWHERE][InitGlobalBuildThreadPool][milvus] Init global build thread pool with size 96
[2025/04/16 03:42:52.112 +00:00] [INFO] [indexnode/indexnode.go:219] ["init index node done"] [nodeID=1] [Address=172.18.0.4:21121]
[2025/04/16 03:42:52.112 +00:00] [DEBUG] [indexnode/service.go:74] ["IndexNode init done ..."]
[2025/04/16 03:42:52.112 +00:00] [INFO] [indexnode/indexnode.go:230] [IndexNode] [State=Healthy]
[2025/04/16 03:42:52.112 +00:00] [INFO] [indexnode/indexnode.go:233] ["IndexNode start finished"] []
[2025/04/16 03:42:52.112 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=indexnode] [ServerID=1]
[2025/04/16 03:42:52.112 +00:00] [DEBUG] [indexnode/task_scheduler.go:247] ["IndexNode TaskScheduler start build loop ..."]
[2025/04/16 03:42:52.116 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/indexnode-1] [value="{\"ServerID\":1,\"ServerName\":\"indexnode\",\"Address\":\"172.18.0.4:21121\",\"TriggerKill\":true,\"Version\":\"2.4.6\",\"IndexEngineVersion\":{},\"LeaseID\":7587886134605090581,\"HostName\":\"b3d726d1ac67\",\"EnableDisk\":true}"]
[2025/04/16 03:42:52.116 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=indexnode] [serverID=1]
[2025/04/16 03:42:52.119 +00:00] [DEBUG] [indexnode/service.go:209] ["IndexNode Register etcd success"]
[2025/04/16 03:42:52.119 +00:00] [DEBUG] [indexnode/service.go:78] ["IndexNode start done ..."]
[2025/04/16 03:42:52.119 +00:00] [DEBUG] [components/index_node.go:57] ["IndexNode successfully started"]
[2025/04/16 03:42:52.146 +00:00] [INFO] [tso/tso.go:122] ["sync and save timestamp"] [last=0001/01/01 00:00:00.000 +00:00] [save=2025/04/16 03:42:55.146 +00:00] [next=2025/04/16 03:42:52.146 +00:00]
[2025/04/16 03:42:52.146 +00:00] [INFO] [msgstream/mq_factory.go:18] ["init rocksmq msgstream success"] [path=/var/lib/milvus/rdb_data]
[2025/04/16 03:42:52.146 +00:00] [INFO] [msgstream/mq_factory.go:18] ["init rocksmq msgstream success"] [path=/var/lib/milvus/rdb_data]
[2025/04/16 03:42:52.146 +00:00] [DEBUG] [server/rocksmq_retention.go:80] ["Rocksmq retention goroutine start!"]
[2025/04/16 03:42:52.146 +00:00] [INFO] [msgstream/mq_factory.go:18] ["init rocksmq msgstream success"] [path=/var/lib/milvus/rdb_data]
[2025/04/16 03:42:52.147 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.147 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.148 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.148 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.149 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true]
[2025/04/16 03:42:52.149 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=rootcoord] [address=172.18.0.4:53100] [id=1]
[2025/04/16 03:42:52.149 +00:00] [INFO] [rootcoord/root_coord.go:154] ["update rootcoord state"] [state=Initializing]
[2025/04/16 03:42:52.150 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true]
[2025/04/16 03:42:52.150 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=indexcoord] [address=172.18.0.4:13333] [id=1]
[2025/04/16 03:42:52.150 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.151 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.152 +00:00] [INFO] [storage/minio_object_storage.go:144] ["blob bucket not exist, create bucket."] ["bucket name"=a-bucket]
[2025/04/16 03:42:52.153 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true]
[2025/04/16 03:42:52.153 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=datacoord] [address=172.18.0.4:13333] [id=1]
[2025/04/16 03:42:52.153 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.153 +00:00] [INFO] [tso/tso.go:122] ["sync and save timestamp"] [last=0001/01/01 00:00:00.000 +00:00] [save=2025/04/16 03:42:55.152 +00:00] [next=2025/04/16 03:42:52.152 +00:00]
[2025/04/16 03:42:52.154 +00:00] [INFO] [rootcoord/root_coord.go:398] ["id allocator initialized"] [root_path=by-dev/kv] [sub_path=gid] [key=idTimestamp]
[2025/04/16 03:42:52.154 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.154 +00:00] [INFO] [datacoord/server.go:343] ["init rootcoord client done"]
[2025/04/16 03:42:52.156 +00:00] [INFO] [tso/tso.go:122] ["sync and save timestamp"] [last=0001/01/01 00:00:00.000 +00:00] [save=2025/04/16 03:42:55.155 +00:00] [next=2025/04/16 03:42:52.155 +00:00]
[2025/04/16 03:42:52.156 +00:00] [INFO] [rootcoord/root_coord.go:422] ["tso allocator initialized"] [root_path=by-dev/kv] [sub_path=gid] [key=idTimestamp]
[2025/04/16 03:42:52.157 +00:00] [INFO] [rootcoord/root_coord.go:341] ["Using etcd as meta storage."]
[2025/04/16 03:42:52.156 +00:00] [INFO] [storage/remote_chunk_manager.go:92] ["remote chunk manager init success."] [remote=aws] [bucketname=a-bucket] [root=files]
[2025/04/16 03:42:52.157 +00:00] [INFO] [tasks/concurrent_safe_scheduler.go:27] ["query node use concurrent safe scheduler"] [max_concurrency=128]
[2025/04/16 03:42:52.157 +00:00] [DEBUG] [rootcoord/suffix_snapshot.go:558] ["suffix snapshot GC goroutine start!"]
[2025/04/16 03:42:52.157 +00:00] [INFO] [querynodev2/server.go:326] ["queryNode init scheduler"] [policy=fifo]
[2025/04/16 03:42:52.157 +00:00] [INFO] [segments/segment_loader.go:548] ["SegmentLoader created"] [ioPoolSize=256]
[2025/04/16 03:42:52.158 +00:00] [INFO] [rootcoord/meta_table.go:150] ["recover databases"] ["num of dbs"=0]
I20250416 03:42:52.158820    97 thread_pool.h:172] [KNOWHERE][InitGlobalSearchThreadPool][milvus] Init global search thread pool with size 128
I20250416 03:42:52.159070    97 knowhere_config.cc:64] [KNOWHERE][SetSimdType][milvus] FAISS expect simdType::AUTO
I20250416 03:42:52.159101    97 knowhere_config.cc:89] [KNOWHERE][SetSimdType][milvus] FAISS hook AVX512
[2025/04/16 03:42:52.159 +00:00] [INFO] [querynodev2/server.go:227] ["set up knowhere build pool size"] [pool_size=64]
I20250416 03:42:52.159654   134 thread_pool.h:53] [KNOWHERE][operator()][knowhere_build0] Successfully set priority of knowhere thread.
[2025/04/16 03:42:52.160 +00:00] [INFO] [storage/remote_chunk_manager.go:92] ["remote chunk manager init success."] [remote=aws] [bucketname=a-bucket] [root=files]
[2025/04/16 03:42:52.160 +00:00] [INFO] [datacoord/server.go:352] ["init chunk manager factory done"]
[2025/04/16 03:42:52.160 +00:00] [INFO] [datacoord/server.go:655] ["data coordinator connecting to metadata store"] [metaType=etcd]
[2025/04/16 03:42:52.160 +00:00] [INFO] [datacoord/server.go:668] ["data coordinator successfully connected to metadata store"] [metaType=etcd]
[2025/04/16 03:42:52.162 +00:00] [INFO] [rootcoord/meta_table.go:253] ["create database"] [db=default] [ts=457382290300600321]
[2025/04/16 03:42:52.163 +00:00] [INFO] [datacoord/index_meta.go:95] ["indexMeta reloadFromKV done"] [duration=3.2941ms]
I20250416 03:42:52.164088    97 thread_pool.h:188] [KNOWHERE][SetGlobalBuildThreadPoolSize][milvus] Global build thread pool size has already been set to 64
I20250416 03:42:52.164280    97 Common.cpp:62] [SERVER][SetDefaultExecEvalExprBatchSize][milvus] set default expr eval batch size: 8192
I20250416 03:42:52.164563    97 MinioChunkManager.cpp:161] [SERVER][InitSDKAPIDefault][milvus] init aws with log level:fatal
[2025/04/16 03:42:52.171 +00:00] [INFO] [datacoord/meta.go:163] ["DataCoord meta reloadFromKV done"] [duration=7.908298ms]
[2025/04/16 03:42:52.173 +00:00] [INFO] [rootcoord/meta_table.go:190] ["collections recovered from db"] [db_name=default] [collection_num=0] [partition_num=0]
[2025/04/16 03:42:52.173 +00:00] [INFO] [datacoord/server.go:1238] ["all old data node down, enable auto balance!"]
[2025/04/16 03:42:52.175 +00:00] [INFO] [datacoord/channel_store_v2.go:71] ["channel store reload done"] [duration=1.712328ms]
[2025/04/16 03:42:52.175 +00:00] [INFO] [datacoord/server.go:366] ["init datanode cluster done"]
[2025/04/16 03:42:52.176 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord]
[2025/04/16 03:42:52.176 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.176 +00:00] [INFO] [datacoord/server.go:572] ["DataCoord success to get DataNode sessions"] [sessions={}]
[2025/04/16 03:42:52.176 +00:00] [WARN] [grpcclient/client.go:557] ["fail to get grpc client"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.176 +00:00] [INFO] [datacoord/server.go:593] ["DataCoord Cluster Manager start up"]
[2025/04/16 03:42:52.176 +00:00] [WARN] [retry/retry.go:104] ["grpc client is nil, maybe fail to get client in the retry state"] [client_role=rootcoord] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.176 +00:00] [INFO] [datacoord/channel_manager_v2.go:162] ["starting channel balance loop"]
[2025/04/16 03:42:52.176 +00:00] [INFO] [datacoord/channel_manager_v2.go:170] ["cluster start up"] [allNodes="[]"] [legacyNodes="[]"] [oldNodes="[]"] [newOnlines="[]"] [offLines="[]"]
[2025/04/16 03:42:52.176 +00:00] [INFO] [datacoord/server.go:598] ["DataCoord Cluster Manager start up successfully"]
[2025/04/16 03:42:52.177 +00:00] [INFO] [rootcoord/meta_table.go:208] ["RootCoord meta table reload done"] [duration=20.365329ms]
[2025/04/16 03:42:52.177 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord]
[2025/04/16 03:42:52.177 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.177 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.177 +00:00] [WARN] [grpcclient/client.go:479] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.178 +00:00] [WARN] [grpcclient/client.go:470] ["retry func failed"] [retried=0] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.178 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_0] [elapsed=0]
[2025/04/16 03:42:52.178 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.178 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_1] [elapsed=0]
[2025/04/16 03:42:52.178 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.178 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_2] [elapsed=0]
[2025/04/16 03:42:52.178 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.178 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_3] [elapsed=0]
[2025/04/16 03:42:52.178 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.178 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_4] [elapsed=0]
[2025/04/16 03:42:52.178 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.178 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_5] [elapsed=0]
[2025/04/16 03:42:52.178 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.178 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_6] [elapsed=0]
[2025/04/16 03:42:52.179 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=indexnode] [key=indexnode-1] [address=172.18.0.4:21121]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_7] [elapsed=0]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [datacoord/indexnode_manager.go:84] ["add IndexNode"] [nodeID=1] ["node address"=172.18.0.4:21121]
[2025/04/16 03:42:52.179 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_8] [elapsed=0]
[2025/04/16 03:42:52.179 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_9] [elapsed=0]
[2025/04/16 03:42:52.179 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_10] [elapsed=0]
[2025/04/16 03:42:52.179 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_11] [elapsed=0]
[2025/04/16 03:42:52.179 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_12] [elapsed=0]
[2025/04/16 03:42:52.179 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_13] [elapsed=0]
[2025/04/16 03:42:52.179 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_14] [elapsed=0]
[2025/04/16 03:42:52.179 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:52.179 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-rootcoord-dml_15] [elapsed=0]
[2025/04/16 03:42:52.179 +00:00] [INFO] [rootcoord/dml_channels.go:215] ["init dml channels"] [prefix=by-dev-rootcoord-dml] [num=16]
[2025/04/16 03:42:52.179 +00:00] [INFO] [rootcoord/root_coord.go:451] ["create TimeTick sync done"]
[2025/04/16 03:42:52.180 +00:00] [INFO] [rootcoord/root_coord.go:467] ["init proxy manager done"]
[2025/04/16 03:42:52.180 +00:00] [DEBUG] [rootcoord/root_coord.go:472] ["RootCoord init QuotaCenter done"]
[2025/04/16 03:42:52.180 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.180 +00:00] [DEBUG] [datacoord/indexnode_manager.go:57] ["set IndexNode client"] [nodeID=1]
[2025/04/16 03:42:52.180 +00:00] [DEBUG] [datacoord/indexnode_manager.go:62] ["IndexNode IndexNodeManager setClient success"] [nodeID=1] ["IndexNode num"=1]
[2025/04/16 03:42:52.181 +00:00] [DEBUG] [rootcoord/kv_catalog.go:410] ["not found the user"] [key=root-coord/credential/users/root]
[2025/04/16 03:42:52.181 +00:00] [DEBUG] [rootcoord/root_coord.go:530] ["RootCoord init user root"]
[2025/04/16 03:42:52.182 +00:00] [INFO] [datacoord/server.go:373] ["init service discovery done"]
[2025/04/16 03:42:52.183 +00:00] [INFO] [datacoord/server.go:378] ["init compaction scheduler done"]
[2025/04/16 03:42:52.183 +00:00] [INFO] [datacoord/server.go:384] ["init segment manager done"]
[2025/04/16 03:42:52.183 +00:00] [INFO] [datacoord/garbage_collector.go:83] ["GC with option"] [enabled=true] [interval=1h0m0s] [scanInterval=168h0m0s] [missingTolerance=24h0m0s] [dropTolerance=3h0m0s]
[2025/04/16 03:42:52.186 +00:00] [INFO] [datacoord/server.go:398] ["init datacoord done"] [nodeID=1] [Address=172.18.0.4:13333]
[2025/04/16 03:42:52.186 +00:00] [DEBUG] [datacoord/service.go:259] ["DataCoord init done ..."]
[2025/04/16 03:42:52.186 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=indexcoord] [ServerID=1]
[2025/04/16 03:42:52.188 +00:00] [DEBUG] [rootcoord/kv_catalog.go:410] ["not found the user"] [key=root-coord/credential/users/root]
[2025/04/16 03:42:52.188 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=indexnode] [key=by-dev/meta/session/indexnode-1]
[2025/04/16 03:42:52.189 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/indexcoord] [value="{\"ServerID\":1,\"ServerName\":\"indexcoord\",\"Address\":\"172.18.0.4:13333\",\"Exclusive\":true,\"TriggerKill\":true,\"Version\":\"2.4.6\",\"IndexEngineVersion\":{},\"LeaseID\":7587886134605090626,\"HostName\":\"b3d726d1ac67\"}"]
[2025/04/16 03:42:52.189 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=indexcoord] [serverID=1]
[2025/04/16 03:42:52.189 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=datacoord] [ServerID=1]
[2025/04/16 03:42:52.189 +00:00] [INFO] [rootcoord/root_coord.go:477] ["init credentials done"]
[2025/04/16 03:42:52.193 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/datacoord] [value="{\"ServerID\":1,\"ServerName\":\"datacoord\",\"Address\":\"172.18.0.4:13333\",\"Exclusive\":true,\"TriggerKill\":true,\"Version\":\"2.4.6\",\"IndexEngineVersion\":{},\"LeaseID\":7587886134605090631,\"HostName\":\"b3d726d1ac67\"}"]
[2025/04/16 03:42:52.193 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=datacoord] [serverID=1]
[2025/04/16 03:42:52.193 +00:00] [INFO] [datacoord/server.go:265] ["DataCoord Register Finished"]
[2025/04/16 03:42:52.195 +00:00] [INFO] [datacoord/compaction.go:184] ["Compaction handler check result loop start"] ["check result interval"=3s]
[2025/04/16 03:42:52.195 +00:00] [INFO] [datacoord/import_scheduler.go:74] ["start import scheduler"]
[2025/04/16 03:42:52.195 +00:00] [INFO] [runtime/asm_amd64.s:1650] ["index builder schedule loop start"]
[2025/04/16 03:42:52.195 +00:00] [INFO] [datacoord/index_service.go:110] ["start create index for segment loop..."]
[2025/04/16 03:42:52.195 +00:00] [INFO] [datacoord/import_checker.go:73] ["start import checker"]
[2025/04/16 03:42:52.195 +00:00] [INFO] [datacoord/compaction.go:203] ["compaction handler start schedule"]
[2025/04/16 03:42:52.196 +00:00] [INFO] [datacoord/compaction_view_manager.go:84] ["Compaction view manager start"] ["check interval"=1m0s] ["idle check interval"=3m0s]
[2025/04/16 03:42:52.199 +00:00] [WARN] [rootcoord/kv_catalog.go:1011] ["fail to load grant privilege entity"] [key=root-coord/credential/grantee-privileges/public/Global/*.*] [type=Grant] [error="key not found[key=by-dev/meta/root-coord/credential/grantee-privileges/public/Global/*.*]"]
[2025/04/16 03:42:52.202 +00:00] [WARN] [rootcoord/kv_catalog.go:1033] ["fail to load the grantee id"] [key=root-coord/credential/grantee-id/250dd41b686083b0/PrivilegeDescribeCollection] [error="key not found[key=by-dev/meta/root-coord/credential/grantee-id/250dd41b686083b0/PrivilegeDescribeCollection]"]
[2025/04/16 03:42:52.202 +00:00] [DEBUG] [rootcoord/kv_catalog.go:1038] ["not found the grantee id"] [key=root-coord/credential/grantee-id/250dd41b686083b0/PrivilegeDescribeCollection]
[2025/04/16 03:42:52.205 +00:00] [WARN] [rootcoord/kv_catalog.go:1011] ["fail to load grant privilege entity"] [key=root-coord/credential/grantee-privileges/public/Collection/*.*] [type=Grant] [error="key not found[key=by-dev/meta/root-coord/credential/grantee-privileges/public/Collection/*.*]"]
[2025/04/16 03:42:52.208 +00:00] [WARN] [rootcoord/kv_catalog.go:1033] ["fail to load the grantee id"] [key=root-coord/credential/grantee-id/e03326696e8a3b16/PrivilegeIndexDetail] [error="key not found[key=by-dev/meta/root-coord/credential/grantee-id/e03326696e8a3b16/PrivilegeIndexDetail]"]
[2025/04/16 03:42:52.208 +00:00] [DEBUG] [rootcoord/kv_catalog.go:1038] ["not found the grantee id"] [key=root-coord/credential/grantee-id/e03326696e8a3b16/PrivilegeIndexDetail]
[2025/04/16 03:42:52.209 +00:00] [INFO] [rootcoord/root_coord.go:483] ["init rootcoord done"] [nodeID=1] [Address=172.18.0.4:53100]
[2025/04/16 03:42:52.209 +00:00] [DEBUG] [rootcoord/service.go:169] ["RootCoord init done ..."]
[2025/04/16 03:42:52.209 +00:00] [INFO] [rootcoord/service.go:312] ["RootCoord Core start ..."]
[2025/04/16 03:42:52.209 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=rootcoord] [ServerID=1]
[2025/04/16 03:42:52.212 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/rootcoord] [value="{\"ServerID\":1,\"ServerName\":\"rootcoord\",\"Address\":\"172.18.0.4:53100\",\"Exclusive\":true,\"TriggerKill\":true,\"Version\":\"2.4.6\",\"IndexEngineVersion\":{},\"LeaseID\":7587886134605090649,\"HostName\":\"b3d726d1ac67\"}"]
[2025/04/16 03:42:52.212 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=rootcoord] [serverID=1]
[2025/04/16 03:42:52.212 +00:00] [INFO] [rootcoord/root_coord.go:273] ["RootCoord Register Finished"]
[2025/04/16 03:42:52.213 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="datacoord-1\n"] [filePath=/tmp/milvus/server_id_8]
[2025/04/16 03:42:52.213 +00:00] [INFO] [datacoord/server.go:412] ["DataCoord startup successfully"]
[2025/04/16 03:42:52.213 +00:00] [DEBUG] [datacoord/service.go:264] ["DataCoord start done ..."]
[2025/04/16 03:42:52.213 +00:00] [DEBUG] [components/data_coord.go:56] ["DataCoord successfully started"]
[2025/04/16 03:42:52.214 +00:00] [WARN] [retry/retry.go:104] ["grpc client is nil, maybe fail to get client in the retry state"] [client_role=rootcoord] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.215 +00:00] [INFO] [proxyutil/proxy_watcher.go:96] ["succeed to init sessions on etcd"] [sessions=null] [revision=17]
[2025/04/16 03:42:52.216 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=rootcoord] [key=rootcoord] [address=172.18.0.4:53100]
[2025/04/16 03:42:52.216 +00:00] [DEBUG] [client/client.go:93] ["RootCoordClient GetSessions success"] [address=172.18.0.4:53100] [serverID=1]
[2025/04/16 03:42:52.217 +00:00] [INFO] [rootcoord/root_coord.go:154] ["update rootcoord state"] [state=Healthy]
[2025/04/16 03:42:52.217 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="rootcoord-1\n"] [filePath=/tmp/milvus/server_id_8]
[2025/04/16 03:42:52.217 +00:00] [INFO] [proxyutil/proxy_watcher.go:119] ["start to watch etcd"]
[2025/04/16 03:42:52.217 +00:00] [INFO] [rootcoord/root_coord.go:730] ["rootcoord startup successfully"]
[2025/04/16 03:42:52.217 +00:00] [DEBUG] [rootcoord/service.go:174] ["RootCoord start done ..."]
[2025/04/16 03:42:52.217 +00:00] [INFO] [components/root_coord.go:58] ["RootCoord successfully started"]
[2025/04/16 03:42:52.217 +00:00] [INFO] [rootcoord/quota_center.go:281] ["Start QuotaCenter"] [collectInterval=3s]
[2025/04/16 03:42:52.217 +00:00] [WARN] [proxyutil/proxy_client_manager.go:263] ["proxy client is empty, RefreshPrivilegeInfoCache will not send to any client"]
[2025/04/16 03:42:52.289 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=rootcoord] [key=by-dev/meta/session/rootcoord]
[2025/04/16 03:42:52.309 +00:00] [WARN] [retry/retry.go:104] ["grpc client is nil, maybe fail to get client in the retry state"] [client_role=rootcoord] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.309 +00:00] [WARN] [retry/retry.go:104] ["grpc client is nil, maybe fail to get client in the retry state"] [client_role=rootcoord] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.310 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=rootcoord] [key=rootcoord] [address=172.18.0.4:53100]
[2025/04/16 03:42:52.310 +00:00] [DEBUG] [client/client.go:93] ["RootCoordClient GetSessions success"] [address=172.18.0.4:53100] [serverID=1]
[2025/04/16 03:42:52.310 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=rootcoord] [key=rootcoord] [address=172.18.0.4:53100]
[2025/04/16 03:42:52.311 +00:00] [DEBUG] [client/client.go:93] ["RootCoordClient GetSessions success"] [address=172.18.0.4:53100] [serverID=1]
[2025/04/16 03:42:52.379 +00:00] [WARN] [retry/retry.go:104] ["grpc client is nil, maybe fail to get client in the retry state"] [client_role=rootcoord] [error="empty grpc client: find no available rootcoord, check rootcoord state"]
[2025/04/16 03:42:52.380 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=rootcoord] [key=rootcoord] [address=172.18.0.4:53100]
[2025/04/16 03:42:52.380 +00:00] [DEBUG] [client/client.go:93] ["RootCoordClient GetSessions success"] [address=172.18.0.4:53100] [serverID=1]
[2025/04/16 03:42:52.418 +00:00] [WARN] [rootcoord/root_coord.go:195] ["zero ts was met, this should be only occurred in starting state"] [minBgDdlTs=457382290369544193] [minNormalDdlTs=0]
[2025/04/16 03:42:52.619 +00:00] [DEBUG] [rootcoord/root_coord.go:787] ["RootCoord current state"] [StateCode=Healthy]
[2025/04/16 03:42:52.620 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy]
[2025/04/16 03:42:52.620 +00:00] [DEBUG] [proxy/service.go:607] ["Proxy wait for RootCoord to be healthy done"]
[2025/04/16 03:42:52.620 +00:00] [DEBUG] [proxy/service.go:609] ["set RootCoord client for Proxy"]
[2025/04/16 03:42:52.620 +00:00] [DEBUG] [proxy/service.go:611] ["set RootCoord client for Proxy done"]
[2025/04/16 03:42:52.620 +00:00] [DEBUG] [proxy/service.go:615] ["create DataCoord client for Proxy"]
[2025/04/16 03:42:52.621 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.622 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.622 +00:00] [DEBUG] [proxy/service.go:621] ["create DataCoord client for Proxy done"]
[2025/04/16 03:42:52.622 +00:00] [DEBUG] [proxy/service.go:624] ["Proxy wait for DataCoord to be healthy"]
[2025/04/16 03:42:52.623 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=datacoord] [key=datacoord] [address=172.18.0.4:13333]
[2025/04/16 03:42:52.623 +00:00] [DEBUG] [client/client.go:93] ["DataCoordClient GetSessions success"] [address=172.18.0.4:13333] [serverID=1]
[2025/04/16 03:42:52.625 +00:00] [DEBUG] [datacoord/services.go:660] ["DataCoord current state"] [StateCode=Healthy]
[2025/04/16 03:42:52.626 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy]
[2025/04/16 03:42:52.626 +00:00] [DEBUG] [proxy/service.go:629] ["Proxy wait for DataCoord to be healthy done"]
[2025/04/16 03:42:52.626 +00:00] [DEBUG] [proxy/service.go:631] ["set DataCoord client for Proxy"]
[2025/04/16 03:42:52.626 +00:00] [DEBUG] [proxy/service.go:633] ["set DataCoord client for Proxy done"]
[2025/04/16 03:42:52.626 +00:00] [DEBUG] [proxy/service.go:637] ["create QueryCoord client for Proxy"]
[2025/04/16 03:42:52.626 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.627 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.627 +00:00] [DEBUG] [proxy/service.go:643] ["create QueryCoord client for Proxy done"]
[2025/04/16 03:42:52.627 +00:00] [DEBUG] [proxy/service.go:646] ["Proxy wait for QueryCoord to be healthy"]
[2025/04/16 03:42:52.628 +00:00] [DEBUG] [client/client.go:78] ["QueryCoordClient msess key not existed"] [key=querycoord]
[2025/04/16 03:42:52.628 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available querycoord, check querycoord state"]
[2025/04/16 03:42:52.628 +00:00] [WARN] [grpcclient/client.go:557] ["fail to get grpc client"] [client_role=querycoord] [error="find no available querycoord, check querycoord state"]
[2025/04/16 03:42:52.628 +00:00] [WARN] [retry/retry.go:104] ["grpc client is nil, maybe fail to get client in the retry state"] [client_role=querycoord] [error="empty grpc client: find no available querycoord, check querycoord state"]
[2025/04/16 03:42:52.629 +00:00] [DEBUG] [client/client.go:78] ["QueryCoordClient msess key not existed"] [key=querycoord]
[2025/04/16 03:42:52.630 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available querycoord, check querycoord state"]
[2025/04/16 03:42:52.630 +00:00] [WARN] [grpcclient/client.go:479] ["fail to get grpc client in the retry state"] [client_role=querycoord] [error="find no available querycoord, check querycoord state"]
[2025/04/16 03:42:52.630 +00:00] [WARN] [grpcclient/client.go:470] ["retry func failed"] [retried=0] [error="empty grpc client: find no available querycoord, check querycoord state"]
[2025/04/16 03:42:52.713 +00:00] [DEBUG] [rootcoord/root_coord.go:787] ["RootCoord current state"] [StateCode=Healthy]
[2025/04/16 03:42:52.713 +00:00] [DEBUG] [rootcoord/root_coord.go:787] ["RootCoord current state"] [StateCode=Healthy]
[2025/04/16 03:42:52.713 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy]
[2025/04/16 03:42:52.713 +00:00] [INFO] [datanode/service.go:277] ["RootCoord client is ready for DataNode"]
[2025/04/16 03:42:52.713 +00:00] [DEBUG] [datanode/service.go:285] ["starting DataCoord client for DataNode"]
[2025/04/16 03:42:52.713 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.714 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy]
[2025/04/16 03:42:52.714 +00:00] [DEBUG] [querycoord/service.go:178] ["QueryCoord report RootCoord ready"]
[2025/04/16 03:42:52.714 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.715 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.715 +00:00] [DEBUG] [querycoord/service.go:189] ["QueryCoord try to wait for DataCoord ready"]
[2025/04/16 03:42:52.715 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.716 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=datacoord] [key=datacoord] [address=172.18.0.4:13333]
[2025/04/16 03:42:52.716 +00:00] [DEBUG] [client/client.go:93] ["DataCoordClient GetSessions success"] [address=172.18.0.4:13333] [serverID=1]
[2025/04/16 03:42:52.716 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=datacoord] [key=datacoord] [address=172.18.0.4:13333]
[2025/04/16 03:42:52.716 +00:00] [DEBUG] [client/client.go:93] ["DataCoordClient GetSessions success"] [address=172.18.0.4:13333] [serverID=1]
[2025/04/16 03:42:52.718 +00:00] [DEBUG] [datacoord/services.go:660] ["DataCoord current state"] [StateCode=Healthy]
[2025/04/16 03:42:52.719 +00:00] [DEBUG] [datacoord/services.go:660] ["DataCoord current state"] [StateCode=Healthy]
[2025/04/16 03:42:52.719 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy]
[2025/04/16 03:42:52.719 +00:00] [INFO] [datanode/service.go:296] ["DataCoord client is ready for DataNode"]
[2025/04/16 03:42:52.719 +00:00] [INFO] [sync/once.go:74] ["DataNode server initializing"] [TimeTickChannelName=by-dev-datacoord-timetick-channel]
[2025/04/16 03:42:52.719 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.719 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy]
[2025/04/16 03:42:52.719 +00:00] [DEBUG] [querycoord/service.go:198] ["QueryCoord report DataCoord ready"]
[2025/04/16 03:42:52.719 +00:00] [INFO] [querycoordv2/server.go:186] ["QueryCoord start init"] [meta-root-path=by-dev/meta] [address=172.18.0.4:19531]
[2025/04/16 03:42:52.719 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:52.720 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.721 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:52.722 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true]
[2025/04/16 03:42:52.722 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=datanode] [address=172.18.0.4:21124] [id=1]
[2025/04/16 03:42:52.722 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="datanode-1\n"] [filePath=/tmp/milvus/server_id_8]
[2025/04/16 03:42:52.722 +00:00] [INFO] [sync/once.go:74] ["DataNode server init rateCollector done"] [role=datanode] [nodeID=1]
[2025/04/16 03:42:52.722 +00:00] [INFO] [sync/once.go:74] ["DataNode server init dispatcher client done"] [role=datanode] [nodeID=1]
[2025/04/16 03:42:52.722 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true]
[2025/04/16 03:42:52.722 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=querycoord] [address=172.18.0.4:19531] [id=1]
[2025/04/16 03:42:52.722 +00:00] [INFO] [querycoordv2/server.go:218] ["start init querycoord"] [State=Initializing]
[2025/04/16 03:42:52.722 +00:00] [INFO] [querycoordv2/server.go:222] ["query coordinator connecting to etcd."]
[2025/04/16 03:42:52.722 +00:00] [INFO] [querycoordv2/server.go:234] ["query coordinator successfully connected to etcd."]
[2025/04/16 03:42:52.723 +00:00] [INFO] [dependency/factory.go:86] ["try to init mq"] [standalone=true] [mqType=rocksmq]
[2025/04/16 03:42:52.723 +00:00] [INFO] [msgstream/mq_factory.go:18] ["init rocksmq msgstream success"] [path=/var/lib/milvus/rdb_data]
[2025/04/16 03:42:52.723 +00:00] [INFO] [sync/once.go:74] ["DataNode server init succeeded"] [role=datanode] [nodeID=1] [MsgChannelSubName=by-dev-dataNode]
[2025/04/16 03:42:52.725 +00:00] [INFO] [tso/tso.go:122] ["sync and save timestamp"] [last=0001/01/01 00:00:00.000 +00:00] [save=2025/04/16 03:42:55.724 +00:00] [next=2025/04/16 03:42:52.724 +00:00]
[2025/04/16 03:42:52.725 +00:00] [INFO] [querycoordv2/server.go:245] ["init ID allocator done"]
[2025/04/16 03:42:52.725 +00:00] [INFO] [querycoordv2/server.go:348] ["init meta"]
[2025/04/16 03:42:52.725 +00:00] [INFO] [querycoordv2/server.go:357] ["recover meta..."]
[2025/04/16 03:42:52.727 +00:00] [INFO] [querycoordv2/server.go:358] ["recover collections and partitions from kv store"] [traceID=1744774972727936622]
[2025/04/16 03:42:52.728 +00:00] [INFO] [querycoordv2/server.go:364] ["recovering collections..."] [collections="[]"]
[2025/04/16 03:42:52.728 +00:00] [INFO] [storage/remote_chunk_manager.go:92] ["remote chunk manager init success."] [remote=aws] [bucketname=a-bucket] [root=files]
[2025/04/16 03:42:52.728 +00:00] [INFO] [syncmgr/sync_manager.go:73] ["sync manager initialized"] [initPoolSize=256]
[2025/04/16 03:42:52.728 +00:00] [INFO] [sync/once.go:74] ["init datanode done"] [role=datanode] [nodeID=1] [Address=172.18.0.4:21124]
[2025/04/16 03:42:52.728 +00:00] [INFO] [datanode/service.go:308] ["current DataNode state"] [state=Initializing]
[2025/04/16 03:42:52.728 +00:00] [INFO] [datanode/service.go:192] ["DataNode gRPC services successfully initialized"]
[2025/04/16 03:42:52.728 +00:00] [INFO] [datanode/data_node.go:364] ["start id allocator done"] [role=datanode]
[2025/04/16 03:42:52.729 +00:00] [DEBUG] [datanode/data_node.go:191] ["node begin to register to etcd"] [serverName=datanode] [ServerID=1]
[2025/04/16 03:42:52.729 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=datanode] [ServerID=1]
[2025/04/16 03:42:52.729 +00:00] [INFO] [datanode/data_node.go:343] ["DataNode Background GC Start"]
[2025/04/16 03:42:52.729 +00:00] [INFO] [importv2/scheduler.go:53] ["start import scheduler"]
[2025/04/16 03:42:52.729 +00:00] [INFO] [datanode/channel_manager.go:171] ["DataNode ChannelManager start"]
[2025/04/16 03:42:52.729 +00:00] [INFO] [datanode/channel_checkpoint_updater.go:64] ["channel checkpoint updater start"]
[2025/04/16 03:42:52.732 +00:00] [INFO] [querycoordv2/server.go:394] ["QueryCoord server initMeta done"] [duration=7.307983ms]
[2025/04/16 03:42:52.732 +00:00] [INFO] [querycoordv2/server.go:257] ["init session"]
[2025/04/16 03:42:52.732 +00:00] [INFO] [querycoordv2/server.go:261] ["init schedulers"]
[2025/04/16 03:42:52.732 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/datanode-1] [value="{\"ServerID\":1,\"ServerName\":\"datanode\",\"Address\":\"172.18.0.4:21124\",\"TriggerKill\":true,\"Version\":\"2.4.6\",\"IndexEngineVersion\":{},\"LeaseID\":7587886134605090677,\"HostName\":\"b3d726d1ac67\"}"]
[2025/04/16 03:42:52.732 +00:00] [DEBUG] [sessionutil/session_util.go:779] ["watch services"] ["add kv"="key:\"by-dev/meta/session/datanode-1\" create_revision:19 mod_revision:19 version:1 value:\"{\\\"ServerID\\\":1,\\\"ServerName\\\":\\\"datanode\\\",\\\"Address\\\":\\\"172.18.0.4:21124\\\",\\\"TriggerKill\\\":true,\\\"Version\\\":\\\"2.4.6\\\",\\\"IndexEngineVersion\\\":{},\\\"LeaseID\\\":7587886134605090677,\\\"HostName\\\":\\\"b3d726d1ac67\\\"}\" lease:7587886134605090677 "]
[2025/04/16 03:42:52.733 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=datanode] [serverID=1]
[2025/04/16 03:42:52.733 +00:00] [INFO] [querycoordv2/server.go:281] ["init proxy manager done"]
[2025/04/16 03:42:52.733 +00:00] [INFO] [querycoordv2/server.go:284] ["init dist controller"]
[2025/04/16 03:42:52.733 +00:00] [INFO] [querycoordv2/server.go:294] ["init checker controller"]
[2025/04/16 03:42:52.733 +00:00] [INFO] [datanode/data_node.go:195] ["DataNode Register Finished"]
[2025/04/16 03:42:52.733 +00:00] [DEBUG] [sessionutil/session_util.go:807] [WatchService] ["event type"=SessionAddEvent]
[2025/04/16 03:42:52.733 +00:00] [INFO] [querycoordv2/server.go:399] ["init observers"]
[2025/04/16 03:42:52.733 +00:00] [INFO] [datacoord/server.go:925] ["received datanode register"] [address=172.18.0.4:21124] [serverID=1]
[2025/04/16 03:42:52.733 +00:00] [INFO] [datacoord/channel_manager_v2.go:190] ["register node"] ["registered node"=1]
[2025/04/16 03:42:52.733 +00:00] [INFO] [datacoord/channel_manager_v2.go:196] ["register node with no reassignment"] ["registered node"=1]
[2025/04/16 03:42:52.733 +00:00] [INFO] [querycoordv2/server.go:341] ["init querycoord done"] [nodeID=1] [Address=172.18.0.4:19531]
[2025/04/16 03:42:52.733 +00:00] [DEBUG] [querycoord/service.go:103] ["QueryCoord init done ..."]
[2025/04/16 03:42:52.733 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=querycoord] [ServerID=1]
[2025/04/16 03:42:52.735 +00:00] [INFO] [datanode/service.go:197] ["DataNode gRPC services successfully started"]
[2025/04/16 03:42:52.735 +00:00] [DEBUG] [components/data_node.go:59] ["Datanode successfully started"]
[2025/04/16 03:42:52.736 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/querycoord] [value="{\"ServerID\":1,\"ServerName\":\"querycoord\",\"Address\":\"172.18.0.4:19531\",\"Exclusive\":true,\"TriggerKill\":true,\"Version\":\"2.4.6\",\"IndexEngineVersion\":{},\"LeaseID\":7587886134605090683,\"HostName\":\"b3d726d1ac67\"}"]
[2025/04/16 03:42:52.736 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=querycoord] [serverID=1]
[2025/04/16 03:42:52.738 +00:00] [INFO] [querycoordv2/server.go:441] ["start watcher..."]
[2025/04/16 03:42:52.741 +00:00] [INFO] [querycoordv2/server.go:797] ["all old query node down, enable auto balance!"]
[2025/04/16 03:42:52.742 +00:00] [INFO] [proxyutil/proxy_watcher.go:96] ["succeed to init sessions on etcd"] [sessions=null] [revision=20]
[2025/04/16 03:42:52.743 +00:00] [INFO] [querycoordv2/server.go:491] ["start cluster..."]
[2025/04/16 03:42:52.743 +00:00] [INFO] [querycoordv2/server.go:494] ["start observers..."]
[2025/04/16 03:42:52.743 +00:00] [INFO] [proxyutil/proxy_watcher.go:119] ["start to watch etcd"]
[2025/04/16 03:42:52.744 +00:00] [INFO] [observers/target_observer.go:131] ["Start update next target loop"]
[2025/04/16 03:42:52.744 +00:00] [INFO] [observers/target_observer.go:145] ["target observer init done"]
[2025/04/16 03:42:52.744 +00:00] [INFO] [querycoordv2/server.go:500] ["start task scheduler..."]
[2025/04/16 03:42:52.744 +00:00] [INFO] [querycoordv2/server.go:503] ["start checker controller..."]
[2025/04/16 03:42:52.744 +00:00] [INFO] [querycoordv2/server.go:506] ["start job scheduler..."]
[2025/04/16 03:42:52.744 +00:00] [INFO] [observers/replica_observer.go:69] ["Start check replica loop"]
[2025/04/16 03:42:52.744 +00:00] [INFO] [observers/resource_observer.go:67] ["Start check resource group loop"]
[2025/04/16 03:42:52.744 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="querycoord-1\n"] [filePath=/tmp/milvus/server_id_8]
[2025/04/16 03:42:52.744 +00:00] [INFO] [querycoordv2/server.go:435] ["QueryCoord started"]
[2025/04/16 03:42:52.744 +00:00] [DEBUG] [querycoord/service.go:108] ["QueryCoord start done ..."]
[2025/04/16 03:42:52.744 +00:00] [DEBUG] [components/query_coord.go:59] ["QueryCoord successfully started"]
[2025/04/16 03:42:52.744 +00:00] [DEBUG] [observers/resource_observer.go:93] ["start to check resource group"] [enableRGAutoRecover=true] [resourceGroupNum=1]
[2025/04/16 03:42:52.744 +00:00] [DEBUG] [observers/resource_observer.go:101] ["recover resource groups..."]
[2025/04/16 03:42:52.744 +00:00] [DEBUG] [observers/resource_observer.go:121] ["check resource group done"] [enableRGAutoRecover=true] [resourceGroupNum=1]
[2025/04/16 03:42:52.783 +00:00] [INFO] [rootcoord/service.go:93] ["received request to list databases"] [msgID=0]
[2025/04/16 03:42:52.783 +00:00] [INFO] [rootcoord/service.go:93] ["done to list databases"] [msgID=0] ["num of databases"=1]
[2025/04/16 03:42:52.792 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=querycoord] [key=by-dev/meta/session/querycoord]
[2025/04/16 03:42:52.792 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=datanode] [key=by-dev/meta/session/datanode-1]
[2025/04/16 03:42:52.831 +00:00] [WARN] [retry/retry.go:104] ["grpc client is nil, maybe fail to get client in the retry state"] [client_role=querycoord] [error="empty grpc client: find no available querycoord, check querycoord state"]
[2025/04/16 03:42:52.832 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=querycoord] [key=querycoord] [address=172.18.0.4:19531]
[2025/04/16 03:42:52.832 +00:00] [DEBUG] [client/client.go:82] ["QueryCoordClient GetSessions success"] [address=172.18.0.4:19531] [serverID=1]
[2025/04/16 03:42:53.229 +00:00] [DEBUG] [datanode/timetick_sender.go:170] ["timeTickSender send datanode timetick message"] [toSendMsgs=null] [sendLastTss={}]
[2025/04/16 03:42:53.232 +00:00] [DEBUG] [datanode/timetick_sender.go:165] ["timeTickSender stats"] [lastSentTss={}] [sizeBeforeClean=0] [sizeAfterClean=0]
[2025/04/16 03:42:53.236 +00:00] [DEBUG] [querycoordv2/server.go:584] ["QueryCoord current state"] [StateCode=Healthy]
[2025/04/16 03:42:53.236 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy]
[2025/04/16 03:42:53.236 +00:00] [DEBUG] [proxy/service.go:651] ["Proxy wait for QueryCoord to be healthy done"]
[2025/04/16 03:42:53.236 +00:00] [DEBUG] [proxy/service.go:653] ["set QueryCoord client for Proxy"]
[2025/04/16 03:42:53.236 +00:00] [DEBUG] [proxy/service.go:655] ["set QueryCoord client for Proxy done"]
[2025/04/16 03:42:53.237 +00:00] [DEBUG] [proxy/service.go:657] ["update Proxy's state to Initializing"]
[2025/04/16 03:42:53.237 +00:00] [DEBUG] [proxy/service.go:660] ["init Proxy"]
[2025/04/16 03:42:53.237 +00:00] [INFO] [proxy/proxy.go:215] ["init session for Proxy"]
[2025/04/16 03:42:53.237 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:53.238 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:53.239 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true]
[2025/04/16 03:42:53.239 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=proxy] [address=172.18.0.4:19529] [id=1]
[2025/04/16 03:42:53.239 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="proxy-1\n"] [filePath=/tmp/milvus/server_id_8]
[2025/04/16 03:42:53.239 +00:00] [INFO] [proxy/proxy.go:220] ["init session for Proxy done"]
[2025/04/16 03:42:53.239 +00:00] [INFO] [dependency/factory.go:86] ["try to init mq"] [standalone=true] [mqType=rocksmq]
[2025/04/16 03:42:53.239 +00:00] [INFO] [msgstream/mq_factory.go:18] ["init rocksmq msgstream success"] [path=/var/lib/milvus/rdb_data]
[2025/04/16 03:42:53.240 +00:00] [DEBUG] [proxy/proxy.go:224] ["init access log for Proxy done"]
[2025/04/16 03:42:53.240 +00:00] [INFO] [proxy/proxy.go:230] ["Proxy init rateCollector done"] [nodeID=1]
[2025/04/16 03:42:53.240 +00:00] [DEBUG] [proxy/proxy.go:240] ["create id allocator done"] [role=proxy] [ProxyID=1]
[2025/04/16 03:42:53.240 +00:00] [DEBUG] [proxy/proxy.go:250] ["create timestamp allocator done"] [role=proxy] [ProxyID=1]
[2025/04/16 03:42:53.240 +00:00] [DEBUG] [proxy/proxy.go:261] ["create segment id assigner done"] [role=proxy] [ProxyID=1]
[2025/04/16 03:42:53.240 +00:00] [DEBUG] [proxy/proxy.go:266] ["create channels manager done"] [role=proxy]
[2025/04/16 03:42:53.240 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true]
[2025/04/16 03:42:53.241 +00:00] [DEBUG] [server/rocksmq_impl.go:424] ["Rocksmq create topic successfully "] [topic=by-dev-replicate-msg] [elapsed=0]
[2025/04/16 03:42:53.241 +00:00] [DEBUG] [proxy/proxy.go:284] ["create task scheduler done"] [role=proxy]
[2025/04/16 03:42:53.241 +00:00] [DEBUG] [proxy/proxy.go:288] ["create channels time ticker done"] [role=proxy] [syncTimeTickInterval=100ms]
[2025/04/16 03:42:53.241 +00:00] [DEBUG] [proxy/proxy.go:291] ["create metrics cache manager done"] [role=proxy]
[2025/04/16 03:42:53.242 +00:00] [DEBUG] [rootcoord/service.go:521] [PolicyList] [role=rootcoord] [in=]
[2025/04/16 03:42:53.247 +00:00] [DEBUG] [rootcoord/service.go:521] ["PolicyList success"] [role=rootcoord] [in=]
[2025/04/16 03:42:53.248 +00:00] [INFO] [proxy/meta_cache.go:292] ["success to init meta cache"] [policy_infos="[\"{\\\"PType\\\":\\\"p\\\",\\\"V0\\\":\\\"public\\\",\\\"V1\\\":\\\"Collection-*.*\\\",\\\"V2\\\":\\\"PrivilegeIndexDetail\\\"}\",\"{\\\"PType\\\":\\\"p\\\",\\\"V0\\\":\\\"public\\\",\\\"V1\\\":\\\"Global-*.*\\\",\\\"V2\\\":\\\"PrivilegeDescribeCollection\\\"}\"]"]
[2025/04/16 03:42:53.248 +00:00] [DEBUG] [proxy/proxy.go:297] ["init meta cache done"] [role=proxy]
[2025/04/16 03:42:53.248 +00:00] [INFO] [proxy/proxy.go:301] ["init proxy done"] [nodeID=1] [Address=172.18.0.4:19529]
[2025/04/16 03:42:53.248 +00:00] [DEBUG] [proxy/service.go:665] ["init Proxy done"]
---Milvus Proxy successfully initialized and ready to serve!---
[2025/04/16 03:42:53.248 +00:00] [DEBUG] [proxy/service.go:428] ["init Proxy server done"]
[2025/04/16 03:42:53.248 +00:00] [DEBUG] [proxy/service.go:430] ["start Proxy server"]
[2025/04/16 03:42:53.248 +00:00] [DEBUG] [proxy/proxy.go:394] ["start task scheduler done"] [role=proxy]
[2025/04/16 03:42:53.248 +00:00] [DEBUG] [proxy/proxy.go:400] ["start id allocator done"] [role=proxy]
[2025/04/16 03:42:53.249 +00:00] [DEBUG] [proxy/proxy.go:406] ["start segment id assigner done"] [role=proxy]
[2025/04/16 03:42:53.250 +00:00] [DEBUG] [proxy/proxy.go:412] ["start channels time ticker done"] [role=proxy]
[2025/04/16 03:42:53.250 +00:00] [DEBUG] [proxy/proxy.go:426] ["update state code"] [role=proxy] [State=Healthy]
[2025/04/16 03:42:53.251 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=proxy] [ServerID=1]
[2025/04/16 03:42:53.254 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/proxy-1] [value="{\"ServerID\":1,\"ServerName\":\"proxy\",\"Address\":\"172.18.0.4:19529\",\"TriggerKill\":true,\"Version\":\"2.4.6\",\"IndexEngineVersion\":{},\"LeaseID\":7587886134605090697,\"HostName\":\"b3d726d1ac67\"}"]
[2025/04/16 03:42:53.254 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=proxy] [serverID=1]
[2025/04/16 03:42:53.254 +00:00] [INFO] [proxy/proxy.go:175] ["Proxy Register Finished"]
[2025/04/16 03:42:53.254 +00:00] [DEBUG] [proxyutil/proxy_watcher.go:169] ["received proxy put event with session"] [session="Session:<ServerID: 1, ServerName: proxy, Version: 2.4.6>"]
[2025/04/16 03:42:53.254 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:53.254 +00:00] [DEBUG] [proxyutil/proxy_watcher.go:169] ["received proxy put event with session"] [session="Session:<ServerID: 1, ServerName: proxy, Version: 2.4.6>"]
[2025/04/16 03:42:53.254 +00:00] [INFO] [rootcoord/timeticksync.go:233] ["Add session for timeticksync"] [serverID=1]
[2025/04/16 03:42:53.254 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:53.256 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:53.256 +00:00] [INFO] [proxyutil/proxy_client_manager.go:156] ["succeed to create proxy client"] [address=172.18.0.4:19529] [serverID=1]
[2025/04/16 03:42:53.256 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:53.256 +00:00] [INFO] [proxyutil/proxy_client_manager.go:156] ["succeed to create proxy client"] [address=172.18.0.4:19529] [serverID=1]
[2025/04/16 03:42:53.257 +00:00] [INFO] [proxy/service.go:685] ["start Proxy http server"]
[2025/04/16 03:42:53.257 +00:00] [DEBUG] [proxy/service.go:435] ["start Proxy server done"]
[2025/04/16 03:42:53.257 +00:00] [INFO] [components/proxy.go:58] ["Proxy successfully started"]
[2025/04/16 03:42:53.296 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=proxy] [key=by-dev/meta/session/proxy-1]
[2025/04/16 03:42:54.197 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:54.198 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:54.201 +00:00] [DEBUG] [datacoord/import_scheduler.go:167] ["peek slots done"] [nodeSlots="{\"1\":16}"]
I20250416 03:42:54.303653    97 MinioChunkManager.cpp:225] [SERVER][PreCheck][milvus] start to precheck chunk manager with configuration: [address=minio:9000, bucket_name=a-bucket, root_path=files, storage_type=remote, cloud_provider=aws, iam_endpoint=, log_level=fatal, region=, useSSL=false, sslCACert=19, useIAM=false, useVirtualHost=false, requestTimeoutMs=10000]
I20250416 03:42:54.312366    97 ChunkManager.cpp:112] [SERVER][AwsChunkManager][milvus] init AwsChunkManager with parameter[endpoint=minio:9000][bucket_name=a-bucket][root_path=files][use_secure=false]
I20250416 03:42:54.312676    97 ChunkCache.h:38] [SERVER][ChunkCache][milvus] Init ChunkCache with prefix: /var/lib/milvus/data/mmap/chunk_cache, read_ahead_policy: willneed
[2025/04/16 03:42:54.312 +00:00] [INFO] [querynodev2/server.go:260] ["InitChunkCache done"] [dir=/var/lib/milvus/data/mmap/chunk_cache] [policy=willneed]
I20250416 03:42:54.312882    97 Tracer.cpp:66] [SERVER][initTelemetry][milvus] Empty Trace
[2025/04/16 03:42:54.315 +00:00] [INFO] [gc/gc_tuner.go:137] ["GC Helper initialized."] ["Initial GoGC"=100] [minimumGOGC=30] [maximumGOGC=200] [memoryThreshold=486625963622]
[2025/04/16 03:42:54.315 +00:00] [INFO] [querynodev2/server.go:385] ["query node init successfully"] [queryNodeID=1] [Address=172.18.0.4:21123]
[2025/04/16 03:42:54.315 +00:00] [DEBUG] [querynode/service.go:234] ["QueryNode init done ..."]
[2025/04/16 03:42:54.315 +00:00] [INFO] [querynodev2/server.go:405] ["query node start successfully"] [queryNodeID=1] [Address=172.18.0.4:21123] [mmapEnabled=false]
[2025/04/16 03:42:54.315 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=querynode] [ServerID=1]
[2025/04/16 03:42:54.315 +00:00] [INFO] [tasks/concurrent_safe_scheduler.go:213] ["start execute loop"]
[2025/04/16 03:42:54.319 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/querynode-1] [value="{\"ServerID\":1,\"ServerName\":\"querynode\",\"Address\":\"172.18.0.4:21123\",\"TriggerKill\":true,\"Version\":\"2.4.6\",\"IndexEngineVersion\":{\"CurrentIndexVersion\":4},\"LeaseID\":7587886134605090704,\"HostName\":\"b3d726d1ac67\"}"]
[2025/04/16 03:42:54.319 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=querynode] [serverID=1]
[2025/04/16 03:42:54.319 +00:00] [DEBUG] [sessionutil/session_util.go:779] ["watch services"] ["add kv"="key:\"by-dev/meta/session/querynode-1\" create_revision:22 mod_revision:22 version:1 value:\"{\\\"ServerID\\\":1,\\\"ServerName\\\":\\\"querynode\\\",\\\"Address\\\":\\\"172.18.0.4:21123\\\",\\\"TriggerKill\\\":true,\\\"Version\\\":\\\"2.4.6\\\",\\\"IndexEngineVersion\\\":{\\\"CurrentIndexVersion\\\":4},\\\"LeaseID\\\":7587886134605090704,\\\"HostName\\\":\\\"b3d726d1ac67\\\"}\" lease:7587886134605090704 "]
[2025/04/16 03:42:54.319 +00:00] [DEBUG] [sessionutil/session_util.go:807] [WatchService] ["event type"=SessionAddEvent]
[2025/04/16 03:42:54.319 +00:00] [INFO] [querycoordv2/server.go:679] ["add node to NodeManager"] [nodeID=1] [nodeAddr=172.18.0.4:21123]
[2025/04/16 03:42:54.319 +00:00] [DEBUG] [sessionutil/session_util.go:779] ["watch services"] ["add kv"="key:\"by-dev/meta/session/querynode-1\" create_revision:22 mod_revision:22 version:1 value:\"{\\\"ServerID\\\":1,\\\"ServerName\\\":\\\"querynode\\\",\\\"Address\\\":\\\"172.18.0.4:21123\\\",\\\"TriggerKill\\\":true,\\\"Version\\\":\\\"2.4.6\\\",\\\"IndexEngineVersion\\\":{\\\"CurrentIndexVersion\\\":4},\\\"LeaseID\\\":7587886134605090704,\\\"HostName\\\":\\\"b3d726d1ac67\\\"}\" lease:7587886134605090704 "]
[2025/04/16 03:42:54.319 +00:00] [DEBUG] [sessionutil/session_util.go:807] [WatchService] ["event type"=SessionAddEvent]
[2025/04/16 03:42:54.319 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"]
[2025/04/16 03:42:54.319 +00:00] [INFO] [datacoord/server.go:976] ["received querynode register"] [address=172.18.0.4:21123] [serverID=1]
[2025/04/16 03:42:54.319 +00:00] [INFO] [datacoord/index_engine_version_manager.go:65] ["addOrUpdate version"] [nodeId=1] [minimal=0] [current=4]
[2025/04/16 03:42:54.320 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"]
[2025/04/16 03:42:54.320 +00:00] [DEBUG] [querynode/service.go:239] ["QueryNode start done ..."]
[2025/04/16 03:42:54.320 +00:00] [DEBUG] [components/query_node.go:59] ["QueryNode successfully started"]
[2025/04/16 03:42:54.321 +00:00] [INFO] [logutil/logutil.go:163] ["Log directory"] [configDir=]
[2025/04/16 03:42:54.321 +00:00] [INFO] [logutil/logutil.go:164] ["Set log file to "] [path=]
[2025/04/16 03:42:54.321 +00:00] [INFO] [tracer/tracer.go:49] ["Init tracer finished"] [Exporter=noop]
[2025/04/16 03:42:54.322 +00:00] [INFO] [task/scheduler.go:239] ["add executor for new QueryNode"] [nodeID=1]
[2025/04/16 03:42:54.323 +00:00] [INFO] [dist/dist_handler.go:58] ["start dist handler"] [nodeID=1]
[2025/04/16 03:42:54.324 +00:00] [INFO] [meta/resource_manager.go:805] ["transfer node to resource group"] [rgName=__default_resource_group] [originalRG=_] [node=1]
[2025/04/16 03:42:54.324 +00:00] [INFO] [meta/resource_manager.go:444] ["HandleNodeUp: add node to resource group"] [rgName=__default_resource_group] [node=1] []
[2025/04/16 03:42:54.404 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=querynode] [key=by-dev/meta/session/querynode-1]
[2025/04/16 03:42:54.826 +00:00] [WARN] [dist/dist_handler.go:112] ["node last heart beat time lag too behind"] [now=2025/04/16 03:42:54.826 +00:00] [lastHeartBeatTime=1970/01/01 00:00:00.000 +00:00] [nodeID=1]
[2025/04/16 03:43:52.197 +00:00] [INFO] [datacoord/compaction_trigger.go:363] ["the length of SegmentsChanPart is 0, skip to handle compaction"] [compactionID=457382290299814190] [signal.collectionID=0] [signal.partitionID=0] [signal.segmentID=0]
[2025/04/16 03:44:52.196 +00:00] [INFO] [datacoord/import_checker.go:131] ["import task stats"] [type=PreImportTask] [pending=0] [inProgress=0] [completed=0] [failed=0]
[2025/04/16 03:44:52.196 +00:00] [INFO] [datacoord/import_checker.go:131] ["import task stats"] [type=ImportTask] [pending=0] [inProgress=0] [completed=0] [failed=0]
[2025/04/16 03:44:52.197 +00:00] [INFO] [datacoord/compaction_trigger.go:363] ["the length of SegmentsChanPart is 0, skip to handle compaction"] [compactionID=457382290299814491] [signal.collectionID=0] [signal.partitionID=0] [signal.segmentID=0]
[2025/04/16 03:45:52.196 +00:00] [INFO] [datacoord/compaction_view_manager.go:107] ["Views idle for a long time, try to trigger a TriggerTypeLevelZeroViewIDLE compaction event"]
[2025/04/16 03:45:52.197 +00:00] [INFO] [datacoord/compaction_trigger.go:363] ["the length of SegmentsChanPart is 0, skip to handle compaction"] [compactionID=457382290299814792] [signal.collectionID=0] [signal.partitionID=0] [signal.segmentID=0]
[2025/04/16 03:46:52.196 +00:00] [INFO] [datacoord/import_checker.go:131] ["import task stats"] [type=PreImportTask] [pending=0] [inProgress=0] [completed=0] [failed=0]
[2025/04/16 03:46:52.196 +00:00] [INFO] [datacoord/import_checker.go:131] ["import task stats"] [type=ImportTask] [pending=0] [inProgress=0] [completed=0] [failed=0]
[2025/04/16 03:46:52.197 +00:00] [INFO] [datacoord/compaction_trigger.go:363] ["the length of SegmentsChanPart is 0, skip to handle compaction"] [compactionID=457382290299815093] [signal.collectionID=0] [signal.partitionID=0] [signal.segmentID=0]
xiguiw commented 2 months ago

@siddhivelankar23

Raw log

docker compose milvus-standalone error [2025/04/11 17:03:46.577 +00:00] [DEBUG] [rootcoord/service.go:198] ["RootCoord

"RootCoord connect to etcd failed"] [error="context deadline exceeded"]

The log shows "connect to etcd failed"

Please check:

joshuayao commented 1 month ago

Hi @siddhivelankar23 Is the issue fixed in your environment?

siddhivelankar23 commented 1 month ago

I haven’t had a chance to look into it yet, but my team and I will review it soon.

CICD-at-OPEA commented 1 week ago

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days.

CICD-at-OPEA commented 2 days ago

This issue was closed because it has been stalled for 7 days with no activity.