search

milvus-io / milvus

A cloud-native vector database, storage for next generation AI applications
https://milvus.io
Apache License 2.0
30.46k stars 2.92k forks source link

[Bug]: Milvus Standalone container randomly stopping + Connection Failed #34821

Closed lukezx3 closed 3 months ago

lukezx3 commented 3 months ago

Is there an existing issue for this?

Environment

- Milvus version: 2.4.4
- Deployment mode(standalone or cluster): standalone
- MQ type(rocksmq, pulsar or kafka):    
- SDK version(e.g. pymilvus v2.0.0rc2): pymilvus 2.4.4
- OS(Ubuntu or CentOS): ubuntu 22.04 (vmware)
- CPU/Memory: 16384, 4 core
- GPU: 
- Others:

Current Behavior

My DB has 2 collections, 1 with partition (100k records), 1 without partition (100k records), total 200k records. each record has vector with 1536 dimensions. I ran search/query for 30 minutes to an hour to test and everything was working perfectly. All of a sudden, I get

Failed to create new connection using: a4e2766d20df4ce7a9fb23881ac31667 Traceback (most recent call last): File "/var/www/html/milvus-docker-test/milvus_docker_intro.py", line 4, in <module> client = MilvusClient( File "/home/vagrant/.local/lib/python3.10/site-packages/pymilvus/milvus_client/milvus_client.py", line 58, in __init__ self._using = self._create_connection( File "/home/vagrant/.local/lib/python3.10/site-packages/pymilvus/milvus_client/milvus_client.py", line 651, in _create_connection raise ex from ex File "/home/vagrant/.local/lib/python3.10/site-packages/pymilvus/milvus_client/milvus_client.py", line 648, in _create_connection connections.connect(using, user, password, db_name, token, uri=uri, **kwargs) File "/home/vagrant/.local/lib/python3.10/site-packages/pymilvus/orm/connections.py", line 447, in connect connect_milvus(**kwargs, user=user, password=password, token=token, db_name=db_name) File "/home/vagrant/.local/lib/python3.10/site-packages/pymilvus/orm/connections.py", line 398, in connect_milvus gh._wait_for_channel_ready(timeout=timeout) File "/home/vagrant/.local/lib/python3.10/site-packages/pymilvus/client/grpc_handler.py", line 150, in _wait_for_channel_ready raise MilvusException( pymilvus.exceptions.MilvusException: <MilvusException: (code=2, message=Fail connecting to server on localhost:19530, illegal connection params or server unavailable)>

I run sudo docker compose ps and see that milvus standalone stopped running. milvus-minio healthy but milvus-etcd unhealthy as well. What's the issue?

What I Tried

Attempted:

sudo docker compose down -> sudo docker compose up -d

change vm memory size/cores from (8192, 2) -> (16134, 4) in case it was running OOM.

print loading progress/load state -> "COULD NOT CREATE NEW CONNECTION)

Expected Behavior

No response

Steps To Reproduce

No response

Milvus Log

Milvus Standalone logs: [2024/07/18 20:35:39.052 +00:00] [WARN] [rootcoord/root_coord.go:235] ["failed to update tso"] [error="etcdserver: request timed out"] [errorVerbose="etcdserver: request timed out\n(1) attached stack trace\n -- stack trace:\n | github.com/milvus-io/milvus/internal/tso.(timestampOracle).saveTimestamp\n | \t/go/src/github.com/milvus-io/milvus/internal/tso/tso.go:98\n | github.com/milvus-io/milvus/internal/tso.(timestampOracle).UpdateTimestamp\n | \t/go/src/github.com/milvus-io/milvus/internal/tso/tso.go:201\n | github.com/milvus-io/milvus/internal/tso.(GlobalTSOAllocator).UpdateTSO\n | \t/go/src/github.com/milvus-io/milvus/internal/tso/global_allocator.go:100\n | github.com/milvus-io/milvus/internal/rootcoord.(Core).tsLoop\n | \t/go/src/github.com/milvus-io/milvus/internal/rootcoord/root_coord.go:234\n | runtime.goexit\n | \t/usr/local/go/src/runtime/asm_arm64.s:1172\nWraps: (2) etcdserver: request timed out\nError types: (1) *withstack.withStack (2) rpctypes.EtcdError"]

[2024/07/18 20:37:12.618 +00:00] [ERROR] [datanode/data_node.go:198] ["Data Node disconnected from etcd, process will exit"] ["Server Id"=8] [stack="github.com/milvus-io/milvus/internal/datanode.(*DataNode).Register.func1\n\t/go/src/github.com/milvus-io/milvus/internal/datanode/data_node.go:198"]

[2024/07/18 21:14:03.775 +00:00] [INFO] [datacoord/index_builder.go:279] ["index builder peek client error, there is no available"] [2024/07/18 21:14:03.775 +00:00] [INFO] [datacoord/index_builder.go:202] ["there is no idle indexing node, wait a minute..."]

Anything else?

Docker-compose.yml

`services: etcd: container_name: milvus-etcd image: quay.io/coreos/etcd:v3.5.5 environment:

networks: default: name: milvus`

yanliang567 commented 3 months ago

it seems that the milvus service lost connection to etcd, please double check the etcd is healthy. Usually Milvus lost the connection for etcd responses too slowly, check the network and ssd volumes for etcd /assign @lukezx3 /unassign

lukezx3 commented 3 months ago

it seems that the milvus service lost connection to etcd, please double check the etcd is healthy. Usually Milvus lost the connection for etcd responses too slowly, check the network and ssd volumes for etcd /assign @lukezx3 /unassign

hi yes etcd is unhealthy but why? it should be able to handle only 100k records insertion at 10k at a time. this also prevents connection from getting loaded and every basic function call (get_load_state, load_collection) takes several minutes to execute or times out. how to fix?

jaime0815 commented 3 months ago

it seems that the milvus service lost connection to etcd, please double check the etcd is healthy. Usually Milvus lost the connection for etcd responses too slowly, check the network and ssd volumes for etcd /assign @lukezx3 /unassign

hi yes etcd is unhealthy but why? it should be able to handle only 100k records insertion at 10k at a time. this also prevents connection from getting loaded and every basic function call (get_load_state, load_collection) takes several minutes to execute or times out. how to fix?

Try to restart etcd, please provide logs of etcd if it still is unhealthy.

lukezx3 commented 3 months ago

it seems that the milvus service lost connection to etcd, please double check the etcd is healthy. Usually Milvus lost the connection for etcd responses too slowly, check the network and ssd volumes for etcd /assign @lukezx3 /unassign

hi yes etcd is unhealthy but why? it should be able to handle only 100k records insertion at 10k at a time. this also prevents connection from getting loaded and every basic function call (get_load_state, load_collection) takes several minutes to execute or times out. how to fix?

Try to restart etcd, please provide logs of etcd if it still is unhealthy.

Hey! Yeah I restarted multiple times. Restarted etcd when unhealthy and milvus standalone when it suddenly stops. Do you need etcd logs or standalone logs? I provided some output for standalone logs in my problem statement

lukezx3 commented 3 months ago

it seems that the milvus service lost connection to etcd, please double check the etcd is healthy. Usually Milvus lost the connection for etcd responses too slowly, check the network and ssd volumes for etcd /assign @lukezx3 /unassign

hi yes etcd is unhealthy but why? it should be able to handle only 100k records insertion at 10k at a time. this also prevents connection from getting loaded and every basic function call (get_load_state, load_collection) takes several minutes to execute or times out. how to fix?

Try to restart etcd, please provide logs of etcd if it still is unhealthy.

ETCD LOGS

{"level":"info","ts":"2024-07-19T20:26:18.770Z","caller":"traceutil/trace.go:171","msg":"trace[2110741098] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:4238; }","duration":"1.621665079s","start":"2024-07-19T20:26:17.148Z","end":"2024-07-19T20:26:18.770Z","steps":["trace[2110741098] 'process raft request' (duration: 631.780521ms)","trace[2110741098] 'get key's previous created_revision and leaseID' (duration: 989.727471ms)"],"step_count":2} {"level":"warn","ts":"2024-07-19T20:26:18.770Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-19T20:26:17.148Z","time spent":"1.621708247s","remote":"172.18.0.4:52020","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} {"level":"info","ts":"2024-07-19T20:26:21.714Z","caller":"traceutil/trace.go:171","msg":"trace[1128419264] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:4239; }","duration":"1.566294941s","start":"2024-07-19T20:26:20.147Z","end":"2024-07-19T20:26:21.714Z","steps":["trace[1128419264] 'process raft request' (duration: 1.566191688s)"],"step_count":1} {"level":"warn","ts":"2024-07-19T20:26:21.714Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-19T20:26:20.147Z","time spent":"1.566372068s","remote":"172.18.0.4:52020","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} {"level":"warn","ts":"2024-07-19T20:26:28.273Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.371402076s","expected-duration":"100ms","prefix":"","request":"header: put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} {"level":"info","ts":"2024-07-19T20:26:28.273Z","caller":"traceutil/trace.go:171","msg":"trace[512952376] linearizableReadLoop","detail":"{readStateIndex:4697; appliedIndex:4696; }","duration":"558.406335ms","start":"2024-07-19T20:26:27.714Z","end":"2024-07-19T20:26:28.273Z","steps":["trace[512952376] 'read index received' (duration: 15.459µs)","trace[512952376] 'applied index is now lower than readState.Index' (duration: 558.390209ms)"],"step_count":2} {"level":"info","ts":"2024-07-19T20:26:28.273Z","caller":"traceutil/trace.go:171","msg":"trace[2096251078] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:4240; }","duration":"5.125443211s","start":"2024-07-19T20:26:23.147Z","end":"2024-07-19T20:26:28.273Z","steps":["trace[2096251078] 'process raft request' (duration: 753.901257ms)","trace[2096251078] 'get key's previous created_revision and leaseID' (duration: 4.37124003s)"],"step_count":2} {"level":"warn","ts":"2024-07-19T20:26:28.273Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-19T20:26:23.147Z","time spent":"5.125515046s","remote":"172.18.0.4:52020","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} {"level":"warn","ts":"2024-07-19T20:26:28.273Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"558.550463ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2024-07-19T20:26:28.273Z","caller":"traceutil/trace.go:171","msg":"trace[583032573] range","detail":"{range_begin:health; range_end:; response_count:0; response_revision:4240; }","duration":"558.604589ms","start":"2024-07-19T20:26:27.714Z","end":"2024-07-19T20:26:28.273Z","steps":["trace[583032573] 'agreement among raft nodes before linearized reading' (duration: 558.454877ms)"],"step_count":1} {"level":"warn","ts":"2024-07-19T20:26:28.273Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-19T20:26:27.714Z","time spent":"558.644924ms","remote":"127.0.0.1:57750","response type":"/etcdserverpb.KV/Range","request count":0,"request size":8,"response count":0,"response size":29,"request content":"key:\"health\" "} {"level":"warn","ts":"2024-07-19T20:26:30.756Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"2.126042125s","expected-duration":"100ms","prefix":"","request":"header: put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} {"level":"info","ts":"2024-07-19T20:26:30.756Z","caller":"traceutil/trace.go:171","msg":"trace[1742953296] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:4241; }","duration":"2.482687125s","start":"2024-07-19T20:26:28.274Z","end":"2024-07-19T20:26:30.756Z","steps":["trace[1742953296] 'process raft request' (duration: 356.438578ms)","trace[1742953296] 'get key's previous created_revision and leaseID' (duration: 2.125923413s)"],"step_count":2} {"level":"warn","ts":"2024-07-19T20:26:30.756Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-19T20:26:28.274Z","time spent":"2.482726543s","remote":"172.18.0.4:52020","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} {"level":"warn","ts":"2024-07-19T20:26:30.756Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-19T20:26:28.274Z","time spent":"2.482540496s","remote":"127.0.0.1:57750","response type":"/etcdserverpb.Maintenance/Alarm","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} {"level":"warn","ts":"2024-07-19T20:26:36.224Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.25964568s","expected-duration":"100ms","prefix":"","request":"header: put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} {"level":"info","ts":"2024-07-19T20:26:36.225Z","caller":"traceutil/trace.go:171","msg":"trace[91793388] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:4242; }","duration":"4.926674898s","start":"2024-07-19T20:26:31.298Z","end":"2024-07-19T20:26:36.225Z","steps":["trace[91793388] 'process raft request' (duration: 666.76842ms)","trace[91793388] 'get key's previous created_revision and leaseID' (duration: 4.259539302s)"],"step_count":2} {"level":"warn","ts":"2024-07-19T20:26:36.225Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-19T20:26:31.298Z","time spent":"4.926785859s","remote":"172.18.0.4:52020","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "}

xiaofan-luan commented 3 months ago

{"level":"info","ts":"2024-07-19T20:26:21.714Z","caller":"traceutil/trace.go:171","msg":"trace[1128419264] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:4239; }","duration":"1.566294941s","start":"2024-07-19T20:26:20.147Z","end":"2024-07-19T20:26:21.714Z","steps":["trace[1128419264] 'process raft request' (duration: 1.566191688s)"],"step_count":1}

{"level":"info","ts":"2024-07-19T20:26:21.714Z","caller":"traceutil/trace.go:171","msg":"trace[1128419264] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:4239; }","duration":"1.566294941s","start":"2024-07-19T20:26:20.147Z","end":"2024-07-19T20:26:21.714Z","steps":["trace[1128419264] 'process raft request' (duration: 1.566191688s)"],"step_count":1}

if you look at your trace, the etcd seems to be super slow 1.5s (We expect it to be 10ms )

what kind of disk are u using for etcd? I would recommend to use ssd (not really need to be ssd) or ebs

lukezx3 commented 3 months ago

{"level":"info","ts":"2024-07-19T20:26:21.714Z","caller":"traceutil/trace.go:171","msg":"trace[1128419264] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:4239; }","duration":"1.566294941s","start":"2024-07-19T20:26:20.147Z","end":"2024-07-19T20:26:21.714Z","steps":["trace[1128419264] 'process raft request' (duration: 1.566191688s)"],"step_count":1}

{"level":"info","ts":"2024-07-19T20:26:21.714Z","caller":"traceutil/trace.go:171","msg":"trace[1128419264] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:4239; }","duration":"1.566294941s","start":"2024-07-19T20:26:20.147Z","end":"2024-07-19T20:26:21.714Z","steps":["trace[1128419264] 'process raft request' (duration: 1.566191688s)"],"step_count":1}

if you look at your trace, the etcd seems to be super slow 1.5s (We expect it to be 10ms )

what kind of disk are u using for etcd? I would recommend to use ssd (not really need to be ssd) or ebs

Hi im using m1 MacBook Pro I think 2020 version. Not exactly sure what disk it is but it’s 16 GB RAM. I’m running all my code/milvus docker containers on a VMware machine though. I’ve given it 12GB ram and 4 CPU cores. I’m not sure how to prevent etcd from being unhealthy or how to resolve the 1.5s issue. What do you suggest?

xiaofan-luan commented 3 months ago

100k data seems not to be a huge amount of data.12GB should be good enough to run it and mac has ssd for sure.

  1. could you show me your code to insert into milvus? Did you try to flush every time you do insert?
  2. how many partititons do you have?
lukezx3 commented 3 months ago

100k data seems not to be a huge amount of data.12GB should be good enough to run it and mac has ssd for sure.

  1. could you show me your code to insert into milvus? Did you try to flush every time you do insert?
  2. how many partititons do you have?

hi yes i have 16 partitions (default because im using partition_key_field). the following is my code

` for j in range(10): k = j * 10000 testData = [] for i in range(k, k+10000):

    testDict = {}
    vector = [round(random.uniform(-1.0, 1.0), 16) for _ in range(1536)]
    text = "text" + str(i)

    if i < k + 1000:
        sku = "sku0"
    elif i < k + 2000:
        sku = "sku1"
    elif i < k + 3000:
        sku = "sku2"
    elif i < k + 4000:
        sku = "sku3"
    elif i < k + 5000:
        sku = "sku4"
    elif i < k + 6000:
        sku = "sku5"
    elif i < k + 7000:
        sku = "sku6"
    elif i < k + 8000:
        sku = "sku7"
    elif i < k + 9000:
        sku = "sku8"
    else:
        sku = "sku9"

    metadataKey = "m" + str(i)
    metadataValue = "meta" + str(i)
    metadata = {metadataKey: metadataValue}

    testDict["vector"] = vector
    testDict["text"] = text
    testDict["sku"] = sku
    testDict["metadata"] = metadata
    testData.append(testDict)

insertData = client.insert(
    collection_name="partitions",
    data=testData,
    timeout=3600
)
insertData2 = client.insert(
    collection_name="noPartitions",
    data=testData,
    timeout=3600
)`
xiaofan-luan commented 3 months ago

did you clean the testData for each iteration? Otherwise your test data become larger and larger on each iteration

lukezx3 commented 3 months ago

did you clean the testData for each iteration? Otherwise your test data become larger and larger on each iteration

Yes I’m not sure why but the outer for loop didn’t go in the code block. But you can see I reset with testData = []. What other issue may cause etcd unhealthy/milvus standalone crash because it seems to be a standard batch insertion and memory and cpu core # are fine.

xiaofan-luan commented 3 months ago

where did you rest the testData? from the code it is reset outside the loop

lukezx3 commented 3 months ago

where did you rest the testData? from the code it is reset outside the loop

I have for I in range(10): and then I reset testData=[] within that for loop so the script inserts 10k record at a time

xiaofan-luan commented 3 months ago

could you offer milvus log?

lukezx3 commented 3 months ago

could you offer milvus log?

I have milvus logs in my very first issue description at the top. Or which logs do you want?

xiaofan-luan commented 3 months ago
  1. how many data are there in your milvus cluster? try to count it.
  2. use https://github.com/milvus-io/milvus/blob/166fc902b019ea00fec76420307cb4f8f8d700b3/deployments/export-log/README.md?plain=1#L5 to collect your cluster log
lukezx3 commented 3 months ago
  1. how many data are there in your milvus cluster? try to count it.
  2. use https://github.com/milvus-io/milvus/blob/166fc902b019ea00fec76420307cb4f8f8d700b3/deployments/export-log/README.md?plain=1#L5 to collect your cluster log

  1. ive restarted with (sudo docker compose down -> rm -rf volumes) many times but once insertion hits around 130k+ records, always the same issue.

  2. im on standalone on docker compose so export-milvus-log.sh not supported but here are the logs:

milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:29.730Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_AUTO_COMPACTION_MODE","variable-value":"revision"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:29.730Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_AUTO_COMPACTION_RETENTION","variable-value":"1000"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:29.731Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_QUOTA_BACKEND_BYTES","variable-value":"1024967296"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:29.731Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_SNAPSHOT_COUNT","variable-value":"300000"} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:29.731Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_UNSUPPORTED_ARCH=arm64"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:29.731Z","caller":"etcdmain/etcd.go:73","msg":"Running: ","args":["etcd","-advertise-client-urls=http://127.0.0.1:2379","-listen-client-urls","http://0.0.0.0:2379","--data-dir","/etcd"]} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:29.734Z","caller":"etcdmain/etcd.go:116","msg":"server has been already initialized","data-dir":"/etcd","dir-type":"member"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:29.734Z","caller":"embed/etcd.go:124","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:29.735Z","caller":"embed/etcd.go:132","msg":"configuring client listeners","listen-client-urls":["http://0.0.0.0:2379"]} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:29.738Z","caller":"embed/etcd.go:306","msg":"starting an etcd server","etcd-version":"3.5.5","git-sha":"19002cfc6","go-version":"go1.16.15","go-os":"linux","go-arch":"arm64","max-cpu-set":4,"max-cpu-available":4,"member-initialized":true,"name":"default","data-dir":"/etcd","wal-dir":"","wal-dir-dedicated":"","member-dir":"/etcd/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","initial-election-tick-advance":true,"snapshot-count":300000,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://127.0.0.1:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"","initial-cluster-state":"new","initial-cluster-token":"","quota-backend-bytes":1024967296,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"revision","auto-compaction-retention":"1µs","auto-compaction-interval":"1µs","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"} milvus-etcd | {"level":"warn","ts":1721778929.738485,"caller":"fileutil/fileutil.go:57","msg":"check file permission","error":"directory \"/etcd\" exist, but the permission is \"drwxr-xr-x\". The recommended permission is \"-rwx------\" to prevent possible unprivileged access to the data"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:30.076Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/etcd/member/snap/db","took":"330.408491ms"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:31.122Z","caller":"etcdserver/server.go:530","msg":"No snapshot found. Recovering WAL from scratch!"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.152Z","caller":"etcdserver/raft.go:529","msg":"restarting local member","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","commit-index":10740} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.152Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=()"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.153Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 3"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.153Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 8e9e05c52164694d [peers: [], term: 3, commit: 10740, applied: 0, lastindex: 10740, lastterm: 3]"} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:32.156Z","caller":"auth/store.go:1233","msg":"simple token is not cryptographically signed"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.157Z","caller":"mvcc/kvstore.go:323","msg":"restored last compact revision","meta-bucket-name":"meta","meta-bucket-name-key":"finishedCompactRev","restored-compact-revision":8294} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.160Z","caller":"mvcc/kvstore.go:393","msg":"kvstore restored","current-rev":9294} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.163Z","caller":"etcdserver/quota.go:117","msg":"enabled backend quota","quota-name":"v3-applier","quota-size-bytes":1024967296,"quota-size":"1.0 GB"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.166Z","caller":"etcdserver/server.go:854","msg":"starting etcd server","local-member-id":"8e9e05c52164694d","local-server-version":"3.5.5","cluster-version":"to_be_decided"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.166Z","caller":"etcdserver/server.go:754","msg":"starting initial election tick advance","election-ticks":10} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.166Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.166Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","added-peer-id":"8e9e05c52164694d","added-peer-peer-urls":["http://localhost:2380"]} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.166Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","cluster-version":"3.5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.166Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.167Z","caller":"embed/etcd.go:275","msg":"now serving peer/client/metrics","local-member-id":"8e9e05c52164694d","initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://127.0.0.1:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[]} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.167Z","caller":"embed/etcd.go:584","msg":"serving peer traffic","address":"127.0.0.1:2380"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:32.167Z","caller":"embed/etcd.go:556","msg":"cmux::serve","address":"127.0.0.1:2380"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.355Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d is starting a new election at term 3"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.356Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became pre-candidate at term 3"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.356Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgPreVoteResp from 8e9e05c52164694d at term 3"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.356Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became candidate at term 4"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.356Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgVoteResp from 8e9e05c52164694d at term 4"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.356Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became leader at term 4"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.356Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 8e9e05c52164694d elected leader 8e9e05c52164694d at term 4"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.356Z","caller":"etcdserver/server.go:2054","msg":"published local member to cluster through raft","local-member-id":"8e9e05c52164694d","local-member-attributes":"{Name:default ClientURLs:[http://127.0.0.1:2379]}","request-path":"/0/members/8e9e05c52164694d/attributes","cluster-id":"cdf818194e3a8c32","publish-timeout":"7s"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.357Z","caller":"embed/serve.go:100","msg":"ready to serve client requests"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.358Z","caller":"embed/serve.go:146","msg":"serving client traffic insecurely; this is strongly discouraged!","address":"[::]:2379"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.358Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:33.358Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:34.366Z","caller":"traceutil/trace.go:171","msg":"trace[412126351] linearizableReadLoop","detail":"{readStateIndex:10754; appliedIndex:10753; }","duration":"151.626283ms","start":"2024-07-23T23:55:34.214Z","end":"2024-07-23T23:55:34.366Z","steps":["trace[412126351] 'read index received' (duration: 69.464546ms)","trace[412126351] 'applied index is now lower than readState.Index' (duration: 82.161362ms)"],"step_count":2} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:34.366Z","caller":"traceutil/trace.go:171","msg":"trace[750983471] transaction","detail":"{read_only:false; response_revision:9299; number_of_response:1; }","duration":"151.720117ms","start":"2024-07-23T23:55:34.214Z","end":"2024-07-23T23:55:34.366Z","steps":["trace[750983471] 'process raft request' (duration: 69.567672ms)","trace[750983471] 'compare' (duration: 82.091528ms)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:34.366Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"151.728658ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/meta/datacoord-meta/channel-removal/by-dev-rootcoord-dml_3_451326693849694588v3\" ","response":"range_response_count:1 size:116"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:34.366Z","caller":"traceutil/trace.go:171","msg":"trace[606185576] range","detail":"{range_begin:by-dev/meta/datacoord-meta/channel-removal/by-dev-rootcoord-dml_3_451326693849694588v3; range_end:; response_count:1; response_revision:9299; }","duration":"151.786283ms","start":"2024-07-23T23:55:34.214Z","end":"2024-07-23T23:55:34.366Z","steps":["trace[606185576] 'agreement among raft nodes before linearized reading' (duration: 151.706699ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:34.961Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"151.179407ms","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074657 > lease_grant:<ttl:30-second id:694d90e20589ba60>","response":"size:41"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:34.961Z","caller":"traceutil/trace.go:171","msg":"trace[255513016] linearizableReadLoop","detail":"{readStateIndex:10757; appliedIndex:10756; }","duration":"190.803772ms","start":"2024-07-23T23:55:34.770Z","end":"2024-07-23T23:55:34.961Z","steps":["trace[255513016] 'read index received' (duration: 36.954694ms)","trace[255513016] 'applied index is now lower than readState.Index' (duration: 153.848662ms)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:34.961Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"190.897481ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/meta/session/rootcoord\" range_end:\"by-dev/meta/session/rootcoore\" ","response":"range_response_count:1 size:264"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:34.961Z","caller":"traceutil/trace.go:171","msg":"trace[1791104904] range","detail":"{range_begin:by-dev/meta/session/rootcoord; range_end:by-dev/meta/session/rootcoore; response_count:1; response_revision:9300; }","duration":"190.924564ms","start":"2024-07-23T23:55:34.770Z","end":"2024-07-23T23:55:34.961Z","steps":["trace[1791104904] 'agreement among raft nodes before linearized reading' (duration: 190.882606ms)"],"step_count":1} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:35.133Z","caller":"traceutil/trace.go:171","msg":"trace[1729208455] transaction","detail":"{read_only:false; response_revision:9301; number_of_response:1; }","duration":"171.525612ms","start":"2024-07-23T23:55:34.962Z","end":"2024-07-23T23:55:35.133Z","steps":["trace[1729208455] 'process raft request' (duration: 132.620164ms)","trace[1729208455] 'compare' (duration: 38.828864ms)"],"step_count":2} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:36.481Z","caller":"traceutil/trace.go:171","msg":"trace[2039756306] linearizableReadLoop","detail":"{readStateIndex:10760; appliedIndex:10759; }","duration":"110.195831ms","start":"2024-07-23T23:55:36.371Z","end":"2024-07-23T23:55:36.481Z","steps":["trace[2039756306] 'read index received' (duration: 71.828467ms)","trace[2039756306] 'applied index is now lower than readState.Index' (duration: 38.367072ms)"],"step_count":2} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:36.481Z","caller":"traceutil/trace.go:171","msg":"trace[1167897362] transaction","detail":"{read_only:false; response_revision:9302; number_of_response:1; }","duration":"110.551748ms","start":"2024-07-23T23:55:36.371Z","end":"2024-07-23T23:55:36.481Z","steps":["trace[1167897362] 'process raft request' (duration: 72.141218ms)","trace[1167897362] 'compare' (duration: 38.297946ms)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:36.481Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"110.278706ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/meta/datacoord-meta/channel-removal/by-dev-rootcoord-dml_1_451326693849694588v1\" ","response":"range_response_count:1 size:116"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:36.481Z","caller":"traceutil/trace.go:171","msg":"trace[289958770] range","detail":"{range_begin:by-dev/meta/datacoord-meta/channel-removal/by-dev-rootcoord-dml_1_451326693849694588v1; range_end:; response_count:1; response_revision:9302; }","duration":"110.312039ms","start":"2024-07-23T23:55:36.371Z","end":"2024-07-23T23:55:36.481Z","steps":["trace[289958770] 'agreement among raft nodes before linearized reading' (duration: 110.250747ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:36.748Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"119.453723ms","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074690 > txn:<compare:<key:\"by-dev/meta/session/id\" version:0 > success:<request_put:<key:\"by-dev/meta/session/id\" value_size:1 >> failure:<>>","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:36.748Z","caller":"traceutil/trace.go:171","msg":"trace[1882020450] linearizableReadLoop","detail":"{readStateIndex:10761; appliedIndex:10760; }","duration":"177.769456ms","start":"2024-07-23T23:55:36.570Z","end":"2024-07-23T23:55:36.748Z","steps":["trace[1882020450] 'read index received' (duration: 58.092358ms)","trace[1882020450] 'applied index is now lower than readState.Index' (duration: 119.676473ms)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:36.748Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"177.545831ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"health\" ","response":"range_response_count:0 size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:36.748Z","caller":"traceutil/trace.go:171","msg":"trace[1128289105] range","detail":"{range_begin:health; range_end:; response_count:0; response_revision:9302; }","duration":"177.561456ms","start":"2024-07-23T23:55:36.570Z","end":"2024-07-23T23:55:36.748Z","steps":["trace[1128289105] 'agreement among raft nodes before linearized reading' (duration: 177.540664ms)"],"step_count":1} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:36.748Z","caller":"traceutil/trace.go:171","msg":"trace[1557288991] transaction","detail":"{read_only:false; number_of_response:0; response_revision:9302; }","duration":"183.056257ms","start":"2024-07-23T23:55:36.565Z","end":"2024-07-23T23:55:36.748Z","steps":["trace[1557288991] 'process raft request' (duration: 63.344159ms)","trace[1557288991] 'compare' (duration: 119.419806ms)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:36.748Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"177.819123ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/meta/session/querycoord\" range_end:\"by-dev/meta/session/querycoore\" ","response":"range_response_count:0 size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:36.748Z","caller":"traceutil/trace.go:171","msg":"trace[207918343] range","detail":"{range_begin:by-dev/meta/session/querycoord; range_end:by-dev/meta/session/querycoore; response_count:0; response_revision:9302; }","duration":"177.852582ms","start":"2024-07-23T23:55:36.570Z","end":"2024-07-23T23:55:36.748Z","steps":["trace[207918343] 'agreement among raft nodes before linearized reading' (duration: 177.812123ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:37.136Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"226.809589ms","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074711 > txn:<compare:<> success:<request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_7_451326693850695112v3\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_6_451326693850695112v2\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_4_451326693850695112v0\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_3_451326693849694588v3\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_5_451326693850695112v1\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_1_451326693849694588v1\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_2_451326693849694588v2\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_0_451326693849694588v0\" value_size:440 > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_5_451326693850695112v1\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_6_451326693850695112v2\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_7_451326693850695112v3\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_0_451326693849694588v0\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_1_451326693849694588v1\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_2_451326693849694588v2\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_3_451326693849694588v3\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_4_451326693850695112v0\" > > failure:<>>","response":"size:167"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:37.136Z","caller":"traceutil/trace.go:171","msg":"trace[929005091] linearizableReadLoop","detail":"{readStateIndex:10768; appliedIndex:10767; }","duration":"365.261681ms","start":"2024-07-23T23:55:36.771Z","end":"2024-07-23T23:55:37.136Z","steps":["trace[929005091] 'read index received' (duration: 138.230882ms)","trace[929005091] 'applied index is now lower than readState.Index' (duration: 227.03034ms)"],"step_count":2} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:37.136Z","caller":"traceutil/trace.go:171","msg":"trace[2060696897] transaction","detail":"{read_only:false; response_revision:9306; number_of_response:16; }","duration":"365.578139ms","start":"2024-07-23T23:55:36.770Z","end":"2024-07-23T23:55:37.136Z","steps":["trace[2060696897] 'process raft request' (duration: 138.553841ms)","trace[2060696897] 'compare' (duration: 226.684923ms)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:37.136Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:55:36.770Z","time spent":"365.605474ms","remote":"172.18.0.4:53830","response type":"/etcdserverpb.KV/Txn","request count":16,"request size":4888,"response count":0,"response size":191,"request content":"compare:<> success:<request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_7_451326693850695112v3\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_6_451326693850695112v2\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_4_451326693850695112v0\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_3_451326693849694588v3\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_5_451326693850695112v1\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_1_451326693849694588v1\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_2_451326693849694588v2\" value_size:440 > request_put:<key:\"by-dev/meta/channelwatch/8/by-dev-rootcoord-dml_0_451326693849694588v0\" value_size:440 > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_5_451326693850695112v1\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_6_451326693850695112v2\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_7_451326693850695112v3\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_0_451326693849694588v0\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_1_451326693849694588v1\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_2_451326693849694588v2\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_3_451326693849694588v3\" > request_delete_range:<key:\"by-dev/meta/channelwatch/-9223372036854775808/by-dev-rootcoord-dml_4_451326693850695112v0\" > > failure:<>"} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:37.136Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"365.41939ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/meta/session/querynode\" range_end:\"by-dev/meta/session/querynodf\" ","response":"range_response_count:1 size:272"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:37.136Z","caller":"traceutil/trace.go:171","msg":"trace[1221993253] range","detail":"{range_begin:by-dev/meta/session/querynode; range_end:by-dev/meta/session/querynodf; response_count:1; response_revision:9306; }","duration":"365.435848ms","start":"2024-07-23T23:55:36.771Z","end":"2024-07-23T23:55:37.136Z","steps":["trace[1221993253] 'agreement among raft nodes before linearized reading' (duration: 365.388848ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:37.136Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:55:36.771Z","time spent":"365.446515ms","remote":"172.18.0.4:53892","response type":"/etcdserverpb.KV/Range","request count":0,"request size":62,"response count":1,"response size":296,"request content":"key:\"by-dev/meta/session/querynode\" range_end:\"by-dev/meta/session/querynodf\" "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:37.137Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"188.073392ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/meta/session/querycoord\" range_end:\"by-dev/meta/session/querycoore\" ","response":"range_response_count:1 size:266"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:37.137Z","caller":"traceutil/trace.go:171","msg":"trace[924970958] range","detail":"{range_begin:by-dev/meta/session/querycoord; range_end:by-dev/meta/session/querycoore; response_count:1; response_revision:9307; }","duration":"188.103893ms","start":"2024-07-23T23:55:36.949Z","end":"2024-07-23T23:55:37.137Z","steps":["trace[924970958] 'agreement among raft nodes before linearized reading' (duration: 188.080976ms)"],"step_count":1} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:37.413Z","caller":"traceutil/trace.go:171","msg":"trace[1333033227] transaction","detail":"{read_only:false; response_revision:9309; number_of_response:1; }","duration":"199.004246ms","start":"2024-07-23T23:55:37.213Z","end":"2024-07-23T23:55:37.412Z","steps":["trace[1333033227] 'process raft request' (duration: 109.61508ms)","trace[1333033227] 'compare' (duration: 89.304125ms)"],"step_count":2} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:37.617Z","caller":"traceutil/trace.go:171","msg":"trace[1818575049] transaction","detail":"{read_only:false; response_revision:9310; number_of_response:1; }","duration":"204.064047ms","start":"2024-07-23T23:55:37.413Z","end":"2024-07-23T23:55:37.617Z","steps":["trace[1818575049] 'process raft request' (duration: 184.770011ms)","trace[1818575049] 'compare' (duration: 19.182994ms)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:37.982Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"177.176622ms","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074727 > txn:<compare:<> success:<request_put:<key:\"by-dev/meta/querycoord-replica/451326693850695112/451326693982076930\" value_size:49 >> failure:<>>","response":"size:16"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:37.982Z","caller":"traceutil/trace.go:171","msg":"trace[867682912] linearizableReadLoop","detail":"{readStateIndex:10775; appliedIndex:10774; }","duration":"267.936791ms","start":"2024-07-23T23:55:37.714Z","end":"2024-07-23T23:55:37.982Z","steps":["trace[867682912] 'read index received' (duration: 90.680794ms)","trace[867682912] 'applied index is now lower than readState.Index' (duration: 177.255456ms)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:37.982Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"267.9835ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/meta/root-coord/credential/grantee-id/e03326696e8a3b16\" range_end:\"by-dev/meta/root-coord/credential/grantee-id/e03326696e8a3b17\" ","response":"range_response_count:1 size:105"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:37.982Z","caller":"traceutil/trace.go:171","msg":"trace[1135346067] range","detail":"{range_begin:by-dev/meta/root-coord/credential/grantee-id/e03326696e8a3b16; range_end:by-dev/meta/root-coord/credential/grantee-id/e03326696e8a3b17; response_count:1; response_revision:9312; }","duration":"268.000791ms","start":"2024-07-23T23:55:37.714Z","end":"2024-07-23T23:55:37.982Z","steps":["trace[1135346067] 'agreement among raft nodes before linearized reading' (duration: 267.960208ms)"],"step_count":1} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:37.982Z","caller":"traceutil/trace.go:171","msg":"trace[1208096038] transaction","detail":"{read_only:false; response_revision:9312; number_of_response:1; }","duration":"268.097416ms","start":"2024-07-23T23:55:37.714Z","end":"2024-07-23T23:55:37.982Z","steps":["trace[1208096038] 'process raft request' (duration: 90.759211ms)","trace[1208096038] 'compare' (duration: 177.115372ms)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:38.721Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"358.886169ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/config\" range_end:\"by-dev/confih\" serializable:true ","response":"range_response_count:0 size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:38.721Z","caller":"traceutil/trace.go:171","msg":"trace[768409726] range","detail":"{range_begin:by-dev/config; range_end:by-dev/confih; response_count:0; response_revision:9313; }","duration":"358.95542ms","start":"2024-07-23T23:55:38.362Z","end":"2024-07-23T23:55:38.721Z","steps":["trace[768409726] 'range keys from in-memory index tree' (duration: 358.876253ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:38.721Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:55:38.362Z","time spent":"358.986461ms","remote":"172.18.0.4:53826","response type":"/etcdserverpb.KV/Range","request count":0,"request size":32,"response count":0,"response size":29,"request content":"key:\"by-dev/config\" range_end:\"by-dev/confih\" serializable:true "} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:40.204Z","caller":"traceutil/trace.go:171","msg":"trace[1563667082] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9314; }","duration":"131.870996ms","start":"2024-07-23T23:55:40.073Z","end":"2024-07-23T23:55:40.204Z","steps":["trace[1563667082] 'process raft request' (duration: 131.811996ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:43.625Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"263.6357ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/config\" range_end:\"by-dev/confih\" serializable:true ","response":"range_response_count:0 size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:43.625Z","caller":"traceutil/trace.go:171","msg":"trace[654113844] range","detail":"{range_begin:by-dev/config; range_end:by-dev/confih; response_count:0; response_revision:9315; }","duration":"263.695242ms","start":"2024-07-23T23:55:43.362Z","end":"2024-07-23T23:55:43.625Z","steps":["trace[654113844] 'range keys from in-memory index tree' (duration: 263.625783ms)"],"step_count":1} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:46.195Z","caller":"traceutil/trace.go:171","msg":"trace[1823002812] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9316; }","duration":"123.603648ms","start":"2024-07-23T23:55:46.072Z","end":"2024-07-23T23:55:46.195Z","steps":["trace[1823002812] 'process raft request' (duration: 123.536981ms)"],"step_count":1} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:49.391Z","caller":"traceutil/trace.go:171","msg":"trace[1094214009] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9317; }","duration":"319.105345ms","start":"2024-07-23T23:55:49.072Z","end":"2024-07-23T23:55:49.391Z","steps":["trace[1094214009] 'process raft request' (duration: 318.95347ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:49.391Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:55:49.072Z","time spent":"319.270345ms","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:52.572Z","caller":"traceutil/trace.go:171","msg":"trace[643859248] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9318; }","duration":"500.585892ms","start":"2024-07-23T23:55:52.072Z","end":"2024-07-23T23:55:52.572Z","steps":["trace[643859248] 'process raft request' (duration: 500.502933ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:52.573Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:55:52.072Z","time spent":"500.658017ms","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:54.709Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"1.347651317s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/config\" range_end:\"by-dev/confih\" serializable:true ","response":"range_response_count:0 size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:54.709Z","caller":"traceutil/trace.go:171","msg":"trace[1548861221] range","detail":"{range_begin:by-dev/config; range_end:by-dev/confih; response_count:0; response_revision:9318; }","duration":"1.34773586s","start":"2024-07-23T23:55:53.361Z","end":"2024-07-23T23:55:54.709Z","steps":["trace[1548861221] 'range keys from in-memory index tree' (duration: 1.347364233s)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:54.709Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:55:53.361Z","time spent":"1.347782276s","remote":"172.18.0.4:53826","response type":"/etcdserverpb.KV/Range","request count":0,"request size":32,"response count":0,"response size":29,"request content":"key:\"by-dev/config\" range_end:\"by-dev/confih\" serializable:true "} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:55.730Z","caller":"traceutil/trace.go:171","msg":"trace[100857704] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9319; }","duration":"658.77992ms","start":"2024-07-23T23:55:55.071Z","end":"2024-07-23T23:55:55.730Z","steps":["trace[100857704] 'process raft request' (duration: 658.68792ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:55:55.730Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:55:55.071Z","time spent":"658.837504ms","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"info","ts":"2024-07-23T23:55:58.358Z","caller":"traceutil/trace.go:171","msg":"trace[1895993853] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9320; }","duration":"286.478568ms","start":"2024-07-23T23:55:58.072Z","end":"2024-07-23T23:55:58.358Z","steps":["trace[1895993853] 'process raft request' (duration: 286.244817ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:00.774Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:55:59.788Z","time spent":"986.506107ms","remote":"127.0.0.1:41538","response type":"/etcdserverpb.Maintenance/Alarm","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:01.585Z","caller":"traceutil/trace.go:171","msg":"trace[1160981365] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9321; }","duration":"513.682152ms","start":"2024-07-23T23:56:01.071Z","end":"2024-07-23T23:56:01.585Z","steps":["trace[1160981365] 'process raft request' (duration: 513.619402ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:01.585Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:01.071Z","time spent":"513.747443ms","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:04.516Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"1.154546004s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/config\" range_end:\"by-dev/confih\" serializable:true ","response":"range_response_count:0 size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:04.516Z","caller":"traceutil/trace.go:171","msg":"trace[1895639188] range","detail":"{range_begin:by-dev/config; range_end:by-dev/confih; response_count:0; response_revision:9321; }","duration":"1.154638963s","start":"2024-07-23T23:56:03.361Z","end":"2024-07-23T23:56:04.516Z","steps":["trace[1895639188] 'range keys from in-memory index tree' (duration: 1.154523295s)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:04.516Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:03.361Z","time spent":"1.154679713s","remote":"172.18.0.4:53826","response type":"/etcdserverpb.KV/Range","request count":0,"request size":32,"response count":0,"response size":29,"request content":"key:\"by-dev/config\" range_end:\"by-dev/confih\" serializable:true "} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:04.650Z","caller":"traceutil/trace.go:171","msg":"trace[1058848019] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9322; }","duration":"578.129867ms","start":"2024-07-23T23:56:04.072Z","end":"2024-07-23T23:56:04.650Z","steps":["trace[1058848019] 'process raft request' (duration: 578.061241ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:04.650Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:04.072Z","time spent":"578.189742ms","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:07.605Z","caller":"traceutil/trace.go:171","msg":"trace[1411999864] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9323; }","duration":"533.077433ms","start":"2024-07-23T23:56:07.072Z","end":"2024-07-23T23:56:07.605Z","steps":["trace[1411999864] 'process raft request' (duration: 533.011808ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:07.605Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:07.072Z","time spent":"533.145766ms","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:10.615Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"2.254132601s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/config\" range_end:\"by-dev/confih\" serializable:true ","response":"range_response_count:0 size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:10.616Z","caller":"traceutil/trace.go:171","msg":"trace[568449473] range","detail":"{range_begin:by-dev/config; range_end:by-dev/confih; response_count:0; response_revision:9323; }","duration":"2.254207102s","start":"2024-07-23T23:56:08.361Z","end":"2024-07-23T23:56:10.616Z","steps":["trace[568449473] 'range keys from in-memory index tree' (duration: 2.254121393s)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:10.616Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:08.361Z","time spent":"2.254244852s","remote":"172.18.0.4:53826","response type":"/etcdserverpb.KV/Range","request count":0,"request size":32,"response count":0,"response size":29,"request content":"key:\"by-dev/config\" range_end:\"by-dev/confih\" serializable:true "} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:10.616Z","caller":"traceutil/trace.go:171","msg":"trace[1361288002] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9324; }","duration":"543.559712ms","start":"2024-07-23T23:56:10.072Z","end":"2024-07-23T23:56:10.615Z","steps":["trace[1361288002] 'process raft request' (duration: 536.86207ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:10.616Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:10.072Z","time spent":"543.725337ms","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:13.366Z","caller":"traceutil/trace.go:171","msg":"trace[499212259] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9325; }","duration":"293.77155ms","start":"2024-07-23T23:56:13.072Z","end":"2024-07-23T23:56:13.366Z","steps":["trace[499212259] 'process raft request' (duration: 293.724633ms)"],"step_count":1} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:19.215Z","caller":"traceutil/trace.go:171","msg":"trace[1832467815] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9327; }","duration":"143.516618ms","start":"2024-07-23T23:56:19.071Z","end":"2024-07-23T23:56:19.215Z","steps":["trace[1832467815] 'process raft request' (duration: 143.404451ms)"],"step_count":1} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:26.907Z","caller":"traceutil/trace.go:171","msg":"trace[871518124] transaction","detail":"{read_only:false; response_revision:9330; number_of_response:4; }","duration":"152.464598ms","start":"2024-07-23T23:56:26.754Z","end":"2024-07-23T23:56:26.907Z","steps":["trace[871518124] 'process raft request' (duration: 152.344972ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:31.373Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:30.817Z","time spent":"555.801212ms","remote":"127.0.0.1:38580","response type":"/etcdserverpb.Maintenance/Alarm","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:31.954Z","caller":"traceutil/trace.go:171","msg":"trace[1011623412] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9332; }","duration":"882.643132ms","start":"2024-07-23T23:56:31.071Z","end":"2024-07-23T23:56:31.954Z","steps":["trace[1011623412] 'process raft request' (duration: 882.461215ms)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:31.954Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:31.071Z","time spent":"882.738674ms","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:37.834Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.4718546s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"by-dev/config\" range_end:\"by-dev/confih\" serializable:true ","response":"range_response_count:0 size:5"} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:37.834Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"2.749334113s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074759 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:37.834Z","caller":"traceutil/trace.go:171","msg":"trace[1289492442] range","detail":"{range_begin:by-dev/config; range_end:by-dev/confih; response_count:0; response_revision:9332; }","duration":"4.471983934s","start":"2024-07-23T23:56:33.362Z","end":"2024-07-23T23:56:37.834Z","steps":["trace[1289492442] 'range keys from in-memory index tree' (duration: 4.471843184s)"],"step_count":1} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:37.834Z","caller":"traceutil/trace.go:171","msg":"trace[2083412284] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9333; }","duration":"3.761723784s","start":"2024-07-23T23:56:34.072Z","end":"2024-07-23T23:56:37.834Z","steps":["trace[2083412284] 'process raft request' (duration: 1.012289921s)","trace[2083412284] 'get key's previous created_revision and leaseID' (duration: 2.74927078s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:37.834Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:33.362Z","time spent":"4.472023643s","remote":"172.18.0.4:53826","response type":"/etcdserverpb.KV/Range","request count":0,"request size":32,"response count":0,"response size":29,"request content":"key:\"by-dev/config\" range_end:\"by-dev/confih\" serializable:true "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:37.834Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:34.072Z","time spent":"3.761779035s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:40.361Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"969.642729ms","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074760 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:40.361Z","caller":"traceutil/trace.go:171","msg":"trace[677528614] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9334; }","duration":"2.526626501s","start":"2024-07-23T23:56:37.834Z","end":"2024-07-23T23:56:40.361Z","steps":["trace[677528614] 'process raft request' (duration: 1.556711938s)","trace[677528614] 'get key's previous created_revision and leaseID' (duration: 969.533604ms)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:40.361Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:37.834Z","time spent":"2.526683086s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:44.006Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"1.662694918s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074761 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:44.006Z","caller":"traceutil/trace.go:171","msg":"trace[1924704217] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9335; }","duration":"3.13419843s","start":"2024-07-23T23:56:40.872Z","end":"2024-07-23T23:56:44.006Z","steps":["trace[1924704217] 'process raft request' (duration: 1.471292553s)","trace[1924704217] 'get key's previous created_revision and leaseID' (duration: 1.662528043s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:44.007Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:40.872Z","time spent":"3.134485432s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:49.029Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.202100535s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074762 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:49.029Z","caller":"traceutil/trace.go:171","msg":"trace[1052665579] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9336; }","duration":"5.020416753s","start":"2024-07-23T23:56:44.008Z","end":"2024-07-23T23:56:49.029Z","steps":["trace[1052665579] 'process raft request' (duration: 818.271675ms)","trace[1052665579] 'get key's previous created_revision and leaseID' (duration: 4.201975119s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:49.029Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:44.008Z","time spent":"5.020470378s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:53.691Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.063405253s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074763 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:56:53.691Z","caller":"traceutil/trace.go:171","msg":"trace[1872326469] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9337; }","duration":"4.661698033s","start":"2024-07-23T23:56:49.029Z","end":"2024-07-23T23:56:53.691Z","steps":["trace[1872326469] 'process raft request' (duration: 598.053154ms)","trace[1872326469] 'get key's previous created_revision and leaseID' (duration: 4.063328753s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:56:53.691Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:49.029Z","time spent":"4.661817407s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:00.151Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.754187565s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074764 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-standalone | 2024/07/23 23:55:30 maxprocs: Leaving GOMAXPROCS=4: CPU quota undefined milvus-standalone | milvus-standalone | __ _________ _ ____ ______ milvus-standalone | / |/ / _/ /| | / / / / / __/ milvus-standalone | / /|_/ // // /_| |/ / /_/ /\ \ milvus-standalone | /_/ /_/___/____/___/\____/___/ milvus-standalone | milvus-standalone | Welcome to use Milvus! milvus-standalone | Version: v2.4.4 milvus-standalone | Built: Fri May 31 10:25:16 UTC 2024 milvus-standalone | GitCommit: 8e7f36d9 milvus-standalone | GoVersion: go version go1.20.7 linux/arm64 milvus-standalone | milvus-standalone | TotalMem: 12224229376 milvus-standalone | UsedMem: 24276992 milvus-standalone | milvus-standalone | open pid file: /run/milvus/standalone.pid milvus-standalone | lock pid file: /run/milvus/standalone.pid milvus-standalone | [2024/07/23 23:55:30.166 +00:00] [INFO] [roles/roles.go:306] ["starting running Milvus components"] milvus-standalone | [2024/07/23 23:55:30.166 +00:00] [INFO] [roles/roles.go:169] ["Enable Jemalloc"] ["Jemalloc Path"=/milvus/lib/libjemalloc.so] milvus-standalone | [2024/07/23 23:55:30.172 +00:00] [DEBUG] [config/refresher.go:67] ["start refreshing configurations"] [source=FileSource] milvus-standalone | [2024/07/23 23:55:30.172 +00:00] [DEBUG] [config/etcd_source.go:50] ["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}"] milvus-standalone | [2024/07/23 23:55:30.172 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3] milvus-standalone | [2024/07/23 23:55:33.359 +00:00] [DEBUG] [config/etcd_source.go:89] ["etcd refreshConfigurations"] [prefix=by-dev/config] [endpoints="[etcd:2379]"] milvus-standalone | [2024/07/23 23:55:33.361 +00:00] [DEBUG] [config/refresher.go:67] ["start refreshing configurations"] [source=EtcdSource] milvus-standalone | [2024/07/23 23:55:33.361 +00:00] [INFO] [paramtable/hook_config.go:21] ["hook config"] [hook={}] milvus-standalone | [2024/07/23 23:55:33.361 +00:00] [INFO] [roles/roles.go:255] [setupPrometheusHTTPServer] milvus-standalone | [2024/07/23 23:55:33.361 +00:00] [DEBUG] [config/refresher.go:67] ["start refreshing configurations"] [source=FileSource] milvus-standalone | [2024/07/23 23:55:33.362 +00:00] [INFO] [http/server.go:112] ["management listen"] [addr=:9091] milvus-standalone | [2024/07/23 23:55:33.362 +00:00] [INFO] [rootcoord/root_coord.go:154] ["update rootcoord state"] [state=Abnormal] milvus-standalone | [2024/07/23 23:55:33.362 +00:00] [DEBUG] [rootcoord/service.go:184] ["init params done.."] milvus-standalone | [2024/07/23 23:55:33.362 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3] milvus-standalone | [2024/07/23 23:55:33.362 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3] milvus-standalone | [2024/07/23 23:55:33.362 +00:00] [INFO] [components/index_coord.go:38] ["IndexCoord running ..."] milvus-standalone | [2024/07/23 23:55:33.362 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3] milvus-standalone | [2024/07/23 23:55:33.363 +00:00] [DEBUG] [rootcoord/service.go:204] ["etcd connect done ..."] milvus-standalone | [2024/07/23 23:55:33.363 +00:00] [DEBUG] [rootcoord/service.go:264] ["start grpc "] [port=53100] milvus-standalone | [2024/07/23 23:55:33.363 +00:00] [DEBUG] [datacoord/service.go:150] ["network port"] [port=13333] milvus-standalone | [2024/07/23 23:55:33.363 +00:00] [DEBUG] [querynode/service.go:104] [QueryNode] [port=21123] milvus-standalone | [2024/07/23 23:55:33.363 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [DEBUG] [indexnode/indexnode.go:115] ["New IndexNode ..."] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [DEBUG] [querycoord/service.go:218] [network] [port=19531] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [DEBUG] [indexnode/service.go:87] [IndexNode] ["network address"=172.18.0.4:21121] ["network port: "=21121] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [INFO] [datanode/service.go:256] ["DataNode address"] [address=172.18.0.4:21124] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [INFO] [datanode/service.go:257] ["DataNode serverID"] [serverID=0] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [INFO] [proxy/lb_policy.go:78] ["use look_aside policy on replica selection"] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [DEBUG] [querynode/service.go:124] ["QueryNode connect to etcd successfully"] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [INFO] [runtime/asm_arm64.s:1172] ["Start check query node health loop"] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [DEBUG] [proxy/simple_rate_limiter.go:225] ["RateLimiter register for rateType"] [rateType=DDLCollection] [rateLimit=+inf] [burst=1.7976931348623157e+308] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [DEBUG] [proxy/simple_rate_limiter.go:225] ["RateLimiter register for rateType"] [rateType=DDLPartition] [rateLimit=+inf] [burst=1.7976931348623157e+308] milvus-standalone | [2024/07/23 23:55:33.364 +00:00] [INFO] [hookutil/hook.go:46] ["empty so path, skip to load plugin"] milvus-standalone | [2024/07/23 23:55:33.365 +00:00] [DEBUG] [proxy/service.go:122] ["create a new Proxy instance"] [state=2] milvus-standalone | [2024/07/23 23:55:33.365 +00:00] [DEBUG] [proxy/service.go:423] ["init Proxy server"] milvus-standalone | [2024/07/23 23:55:33.365 +00:00] [DEBUG] [proxy/service.go:454] ["Proxy init service's parameter table done"] milvus-standalone | [2024/07/23 23:55:33.365 +00:00] [DEBUG] [proxy/service.go:456] ["Proxy init http server's parameter table done"] milvus-standalone | [2024/07/23 23:55:33.365 +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] milvus-standalone | [2024/07/23 23:55:33.365 +00:00] [INFO] [accesslog/global.go:145] ["Init access logger success"] milvus-standalone | [2024/07/23 23:55:33.365 +00:00] [DEBUG] [proxy/service.go:470] ["init Proxy's tracer done"] ["service name"="Proxy ip: 172.18.0.4, port: 19530"] milvus-standalone | [2024/07/23 23:55:33.365 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3] milvus-standalone | [2024/07/23 23:55:33.365 +00:00] [INFO] [proxy/service.go:370] ["Proxy internal server listen on tcp"] [port=19529] milvus-standalone | [2024/07/23 23:55:33.365 +00:00] [INFO] [proxy/service.go:377] ["Proxy internal server already listen on tcp"] [port=19529] milvus-standalone | [2024/07/23 23:55:33.365 +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}"] milvus-standalone | [2024/07/23 23:55:33.365 +00:00] [INFO] [proxy/service.go:502] ["Proxy server listen on tcp"] [port=19530] milvus-standalone | [2024/07/23 23:55:33.365 +00:00] [INFO] [proxy/service.go:505] ["Proxy server already listen on tcp"] [port=19530] milvus-standalone | [2024/07/23 23:55:33.366 +00:00] [DEBUG] [proxy/service.go:266] ["Get proxy rate limiter done"] [port=19530] milvus-standalone | [2024/07/23 23:55:33.366 +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}"] milvus-standalone | [2024/07/23 23:55:33.366 +00:00] [INFO] [proxy/service.go:586] ["register Proxy http server"] milvus-standalone | [2024/07/23 23:55:33.366 +00:00] [DEBUG] [proxy/service.go:593] ["create RootCoord client for Proxy"] milvus-standalone | [2024/07/23 23:55:33.366 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3] milvus-standalone | [2024/07/23 23:55:33.366 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:33.367 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:33.367 +00:00] [DEBUG] [proxy/service.go:599] ["create RootCoord client for Proxy done"] milvus-standalone | [2024/07/23 23:55:33.367 +00:00] [DEBUG] [proxy/service.go:602] ["Proxy wait for RootCoord to be healthy"] milvus-standalone | [2024/07/23 23:55:33.367 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:33.367 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.367 +00:00] [WARN] [grpcclient/client.go:554] ["fail to get grpc client"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.367 +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"] milvus-standalone | [2024/07/23 23:55:33.367 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:33.367 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.367 +00:00] [WARN] [grpcclient/client.go:476] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.367 +00:00] [WARN] [grpcclient/client.go:467] ["retry func failed"] [retried=0] [error="empty grpc client: find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.464 +00:00] [INFO] [dependency/factory.go:86] ["try to init mq"] [standalone=true] [mqType=rocksmq] milvus-standalone | [2024/07/23 23:55:33.464 +00:00] [DEBUG] [server/global_rmq.go:39] ["initializing global rmq"] [path=/var/lib/milvus/rdb_data] milvus-standalone | [2024/07/23 23:55:33.464 +00:00] [DEBUG] [querynode/service.go:134] [QueryNode] [State=Initializing] milvus-standalone | [2024/07/23 23:55:33.464 +00:00] [INFO] [querynodev2/server.go:286] ["QueryNode session info"] [metaPath=by-dev/meta] milvus-standalone | [2024/07/23 23:55:33.465 +00:00] [INFO] [datanode/service.go:266] ["initializing RootCoord client for DataNode"] milvus-standalone | [2024/07/23 23:55:33.465 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:33.465 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:33.465 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:33.465 +00:00] [INFO] [etcd/etcd_util.go:49] ["create etcd client"] [useEmbedEtcd=false] [useSSL=false] [endpoints="[etcd:2379]"] [minVersion=1.3] milvus-standalone | [2024/07/23 23:55:33.465 +00:00] [DEBUG] [rootcoord/service.go:221] ["grpc init done ..."] milvus-standalone | [2024/07/23 23:55:33.465 +00:00] [DEBUG] [rootcoord/service.go:224] ["RootCoord start to create DataCoord client"] milvus-standalone | [2024/07/23 23:55:33.466 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:33.465 +00:00] [DEBUG] [server/rocksmq_impl.go:177] ["Start rocksmq"] ["max proc"=4] [parallism=1] ["lru cache"=733453762] milvus-standalone | [2024/07/23 23:55:33.468 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:33.468 +00:00] [DEBUG] [querycoord/service.go:168] ["QueryCoord try to wait for RootCoord ready"] milvus-standalone | [2024/07/23 23:55:33.468 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:33.468 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:33.468 +00:00] [INFO] [indexnode/indexnode.go:207] ["IndexNode init"] [state=Initializing] milvus-standalone | [2024/07/23 23:55:33.468 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:33.468 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:33.469 +00:00] [DEBUG] [rootcoord/service.go:233] ["RootCoord start to create QueryCoord client"] milvus-standalone | [2024/07/23 23:55:33.469 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:33.469 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:33.469 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:33.469 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.469 +00:00] [WARN] [grpcclient/client.go:554] ["fail to get grpc client"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.469 +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"] milvus-standalone | [2024/07/23 23:55:33.469 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:33.469 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.469 +00:00] [WARN] [grpcclient/client.go:554] ["fail to get grpc client"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.469 +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"] milvus-standalone | [2024/07/23 23:55:33.469 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:33.469 +00:00] [INFO] [dependency/factory.go:86] ["try to init mq"] [standalone=true] [mqType=rocksmq] milvus-standalone | [2024/07/23 23:55:33.470 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:33.470 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.470 +00:00] [WARN] [grpcclient/client.go:476] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.470 +00:00] [WARN] [grpcclient/client.go:467] ["retry func failed"] [retried=0] [error="empty grpc client: find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.470 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true] milvus-standalone | [2024/07/23 23:55:33.470 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:33.470 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.470 +00:00] [WARN] [grpcclient/client.go:476] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.471 +00:00] [WARN] [grpcclient/client.go:467] ["retry func failed"] [retried=0] [error="empty grpc client: find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.473 +00:00] [DEBUG] [sessionutil/session_util.go:373] ["Session get serverID success"] [key=id] [ServerId=8] milvus-standalone | [2024/07/23 23:55:33.473 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=querynode] [address=172.18.0.4:21123] [id=8] milvus-standalone | [2024/07/23 23:55:33.473 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="querynode-8\n"] [filePath=/tmp/milvus/server_id_8] milvus-standalone | [2024/07/23 23:55:33.473 +00:00] [INFO] [querynodev2/server.go:160] ["QueryNode init session"] [nodeID=8] ["node address"=172.18.0.4:21123] milvus-standalone | [2024/07/23 23:55:33.474 +00:00] [INFO] [dependency/factory.go:86] ["try to init mq"] [standalone=true] [mqType=rocksmq] milvus-standalone | [2024/07/23 23:55:33.474 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true] milvus-standalone | [2024/07/23 23:55:33.474 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=indexnode] [address=172.18.0.4:21121] [id=8] milvus-standalone | [2024/07/23 23:55:33.474 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="indexnode-8\n"] [filePath=/tmp/milvus/server_id_8] milvus-standalone | [2024/07/23 23:55:33.474 +00:00] [INFO] [indexnode/indexnode.go:214] ["IndexNode init session successful"] [serverID=8] milvus-standalone | WARNING: Logging before InitGoogleLogging() is written to STDERR milvus-standalone | I20240723 23:55:33.474103 17 knowhere_config.cc:107] [KNOWHERE][SetBlasThreshold][milvus] Set faiss::distance_compute_blas_threshold to 16384 milvus-standalone | I20240723 23:55:33.474210 17 knowhere_config.cc:118] [KNOWHERE][SetEarlyStopThreshold][milvus] Set faiss::early_stop_threshold to 0 milvus-standalone | I20240723 23:55:33.474251 17 knowhere_config.cc:54] [KNOWHERE][ShowVersion][milvus] Knowhere Version: v2.3.4 milvus-standalone | I20240723 23:55:33.474371 17 knowhere_config.cc:89] [KNOWHERE][SetSimdType][milvus] FAISS hook NEON milvus-standalone | I20240723 23:55:33.474407 17 Common.cpp:35] [SERVER][SetIndexSliceSize][milvus] set config index slice size (byte): 16777216 milvus-standalone | I20240723 23:55:33.474460 17 Common.cpp:41] [SERVER][SetHighPriorityThreadCoreCoefficient][milvus] set high priority thread pool core coefficient: 10 milvus-standalone | I20240723 23:55:33.474468 17 Common.cpp:48] [SERVER][SetMiddlePriorityThreadCoreCoefficient][milvus] set middle priority thread pool core coefficient: 5 milvus-standalone | I20240723 23:55:33.474475 17 Common.cpp:55] [SERVER][SetLowPriorityThreadCoreCoefficient][milvus] set low priority thread pool core coefficient: 1 milvus-standalone | I20240723 23:55:33.475243 17 thread_pool.h:152] [KNOWHERE][InitGlobalBuildThreadPool][milvus] Init global build thread pool with size 3 milvus-standalone | [2024/07/23 23:55:33.475 +00:00] [INFO] [indexnode/indexnode.go:219] ["init index node done"] [nodeID=8] [Address=172.18.0.4:21121] milvus-standalone | [2024/07/23 23:55:33.475 +00:00] [DEBUG] [indexnode/service.go:74] ["IndexNode init done ..."] milvus-standalone | [2024/07/23 23:55:33.475 +00:00] [INFO] [indexnode/indexnode.go:230] [IndexNode] [State=Healthy] milvus-standalone | [2024/07/23 23:55:33.475 +00:00] [INFO] [indexnode/indexnode.go:233] ["IndexNode start finished"] [] milvus-standalone | [2024/07/23 23:55:33.475 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=indexnode] [ServerID=8] milvus-standalone | [2024/07/23 23:55:33.475 +00:00] [DEBUG] [indexnode/task_scheduler.go:247] ["IndexNode TaskScheduler start build loop ..."] milvus-standalone | [2024/07/23 23:55:33.488 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/indexnode-8] [value="{\"ServerID\":8,\"ServerName\":\"indexnode\",\"Address\":\"172.18.0.4:21121\",\"TriggerKill\":true,\"Version\":\"2.4.4\",\"IndexEngineVersion\":{},\"LeaseID\":7587880247619074581,\"HostName\":\"120ed2a7ad41\",\"EnableDisk\":true}"] milvus-standalone | [2024/07/23 23:55:33.489 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=indexnode] [serverID=8] milvus-standalone | [2024/07/23 23:55:33.491 +00:00] [DEBUG] [indexnode/service.go:209] ["IndexNode Register etcd success"] milvus-standalone | [2024/07/23 23:55:33.491 +00:00] [DEBUG] [indexnode/service.go:78] ["IndexNode start done ..."] milvus-standalone | [2024/07/23 23:55:33.491 +00:00] [DEBUG] [components/index_node.go:57] ["IndexNode successfully started"] milvus-standalone | [2024/07/23 23:55:33.568 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=indexnode] [key=by-dev/meta/session/indexnode-8] milvus-standalone | [2024/07/23 23:55:33.568 +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"] milvus-standalone | [2024/07/23 23:55:33.568 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:33.568 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.568 +00:00] [WARN] [grpcclient/client.go:476] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.671 +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"] milvus-standalone | [2024/07/23 23:55:33.671 +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"] milvus-standalone | [2024/07/23 23:55:33.672 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:33.672 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.672 +00:00] [WARN] [grpcclient/client.go:476] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.672 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:33.672 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.672 +00:00] [WARN] [grpcclient/client.go:476] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.968 +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"] milvus-standalone | [2024/07/23 23:55:33.969 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:33.969 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:33.969 +00:00] [WARN] [grpcclient/client.go:476] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:34.007 +00:00] [INFO] [tso/tso.go:122] ["sync and save timestamp"] [last=2024/07/23 23:21:23.814 +00:00] [save=2024/07/23 23:55:36.998 +00:00] [next=2024/07/23 23:55:33.998 +00:00] milvus-standalone | [2024/07/23 23:55:34.007 +00:00] [INFO] [msgstream/mq_factory.go:18] ["init rocksmq msgstream success"] [path=/var/lib/milvus/rdb_data] milvus-standalone | [2024/07/23 23:55:34.007 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:34.007 +00:00] [INFO] [msgstream/mq_factory.go:18] ["init rocksmq msgstream success"] [path=/var/lib/milvus/rdb_data] milvus-standalone | [2024/07/23 23:55:34.007 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:34.007 +00:00] [DEBUG] [server/rocksmq_retention.go:80] ["Rocksmq retention goroutine start!"] milvus-standalone | [2024/07/23 23:55:34.007 +00:00] [INFO] [msgstream/mq_factory.go:18] ["init rocksmq msgstream success"] [path=/var/lib/milvus/rdb_data] milvus-standalone | [2024/07/23 23:55:34.008 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:34.008 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:34.011 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true] milvus-standalone | [2024/07/23 23:55:34.011 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=indexcoord] [address=172.18.0.4:13333] [id=8] milvus-standalone | [2024/07/23 23:55:34.011 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:34.017 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:34.018 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true] milvus-standalone | [2024/07/23 23:55:34.018 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=rootcoord] [address=172.18.0.4:53100] [id=8] milvus-standalone | [2024/07/23 23:55:34.018 +00:00] [INFO] [rootcoord/root_coord.go:154] ["update rootcoord state"] [state=Initializing] milvus-standalone | [2024/07/23 23:55:34.018 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true] milvus-standalone | [2024/07/23 23:55:34.018 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=datacoord] [address=172.18.0.4:13333] [id=8] milvus-standalone | [2024/07/23 23:55:34.018 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:34.038 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:34.038 +00:00] [INFO] [datacoord/server.go:343] ["init rootcoord client done"] milvus-standalone | [2024/07/23 23:55:34.038 +00:00] [INFO] [tso/tso.go:122] ["sync and save timestamp"] [last=2024/07/23 23:21:23.894 +00:00] [save=2024/07/23 23:55:37.018 +00:00] [next=2024/07/23 23:55:34.018 +00:00] milvus-standalone | [2024/07/23 23:55:34.039 +00:00] [INFO] [rootcoord/root_coord.go:398] ["id allocator initialized"] [root_path=by-dev/kv] [sub_path=gid] [key=idTimestamp] milvus-standalone | [2024/07/23 23:55:34.072 +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"] milvus-standalone | [2024/07/23 23:55:34.072 +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"] milvus-standalone | [2024/07/23 23:55:34.078 +00:00] [INFO] [storage/remote_chunk_manager.go:92] ["remote chunk manager init success."] [remote=aws] [bucketname=a-bucket] [root=files] milvus-standalone | [2024/07/23 23:55:34.078 +00:00] [INFO] [tasks/concurrent_safe_scheduler.go:27] ["query node use concurrent safe scheduler"] [max_concurrency=4] milvus-standalone | [2024/07/23 23:55:34.078 +00:00] [INFO] [storage/remote_chunk_manager.go:92] ["remote chunk manager init success."] [remote=aws] [bucketname=a-bucket] [root=files] milvus-standalone | [2024/07/23 23:55:34.078 +00:00] [INFO] [datacoord/server.go:352] ["init chunk manager factory done"] milvus-standalone | [2024/07/23 23:55:34.078 +00:00] [INFO] [querynodev2/server.go:326] ["queryNode init scheduler"] [policy=fifo] milvus-standalone | [2024/07/23 23:55:34.078 +00:00] [INFO] [datacoord/server.go:655] ["data coordinator connecting to metadata store"] [metaType=etcd] milvus-standalone | [2024/07/23 23:55:34.079 +00:00] [INFO] [datacoord/server.go:668] ["data coordinator successfully connected to metadata store"] [metaType=etcd] milvus-standalone | [2024/07/23 23:55:34.125 +00:00] [INFO] [segments/segment_loader.go:548] ["SegmentLoader created"] [ioPoolSize=32] milvus-standalone | I20240723 23:55:34.125780 24 thread_pool.h:172] [KNOWHERE][InitGlobalSearchThreadPool][milvus] Init global search thread pool with size 4 milvus-standalone | I20240723 23:55:34.125887 24 knowhere_config.cc:89] [KNOWHERE][SetSimdType][milvus] FAISS hook NEON milvus-standalone | [2024/07/23 23:55:34.125 +00:00] [INFO] [querynodev2/server.go:227] ["set up knowhere build pool size"] [pool_size=2] milvus-standalone | [2024/07/23 23:55:34.129 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:34.129 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:34.129 +00:00] [WARN] [grpcclient/client.go:476] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:34.129 +00:00] [INFO] [tso/tso.go:122] ["sync and save timestamp"] [last=2024/07/23 23:42:27.460 +00:00] [save=2024/07/23 23:55:37.039 +00:00] [next=2024/07/23 23:55:34.039 +00:00] milvus-standalone | [2024/07/23 23:55:34.129 +00:00] [INFO] [rootcoord/root_coord.go:422] ["tso allocator initialized"] [root_path=by-dev/kv] [sub_path=gid] [key=idTimestamp] milvus-standalone | [2024/07/23 23:55:34.129 +00:00] [INFO] [rootcoord/root_coord.go:341] ["Using etcd as meta storage."] milvus-standalone | [2024/07/23 23:55:34.129 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:34.129 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:34.129 +00:00] [WARN] [grpcclient/client.go:476] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:34.129 +00:00] [DEBUG] [rootcoord/suffix_snapshot.go:558] ["suffix snapshot GC goroutine start!"] milvus-standalone | [2024/07/23 23:55:34.129 +00:00] [INFO] [rootcoord/meta_table.go:149] ["recover databases"] ["num of dbs"=1] milvus-standalone | I20240723 23:55:34.131922 75 thread_pool.h:53] [KNOWHERE][operator()][knowhere_build0] Successfully set priority of knowhere thread. milvus-standalone | [2024/07/23 23:55:34.134 +00:00] [INFO] [datacoord/index_meta.go:95] ["indexMeta reloadFromKV done"] [duration=55.848145ms] milvus-standalone | [2024/07/23 23:55:34.135 +00:00] [INFO] [rootcoord/meta_table.go:188] ["collections recovered from db"] [db_name=default] [collection_num=2] [partition_num=17] milvus-standalone | [2024/07/23 23:55:34.138 +00:00] [INFO] [rootcoord/meta_table.go:206] ["RootCoord meta table reload done"] [duration=9.226309ms] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_0] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_1] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_2] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_3] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_4] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_5] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_6] milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:00.151Z","caller":"traceutil/trace.go:171","msg":"trace[1805600972] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9338; }","duration":"6.459163189s","start":"2024-07-23T23:56:53.692Z","end":"2024-07-23T23:57:00.151Z","steps":["trace[1805600972] 'process raft request' (duration: 1.704812749s)","trace[1805600972] 'get key's previous created_revision and leaseID' (duration: 4.753964564s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:00.151Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:56:53.692Z","time spent":"6.459284274s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:06.414Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.999354194s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"health\" ","response":"","error":"context deadline exceeded"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:06.414Z","caller":"traceutil/trace.go:171","msg":"trace[1901657653] range","detail":"{range_begin:health; range_end:; }","duration":"4.999476986s","start":"2024-07-23T23:57:01.414Z","end":"2024-07-23T23:57:06.414Z","steps":["trace[1901657653] 'agreement among raft nodes before linearized reading' (duration: 4.999366527s)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:06.414Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:01.414Z","time spent":"4.999532736s","remote":"127.0.0.1:38666","response type":"/etcdserverpb.KV/Range","request count":0,"request size":8,"response count":0,"response size":0,"request content":"key:\"health\" "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:06.736Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"6.157190012s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074765 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:06.736Z","caller":"traceutil/trace.go:171","msg":"trace[1191401434] linearizableReadLoop","detail":"{readStateIndex:10805; appliedIndex:10804; }","duration":"5.321427496s","start":"2024-07-23T23:57:01.414Z","end":"2024-07-23T23:57:06.736Z","steps":["trace[1191401434] 'read index received' (duration: 21.875µs)","trace[1191401434] 'applied index is now lower than readState.Index' (duration: 5.321405079s)"],"step_count":2} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:06.736Z","caller":"traceutil/trace.go:171","msg":"trace[1618179900] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9339; }","duration":"6.584145126s","start":"2024-07-23T23:57:00.152Z","end":"2024-07-23T23:57:06.736Z","steps":["trace[1618179900] 'process raft request' (duration: 426.839865ms)","trace[1618179900] 'get key's previous created_revision and leaseID' (duration: 6.157127594s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:06.736Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:00.152Z","time spent":"6.584229586s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:12.670Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"2.916797869s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074767 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:12.670Z","caller":"traceutil/trace.go:171","msg":"trace[203686683] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9340; }","duration":"5.933514292s","start":"2024-07-23T23:57:06.736Z","end":"2024-07-23T23:57:12.670Z","steps":["trace[203686683] 'process raft request' (duration: 3.016562672s)","trace[203686683] 'get key's previous created_revision and leaseID' (duration: 2.916734619s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:12.670Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:06.736Z","time spent":"5.933555083s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:19.278Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"5.372476585s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074768 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:19.278Z","caller":"traceutil/trace.go:171","msg":"trace[318077011] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9341; }","duration":"6.607940891s","start":"2024-07-23T23:57:12.670Z","end":"2024-07-23T23:57:19.278Z","steps":["trace[318077011] 'process raft request' (duration: 1.235300764s)","trace[318077011] 'get key's previous created_revision and leaseID' (duration: 5.372368418s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:19.278Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:12.670Z","time spent":"6.608117267s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:22.553Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"1.096085619s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074769 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:22.553Z","caller":"traceutil/trace.go:171","msg":"trace[45670887] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9342; }","duration":"3.273959649s","start":"2024-07-23T23:57:19.279Z","end":"2024-07-23T23:57:22.553Z","steps":["trace[45670887] 'process raft request' (duration: 2.177825404s)","trace[45670887] 'get key's previous created_revision and leaseID' (duration: 1.096006453s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:22.553Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:19.279Z","time spent":"3.274029441s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:28.583Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.400656858s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074770 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:28.584Z","caller":"traceutil/trace.go:171","msg":"trace[472440171] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9343; }","duration":"6.030546616s","start":"2024-07-23T23:57:22.553Z","end":"2024-07-23T23:57:28.584Z","steps":["trace[472440171] 'process raft request' (duration: 1.629642174s)","trace[472440171] 'get key's previous created_revision and leaseID' (duration: 4.400497857s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:28.584Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:22.553Z","time spent":"6.03059049s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:33.021Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"3.855014971s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074771 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:33.022Z","caller":"traceutil/trace.go:171","msg":"trace[456176307] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9344; }","duration":"4.4375391s","start":"2024-07-23T23:57:28.584Z","end":"2024-07-23T23:57:33.022Z","steps":["trace[456176307] 'process raft request' (duration: 582.259252ms)","trace[456176307] 'get key's previous created_revision and leaseID' (duration: 3.854898055s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:33.022Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:28.584Z","time spent":"4.437577434s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:40.023Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:33.022Z","time spent":"7.000883989s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":0,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:41.455Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.992347347s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"health\" ","response":"","error":"context deadline exceeded"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:41.455Z","caller":"traceutil/trace.go:171","msg":"trace[2133873114] range","detail":"{range_begin:health; range_end:; }","duration":"4.992421014s","start":"2024-07-23T23:57:36.462Z","end":"2024-07-23T23:57:41.455Z","steps":["trace[2133873114] 'agreement among raft nodes before linearized reading' (duration: 4.99236193s)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:41.455Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:36.462Z","time spent":"4.992475264s","remote":"127.0.0.1:46688","response type":"/etcdserverpb.KV/Range","request count":0,"request size":8,"response count":0,"response size":0,"request content":"key:\"health\" "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:44.338Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"10.96831949s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074772 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:44.338Z","caller":"traceutil/trace.go:171","msg":"trace[1586000249] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9346; }","duration":"4.31453737s","start":"2024-07-23T23:57:40.023Z","end":"2024-07-23T23:57:44.338Z","steps":["trace[1586000249] 'process raft request' (duration: 4.314457203s)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:44.338Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:40.023Z","time spent":"4.31463187s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:44.338Z","caller":"traceutil/trace.go:171","msg":"trace[397145014] linearizableReadLoop","detail":"{readStateIndex:10811; appliedIndex:10810; }","duration":"7.875942519s","start":"2024-07-23T23:57:36.462Z","end":"2024-07-23T23:57:44.338Z","steps":["trace[397145014] 'read index received' (duration: 21µs)","trace[397145014] 'applied index is now lower than readState.Index' (duration: 7.875920727s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:47.771Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"2.005622675s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074775 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:47.771Z","caller":"traceutil/trace.go:171","msg":"trace[1530709263] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9347; }","duration":"3.433032361s","start":"2024-07-23T23:57:44.338Z","end":"2024-07-23T23:57:47.771Z","steps":["trace[1530709263] 'process raft request' (duration: 1.427352853s)","trace[1530709263] 'get key's previous created_revision and leaseID' (duration: 2.005549216s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:47.771Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:44.338Z","time spent":"3.433062152s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:54.261Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"5.176450313s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074776 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:54.261Z","caller":"traceutil/trace.go:171","msg":"trace[555429632] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9348; }","duration":"6.489316755s","start":"2024-07-23T23:57:47.772Z","end":"2024-07-23T23:57:54.261Z","steps":["trace[555429632] 'process raft request' (duration: 1.312731233s)","trace[555429632] 'get key's previous created_revision and leaseID' (duration: 5.176329936s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:54.261Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:47.772Z","time spent":"6.489391964s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:57.968Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"2.893755273s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074777 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:57:57.968Z","caller":"traceutil/trace.go:171","msg":"trace[484276213] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9349; }","duration":"3.706807286s","start":"2024-07-23T23:57:54.262Z","end":"2024-07-23T23:57:57.968Z","steps":["trace[484276213] 'process raft request' (duration: 812.95522ms)","trace[484276213] 'get key's previous created_revision and leaseID' (duration: 2.893620814s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:57:57.969Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:54.262Z","time spent":"3.70685562s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:04.535Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"5.980918673s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074778 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:04.535Z","caller":"traceutil/trace.go:171","msg":"trace[1129755007] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9350; }","duration":"6.566172653s","start":"2024-07-23T23:57:57.969Z","end":"2024-07-23T23:58:04.535Z","steps":["trace[1129755007] 'process raft request' (duration: 585.158438ms)","trace[1129755007] 'get key's previous created_revision and leaseID' (duration: 5.98081863s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:04.535Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:57:57.969Z","time spent":"6.566236904s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:08.260Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"2.87019841s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074779 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:08.260Z","caller":"traceutil/trace.go:171","msg":"trace[1673621073] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9351; }","duration":"3.724240473s","start":"2024-07-23T23:58:04.536Z","end":"2024-07-23T23:58:08.260Z","steps":["trace[1673621073] 'process raft request' (duration: 853.864603ms)","trace[1673621073] 'get key's previous created_revision and leaseID' (duration: 2.870078118s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:08.260Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:04.536Z","time spent":"3.724286056s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:11.275Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"1.900596827s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074780 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:11.275Z","caller":"traceutil/trace.go:171","msg":"trace[1151277160] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9352; }","duration":"3.014053141s","start":"2024-07-23T23:58:08.261Z","end":"2024-07-23T23:58:11.275Z","steps":["trace[1151277160] 'process raft request' (duration: 1.113393397s)","trace[1151277160] 'get key's previous created_revision and leaseID' (duration: 1.90052216s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:11.275Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:08.261Z","time spent":"3.014085599s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:12.001Z","caller":"etcdserver/v3_server.go:840","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":7587880247619074774,"retry-timeout":"500ms"} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:16.501Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"5.000165514s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"health\" ","response":"","error":"context deadline exceeded"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:16.501Z","caller":"traceutil/trace.go:171","msg":"trace[2009971477] range","detail":"{range_begin:health; range_end:; }","duration":"5.000233473s","start":"2024-07-23T23:58:11.500Z","end":"2024-07-23T23:58:16.501Z","steps":["trace[2009971477] 'agreement among raft nodes before linearized reading' (duration: 5.000174556s)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:16.501Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:11.500Z","time spent":"5.000269182s","remote":"127.0.0.1:53642","response type":"/etcdserverpb.KV/Range","request count":0,"request size":8,"response count":0,"response size":0,"request content":"key:\"health\" "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:18.275Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:11.275Z","time spent":"7.000128559s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":0,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:18.763Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"6.54602648s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074781 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:18.763Z","caller":"traceutil/trace.go:171","msg":"trace[1617804222] linearizableReadLoop","detail":"{readStateIndex:10819; appliedIndex:10818; }","duration":"7.26286911s","start":"2024-07-23T23:58:11.500Z","end":"2024-07-23T23:58:18.763Z","steps":["trace[1617804222] 'read index received' (duration: 716.719754ms)","trace[1617804222] 'applied index is now lower than readState.Index' (duration: 6.546148647s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:24.380Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.936723052s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074782 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:24.380Z","caller":"traceutil/trace.go:171","msg":"trace[148870481] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9354; }","duration":"6.104398195s","start":"2024-07-23T23:58:18.276Z","end":"2024-07-23T23:58:24.380Z","steps":["trace[148870481] 'process raft request' (duration: 1.167522435s)","trace[148870481] 'get key's previous created_revision and leaseID' (duration: 4.936610009s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:24.380Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:18.276Z","time spent":"6.104456779s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:27.487Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"1.733911911s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074784 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:27.487Z","caller":"traceutil/trace.go:171","msg":"trace[1075664837] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9355; }","duration":"3.106491093s","start":"2024-07-23T23:58:24.381Z","end":"2024-07-23T23:58:27.487Z","steps":["trace[1075664837] 'process raft request' (duration: 1.372500265s)","trace[1075664837] 'get key's previous created_revision and leaseID' (duration: 1.733827786s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:27.487Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:24.381Z","time spent":"3.106541843s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:34.447Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"5.873969999s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074785 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:34.447Z","caller":"traceutil/trace.go:171","msg":"trace[1561040902] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9356; }","duration":"6.959041652s","start":"2024-07-23T23:58:27.488Z","end":"2024-07-23T23:58:34.447Z","steps":["trace[1561040902] 'process raft request' (duration: 1.084992278s)","trace[1561040902] 'get key's previous created_revision and leaseID' (duration: 5.87385204s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:34.447Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:27.488Z","time spent":"6.95908911s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:39.757Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.556288279s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074786 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:39.757Z","caller":"traceutil/trace.go:171","msg":"trace[1201622465] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9357; }","duration":"5.306255679s","start":"2024-07-23T23:58:34.450Z","end":"2024-07-23T23:58:39.757Z","steps":["trace[1201622465] 'process raft request' (duration: 749.853482ms)","trace[1201622465] 'get key's previous created_revision and leaseID' (duration: 4.556156196s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:39.757Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:34.450Z","time spent":"5.306312429s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:46.309Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"5.698386403s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074787 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:46.309Z","caller":"traceutil/trace.go:171","msg":"trace[681159135] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9358; }","duration":"6.552084703s","start":"2024-07-23T23:58:39.757Z","end":"2024-07-23T23:58:46.309Z","steps":["trace[681159135] 'process raft request' (duration: 853.615925ms)","trace[681159135] 'get key's previous created_revision and leaseID' (duration: 5.69827261s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:46.309Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:39.757Z","time spent":"6.552139619s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:47.043Z","caller":"etcdserver/v3_server.go:840","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":7587880247619074783,"retry-timeout":"500ms"} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:47.544Z","caller":"etcdserver/v3_server.go:840","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":7587880247619074783,"retry-timeout":"500ms"} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:51.542Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"4.99936895s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"health\" ","response":"","error":"context deadline exceeded"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:51.542Z","caller":"traceutil/trace.go:171","msg":"trace[1647957123] range","detail":"{range_begin:health; range_end:; }","duration":"4.999445367s","start":"2024-07-23T23:58:46.543Z","end":"2024-07-23T23:58:51.542Z","steps":["trace[1647957123] 'agreement among raft nodes before linearized reading' (duration: 4.999382367s)"],"step_count":1} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:51.542Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:46.543Z","time spent":"4.999510784s","remote":"127.0.0.1:56294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":8,"response count":0,"response size":0,"request content":"key:\"health\" "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:52.777Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"5.216350622s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074788 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:52.777Z","caller":"traceutil/trace.go:171","msg":"trace[2092948100] linearizableReadLoop","detail":"{readStateIndex:10825; appliedIndex:10824; }","duration":"6.234829392s","start":"2024-07-23T23:58:46.543Z","end":"2024-07-23T23:58:52.777Z","steps":["trace[2092948100] 'read index received' (duration: 1.01839777s)","trace[2092948100] 'applied index is now lower than readState.Index' (duration: 5.216431164s)"],"step_count":2} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:52.777Z","caller":"traceutil/trace.go:171","msg":"trace[2111647581] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9359; }","duration":"6.467484875s","start":"2024-07-23T23:58:46.310Z","end":"2024-07-23T23:58:52.777Z","steps":["trace[2111647581] 'process raft request' (duration: 1.251060877s)","trace[2111647581] 'get key's previous created_revision and leaseID' (duration: 5.216240164s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:52.777Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:46.310Z","time spent":"6.467520167s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:58.653Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"5.388179796s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074790 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:58:58.653Z","caller":"traceutil/trace.go:171","msg":"trace[1718298628] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9360; }","duration":"5.874694118s","start":"2024-07-23T23:58:52.778Z","end":"2024-07-23T23:58:58.653Z","steps":["trace[1718298628] 'process raft request' (duration: 486.433321ms)","trace[1718298628] 'get key's previous created_revision and leaseID' (duration: 5.388094755s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:58:58.653Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:52.778Z","time spent":"5.874727826s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:59:02.560Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"3.223347979s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074791 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-minio | WARNING: MINIO_ACCESS_KEY and MINIO_SECRET_KEY are deprecated. milvus-minio | Please use MINIO_ROOT_USER and MINIO_ROOT_PASSWORD milvus-minio | milvus-minio | You are running an older version of MinIO released 1 year ago milvus-minio | Update: Runmc admin update milvus-minio | milvus-minio | milvus-minio | WARNING: Detected default credentials 'minioadmin:minioadmin', we recommend that you change these values with 'MINIO_ROOT_USER' and 'MINIO_ROOT_PASSWORD' environment variables milvus-minio | MinIO Object Storage Server milvus-minio | Copyright: 2015-2023 MinIO, Inc. milvus-minio | License: GNU AGPLv3 <https://www.gnu.org/licenses/agpl-3.0.html> milvus-minio | Version: RELEASE.2023-03-20T20-16-18Z (go1.19.7 linux/arm64) milvus-minio | milvus-minio | Status: 1 Online, 0 Offline. milvus-minio | API: http://172.18.0.3:9000 http://127.0.0.1:9000 milvus-minio | Console: http://172.18.0.3:9001 http://127.0.0.1:9001 milvus-minio | milvus-minio | Documentation: https://min.io/docs/minio/linux/index.html milvus-minio | Warning: The standard parity is set to 0. This can lead to data loss. milvus-minio | IAM refresh took 16.09s milvus-minio | IAM refresh took 20.83s milvus-minio | IAM refresh took 19.81s milvus-minio | milvus-minio | API: PutObjectPart(bucket=a-bucket, object=files/insert_log/451326693850695112/451326693850695113/451354016879214971/101/451354016879214973) milvus-minio | Time: 00:46:01 UTC 07/24/2024 milvus-minio | DeploymentID: b302a7bd-3994-4813-803b-395648c4f60f milvus-minio | RequestID: 17E4FF531CECC04A milvus-minio | RemoteHost: 172.18.0.4 milvus-minio | Host: minio:9000 milvus-minio | UserAgent: MinIO (linux; arm64) minio-go/v7.0.61 milvus-minio | Error: read tcp 172.18.0.3:9000->172.18.0.4:60864: read: connection timed out (*net.OpError) milvus-minio | 7: internal/logger/logger.go:258:logger.LogIf() milvus-minio | 6: cmd/erasure-encode.go:93:cmd.(*Erasure).Encode() milvus-minio | 5: cmd/erasure-multipart.go:668:cmd.erasureObjects.PutObjectPart() milvus-minio | 4: cmd/erasure-sets.go:927:cmd.(*erasureSets).PutObjectPart() milvus-minio | 3: cmd/erasure-server-pool.go:1452:cmd.(*erasureServerPools).PutObjectPart() milvus-minio | 2: cmd/object-multipart-handlers.go:800:cmd.objectAPIHandlers.PutObjectPartHandler() milvus-minio | 1: net/http/server.go:2109:http.HandlerFunc.ServeHTTP() milvus-minio | milvus-minio | API: PutObjectPart(bucket=a-bucket, object=files/insert_log/451326693850695112/451326693850695113/451354016879214971/101/451354016879214973) milvus-minio | Time: 00:46:08 UTC 07/24/2024 milvus-minio | DeploymentID: b302a7bd-3994-4813-803b-395648c4f60f milvus-minio | RequestID: 17E4FF42F2FBC307 milvus-minio | RemoteHost: 172.18.0.4 milvus-minio | Host: minio:9000 milvus-minio | UserAgent: MinIO (linux; arm64) minio-go/v7.0.61 milvus-minio | Error: read tcp 172.18.0.3:9000->172.18.0.4:55806: read: connection timed out (*net.OpError) milvus-minio | 7: internal/logger/logger.go:258:logger.LogIf() milvus-minio | 6: cmd/erasure-encode.go:93:cmd.(*Erasure).Encode() milvus-minio | 5: cmd/erasure-multipart.go:668:cmd.erasureObjects.PutObjectPart() milvus-minio | 4: cmd/erasure-sets.go:927:cmd.(*erasureSets).PutObjectPart() milvus-minio | 3: cmd/erasure-server-pool.go:1452:cmd.(*erasureServerPools).PutObjectPart() milvus-minio | 2: cmd/object-multipart-handlers.go:800:cmd.objectAPIHandlers.PutObjectPartHandler() milvus-minio | 1: net/http/server.go:2109:http.HandlerFunc.ServeHTTP() milvus-minio | milvus-minio | API: GetObject(bucket=a-bucket, object=files/insert_log/451326693849694588/451326693849694601/451326693851382703/101/451326693850903228) milvus-minio | Time: 02:03:44 UTC 07/24/2024 milvus-minio | DeploymentID: b302a7bd-3994-4813-803b-395648c4f60f milvus-minio | RequestID: 17E4FF6F5A2179CB milvus-minio | RemoteHost: 172.18.0.4 milvus-minio | Host: minio:9000 milvus-minio | UserAgent: aws-sdk-cpp/1.9.234 Linux/5.15.0-92-generic aarch64 GCC/9.4.0 milvus-minio | Error: Unable to write all the data to client write tcp 172.18.0.3:9000->172.18.0.4:40790: write: no route to host (*fmt.wrapError) milvus-minio | 4: internal/logger/logger.go:258:logger.LogIf() milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_7] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_8] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_9] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_10] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_11] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_12] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_13] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_14] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [msgstream/common_mq_factory.go:31] ["Msg Stream state"] [can_produce=true] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [WARN] [server/rocksmq_impl.go:398] ["rocksmq topic already exists "] [topic=by-dev-rootcoord-dml_15] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [rootcoord/dml_channels.go:215] ["init dml channels"] [prefix=by-dev-rootcoord-dml] [num=16] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [rootcoord/timeticksync.go:126] ["recover physical channels"] [collectionID=451326693849694588] ["physical channels"="[by-dev-rootcoord-dml_0,by-dev-rootcoord-dml_1,by-dev-rootcoord-dml_2,by-dev-rootcoord-dml_3]"] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [rootcoord/timeticksync.go:126] ["recover physical channels"] [collectionID=451326693850695112] ["physical channels"="[by-dev-rootcoord-dml_4,by-dev-rootcoord-dml_5,by-dev-rootcoord-dml_6,by-dev-rootcoord-dml_7]"] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [rootcoord/root_coord.go:451] ["create TimeTick sync done"] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [INFO] [rootcoord/root_coord.go:467] ["init proxy manager done"] milvus-standalone | [2024/07/23 23:55:34.139 +00:00] [DEBUG] [rootcoord/root_coord.go:472] ["RootCoord init QuotaCenter done"] milvus-standalone | [2024/07/23 23:55:34.140 +00:00] [INFO] [rootcoord/root_coord.go:477] ["init credentials done"] milvus-standalone | [2024/07/23 23:55:34.142 +00:00] [INFO] [rootcoord/meta_table.go:1266] ["role already exists"] [role=admin] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [INFO] [datacoord/meta.go:163] ["DataCoord meta reloadFromKV done"] [duration=6.800179ms] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [INFO] [datacoord/server.go:1238] ["all old data node down, enable auto balance!"] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [INFO] [rootcoord/meta_table.go:1266] ["role already exists"] [role=public] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [WARN] [grpcclient/client.go:554] ["fail to get grpc client"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:34.143 +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"] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [WARN] [client/client.go:90] ["RootCoordClient mess key not exist"] [key=rootcoord] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [WARN] [grpcclient/client.go:476] ["fail to get grpc client in the retry state"] [client_role=rootcoord] [error="find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [WARN] [grpcclient/client.go:467] ["retry func failed"] [retried=0] [error="empty grpc client: find no available rootcoord, check rootcoord state"] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [INFO] [datacoord/channel_store_v2.go:67] ["channel store reload channel"] [nodeID=-9223372036854775808] [channel=by-dev-rootcoord-dml_0_451326693849694588v0] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [INFO] [datacoord/channel_store_v2.go:67] ["channel store reload channel"] [nodeID=-9223372036854775808] [channel=by-dev-rootcoord-dml_1_451326693849694588v1] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [INFO] [datacoord/channel_store_v2.go:67] ["channel store reload channel"] [nodeID=-9223372036854775808] [channel=by-dev-rootcoord-dml_2_451326693849694588v2] milvus-standalone | [2024/07/23 23:55:34.143 +00:00] [INFO] [datacoord/channel_store_v2.go:67] ["channel store reload channel"] [nodeID=-9223372036854775808] [channel=by-dev-rootcoord-dml_3_451326693849694588v3] milvus-standalone | [2024/07/23 23:55:34.144 +00:00] [INFO] [rootcoord/root_coord.go:483] ["init rootcoord done"] [nodeID=8] [Address=172.18.0.4:53100] milvus-standalone | [2024/07/23 23:55:34.144 +00:00] [DEBUG] [rootcoord/service.go:169] ["RootCoord init done ..."] milvus-standalone | [2024/07/23 23:55:34.144 +00:00] [INFO] [rootcoord/service.go:312] ["RootCoord Core start ..."] milvus-standalone | [2024/07/23 23:55:34.144 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=rootcoord] [ServerID=8] milvus-standalone | [2024/07/23 23:55:34.144 +00:00] [INFO] [datacoord/channel_store_v2.go:67] ["channel store reload channel"] [nodeID=-9223372036854775808] [channel=by-dev-rootcoord-dml_4_451326693850695112v0] milvus-standalone | [2024/07/23 23:55:34.144 +00:00] [INFO] [datacoord/channel_store_v2.go:67] ["channel store reload channel"] [nodeID=-9223372036854775808] [channel=by-dev-rootcoord-dml_5_451326693850695112v1] milvus-standalone | [2024/07/23 23:55:34.144 +00:00] [INFO] [datacoord/channel_store_v2.go:67] ["channel store reload channel"] [nodeID=-9223372036854775808] [channel=by-dev-rootcoord-dml_6_451326693850695112v2] milvus-standalone | [2024/07/23 23:55:34.144 +00:00] [INFO] [datacoord/channel_store_v2.go:67] ["channel store reload channel"] [nodeID=-9223372036854775808] [channel=by-dev-rootcoord-dml_7_451326693850695112v3] milvus-standalone | [2024/07/23 23:55:34.144 +00:00] [INFO] [datacoord/channel_store_v2.go:71] ["channel store reload done"] [duration=686.626µs] milvus-standalone | [2024/07/23 23:55:34.144 +00:00] [INFO] [datacoord/server.go:366] ["init datanode cluster done"] milvus-standalone | I20240723 23:55:34.152923 24 thread_pool.h:188] [KNOWHERE][SetGlobalBuildThreadPoolSize][milvus] Global build thread pool size has already been set to 2 milvus-standalone | I20240723 23:55:34.153002 24 Common.cpp:62] [SERVER][SetDefaultExecEvalExprBatchSize][milvus] set default expr eval batch size: 8192 milvus-standalone | I20240723 23:55:34.153093 24 MinioChunkManager.cpp:161] [SERVER][InitSDKAPIDefault][milvus] init aws with log level:fatal milvus-standalone | [2024/07/23 23:55:34.214 +00:00] [INFO] [datacoord/server.go:572] ["DataCoord success to get DataNode sessions"] [sessions={}] milvus-standalone | [2024/07/23 23:55:34.214 +00:00] [INFO] [datacoord/server.go:593] ["DataCoord Cluster Manager start up"] milvus-standalone | [2024/07/23 23:55:34.344 +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"] milvus-standalone | [2024/07/23 23:55:34.366 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/rootcoord] [value="{\"ServerID\":8,\"ServerName\":\"rootcoord\",\"Address\":\"172.18.0.4:53100\",\"Exclusive\":true,\"TriggerKill\":true,\"Version\":\"2.4.4\",\"IndexEngineVersion\":{},\"LeaseID\":7587880247619074632,\"HostName\":\"120ed2a7ad41\"}"] milvus-standalone | [2024/07/23 23:55:34.366 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=rootcoord] [serverID=8] milvus-standalone | [2024/07/23 23:55:34.366 +00:00] [INFO] [rootcoord/root_coord.go:273] ["RootCoord Register Finished"] milvus-standalone | [2024/07/23 23:55:34.366 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=rootcoord] [key=rootcoord] [address=172.18.0.4:53100] milvus-standalone | [2024/07/23 23:55:34.366 +00:00] [DEBUG] [client/client.go:93] ["RootCoordClient GetSessions success"] [address=172.18.0.4:53100] [serverID=8] milvus-standalone | [2024/07/23 23:55:34.367 +00:00] [INFO] [datacoord/channel_manager_v2.go:162] ["starting channel balance loop"] milvus-standalone | [2024/07/23 23:55:34.367 +00:00] [INFO] [datacoord/channel_manager_v2.go:170] ["cluster start up"] [allNodes="[]"] [legacyNodes="[]"] [oldNodes="[]"] [newOnlines="[]"] [offLines="[]"] milvus-standalone | [2024/07/23 23:55:34.367 +00:00] [INFO] [datacoord/server.go:598] ["DataCoord Cluster Manager start up successfully"] milvus-standalone | [2024/07/23 23:55:34.367 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=indexnode] [key=indexnode-8] [address=172.18.0.4:21121] milvus-standalone | [2024/07/23 23:55:34.367 +00:00] [DEBUG] [datacoord/indexnode_manager.go:84] ["add IndexNode"] [nodeID=8] ["node address"=172.18.0.4:21121] milvus-standalone | [2024/07/23 23:55:34.367 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:34.368 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:34.368 +00:00] [DEBUG] [datacoord/indexnode_manager.go:57] ["set IndexNode client"] [nodeID=8] milvus-standalone | [2024/07/23 23:55:34.368 +00:00] [DEBUG] [datacoord/indexnode_manager.go:62] ["IndexNode IndexNodeManager setClient success"] [nodeID=8] ["IndexNode num"=1] milvus-standalone | [2024/07/23 23:55:34.368 +00:00] [INFO] [datacoord/server.go:373] ["init service discovery done"] milvus-standalone | [2024/07/23 23:55:34.368 +00:00] [INFO] [datacoord/server.go:378] ["init compaction scheduler done"] milvus-standalone | [2024/07/23 23:55:34.370 +00:00] [INFO] [proxyutil/proxy_watcher.go:96] ["succeed to init sessions on etcd"] [sessions=null] [revision=9299] milvus-standalone | [2024/07/23 23:55:34.371 +00:00] [WARN] [grpcclient/client.go:467] ["retry func failed"] [retried=0] [error="service not ready[standalone=8]: Initializing"] milvus-standalone | [2024/07/23 23:55:34.371 +00:00] [INFO] [rootcoord/root_coord.go:154] ["update rootcoord state"] [state=Healthy] milvus-standalone | [2024/07/23 23:55:34.371 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="rootcoord-8\n"] [filePath=/tmp/milvus/server_id_8] milvus-standalone | [2024/07/23 23:55:34.371 +00:00] [INFO] [proxyutil/proxy_watcher.go:119] ["start to watch etcd"] milvus-standalone | [2024/07/23 23:55:34.371 +00:00] [INFO] [rootcoord/quota_center.go:281] ["Start QuotaCenter"] [collectInterval=3s] milvus-standalone | [2024/07/23 23:55:34.371 +00:00] [INFO] [rootcoord/root_coord.go:730] ["rootcoord startup successfully"] milvus-standalone | [2024/07/23 23:55:34.371 +00:00] [DEBUG] [rootcoord/service.go:174] ["RootCoord start done ..."] milvus-standalone | [2024/07/23 23:55:34.371 +00:00] [INFO] [components/root_coord.go:58] ["RootCoord successfully started"] milvus-standalone | [2024/07/23 23:55:34.371 +00:00] [WARN] [proxyutil/proxy_client_manager.go:263] ["proxy client is empty, RefreshPrivilegeInfoCache will not send to any client"] milvus-standalone | [2024/07/23 23:55:34.380 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=rootcoord] [key=by-dev/meta/session/rootcoord] milvus-standalone | [2024/07/23 23:55:34.422 +00:00] [WARN] [tso/global_allocator.go:100] ["clock offset is huge, check network latency and clock skew"] [jet-lag=382.82363ms] [prev-physical=2024/07/23 23:55:34.039 +00:00] [now=2024/07/23 23:55:34.422 +00:00] milvus-standalone | [2024/07/23 23:55:34.578 +00:00] [WARN] [datacoord/segment_manager.go:245] ["failed to get ts from rootCoord for globalLastExpire"] [] milvus-standalone | [2024/07/23 23:55:34.579 +00:00] [INFO] [datacoord/server.go:384] ["init segment manager done"] milvus-standalone | [2024/07/23 23:55:34.579 +00:00] [INFO] [datacoord/garbage_collector.go:82] ["GC with option"] [enabled=true] [interval=1h0m0s] [scanInterval=168h0m0s] [missingTolerance=24h0m0s] [dropTolerance=3h0m0s] milvus-standalone | [2024/07/23 23:55:34.654 +00:00] [INFO] [datacoord/server.go:398] ["init datacoord done"] [nodeID=8] [Address=172.18.0.4:13333] milvus-standalone | [2024/07/23 23:55:34.654 +00:00] [DEBUG] [datacoord/service.go:259] ["DataCoord init done ..."] milvus-standalone | [2024/07/23 23:55:34.654 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=indexcoord] [ServerID=8] milvus-standalone | [2024/07/23 23:55:34.730 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/indexcoord] [value="{\"ServerID\":8,\"ServerName\":\"indexcoord\",\"Address\":\"172.18.0.4:13333\",\"Exclusive\":true,\"TriggerKill\":true,\"Version\":\"2.4.4\",\"IndexEngineVersion\":{},\"LeaseID\":7587880247619074653,\"HostName\":\"120ed2a7ad41\"}"] milvus-standalone | [2024/07/23 23:55:34.730 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=indexcoord] [serverID=8] milvus-standalone | [2024/07/23 23:55:34.730 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=datacoord] [ServerID=8] milvus-standalone | [2024/07/23 23:55:34.770 +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"] milvus-standalone | [2024/07/23 23:55:34.771 +00:00] [INFO] [rootcoord/service.go:93] ["received request to list databases"] [msgID=0] milvus-standalone | [2024/07/23 23:55:34.771 +00:00] [INFO] [rootcoord/service.go:93] ["done to list databases"] [msgID=0] ["num of databases"=1] milvus-standalone | [2024/07/23 23:55:34.772 +00:00] [INFO] [datacoord/meta.go:206] ["meta update: add collection"] [collectionID=451326693849694588] milvus-standalone | [2024/07/23 23:55:34.772 +00:00] [INFO] [datacoord/meta.go:211] ["meta update: add collection - complete"] [collectionID=451326693849694588] milvus-standalone | [2024/07/23 23:55:34.772 +00:00] [INFO] [datacoord/meta.go:206] ["meta update: add collection"] [collectionID=451326693850695112] milvus-standalone | [2024/07/23 23:55:34.772 +00:00] [INFO] [datacoord/meta.go:211] ["meta update: add collection - complete"] [collectionID=451326693850695112] milvus-standalone | [2024/07/23 23:55:34.930 +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"] milvus-standalone | [2024/07/23 23:55:34.930 +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"] milvus-standalone | [2024/07/23 23:55:34.961 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=rootcoord] [key=rootcoord] [address=172.18.0.4:53100] milvus-standalone | [2024/07/23 23:55:34.961 +00:00] [DEBUG] [client/client.go:93] ["RootCoordClient GetSessions success"] [address=172.18.0.4:53100] [serverID=8] milvus-standalone | [2024/07/23 23:55:34.961 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=rootcoord] [key=rootcoord] [address=172.18.0.4:53100] milvus-standalone | [2024/07/23 23:55:34.961 +00:00] [DEBUG] [client/client.go:93] ["RootCoordClient GetSessions success"] [address=172.18.0.4:53100] [serverID=8] milvus-standalone | [2024/07/23 23:55:34.961 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=rootcoord] [key=rootcoord] [address=172.18.0.4:53100] milvus-standalone | [2024/07/23 23:55:34.961 +00:00] [DEBUG] [client/client.go:93] ["RootCoordClient GetSessions success"] [address=172.18.0.4:53100] [serverID=8] milvus-standalone | [2024/07/23 23:55:35.050 +00:00] [DEBUG] [rootcoord/root_coord.go:787] ["RootCoord current state"] [StateCode=Healthy] milvus-standalone | [2024/07/23 23:55:35.051 +00:00] [DEBUG] [datacoord/services.go:660] ["DataCoord current state"] [StateCode=Initializing] milvus-standalone | [2024/07/23 23:55:35.051 +00:00] [DEBUG] [querycoordv2/server.go:584] ["QueryCoord current state"] [StateCode=Abnormal] milvus-standalone | [2024/07/23 23:55:35.051 +00:00] [DEBUG] [querynodev2/services.go:70] ["QueryNode current state"] [NodeID=-1] [StateCode=Initializing] milvus-standalone | [2024/07/23 23:55:35.051 +00:00] [DEBUG] [datanode/services.go:58] ["DataNode current state"] [State=Abnormal] milvus-standalone | [2024/07/23 23:55:35.051 +00:00] [INFO] [indexnode/indexnode.go:286] ["get IndexNode components states ..."] milvus-standalone | [2024/07/23 23:55:35.051 +00:00] [INFO] [indexnode/indexnode.go:304] ["IndexNode Component states"] [State="nodeID:8 role:\"indexnode\" state_code:Healthy "] [Status=Success] [SubcomponentStates=null] milvus-standalone | [2024/07/23 23:55:35.051 +00:00] [DEBUG] [proxy/impl.go:75] ["Proxy current state"] [StateCode=Abnormal] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/datacoord] [value="{\"ServerID\":8,\"ServerName\":\"datacoord\",\"Address\":\"172.18.0.4:13333\",\"Exclusive\":true,\"TriggerKill\":true,\"Version\":\"2.4.4\",\"IndexEngineVersion\":{},\"LeaseID\":7587880247619074656,\"HostName\":\"120ed2a7ad41\"}"] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=datacoord] [serverID=8] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [datacoord/server.go:265] ["DataCoord Register Finished"] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [datacoord/compaction.go:184] ["Compaction handler check result loop start"] ["check result interval"=3s] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [datacoord/compaction.go:203] ["compaction handler start schedule"] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="datacoord-8\n"] [filePath=/tmp/milvus/server_id_8] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [datacoord/server.go:412] ["DataCoord startup successfully"] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [DEBUG] [datacoord/service.go:264] ["DataCoord start done ..."] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [DEBUG] [components/data_coord.go:56] ["DataCoord successfully started"] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [datacoord/compaction_view_manager.go:84] ["Compaction view manager start"] ["check interval"=1m0s] ["idle check interval"=3m0s] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [runtime/asm_arm64.s:1172] ["index builder schedule loop start"] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [datacoord/import_checker.go:72] ["start import checker"] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [datacoord/index_service.go:110] ["start create index for segment loop..."] milvus-standalone | [2024/07/23 23:55:35.134 +00:00] [INFO] [datacoord/import_scheduler.go:74] ["start import scheduler"] milvus-standalone | [2024/07/23 23:55:35.178 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_0] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=158] ["updatePage elapse"=48] ["produce total elapse"=206] milvus-standalone | [2024/07/23 23:55:35.178 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_2] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=158] ["updatePage elapse"=48] ["produce total elapse"=206] milvus-standalone | [2024/07/23 23:55:35.178 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_7] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=158] ["updatePage elapse"=47] ["produce total elapse"=205] milvus-standalone | [2024/07/23 23:55:35.178 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_1] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=159] ["updatePage elapse"=47] ["produce total elapse"=206] milvus-standalone | [2024/07/23 23:55:35.178 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_3] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=159] ["updatePage elapse"=47] ["produce total elapse"=206] milvus-standalone | [2024/07/23 23:55:35.178 +00:00] [WARN] [rootcoord/timeticksync.go:313] ["rootcoord send tt to all channels too slowly"] [chanNum=8] [span=206] milvus-standalone | [2024/07/23 23:55:35.184 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=datacoord] [key=by-dev/meta/session/datacoord] milvus-standalone | [2024/07/23 23:55:35.372 +00:00] [INFO] [datacoord/channel_manager_v2.go:515] ["Reassign standby channels to node"] [nodeID=-9223372036854775808] [channels="[by-dev-rootcoord-dml_5_451326693850695112v1,by-dev-rootcoord-dml_6_451326693850695112v2,by-dev-rootcoord-dml_7_451326693850695112v3,by-dev-rootcoord-dml_0_451326693849694588v0,by-dev-rootcoord-dml_1_451326693849694588v1,by-dev-rootcoord-dml_2_451326693849694588v2,by-dev-rootcoord-dml_3_451326693849694588v3,by-dev-rootcoord-dml_4_451326693850695112v0]"] milvus-standalone | [2024/07/23 23:55:35.772 +00:00] [WARN] [rootcoord/timeticksync.go:313] ["rootcoord send tt to all channels too slowly"] [chanNum=8] [span=200] milvus-standalone | I20240723 23:55:36.166635 24 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] milvus-standalone | I20240723 23:55:36.298147 24 ChunkManager.cpp:112] [SERVER][AwsChunkManager][milvus] init AwsChunkManager with parameter[endpoint=minio:9000][bucket_name=a-bucket][root_path=files][use_secure=false] milvus-standalone | I20240723 23:55:36.298249 24 ChunkCache.h:38] [SERVER][ChunkCache][milvus] Init ChunkCache with prefix: /var/lib/milvus/data/mmap/chunk_cache, read_ahead_policy: willneed milvus-standalone | [2024/07/23 23:55:36.298 +00:00] [INFO] [querynodev2/server.go:260] ["InitChunkCache done"] [dir=/var/lib/milvus/data/mmap/chunk_cache] [policy=willneed] milvus-standalone | I20240723 23:55:36.298314 24 Tracer.cpp:66] [SERVER][initTelemetry][milvus] Empty Trace milvus-standalone | [2024/07/23 23:55:36.298 +00:00] [INFO] [gc/gc_tuner.go:137] ["GC Helper initialized."] ["Initial GoGC"=100] [minimumGOGC=30] [maximumGOGC=200] [memoryThreshold=11001806438] milvus-standalone | [2024/07/23 23:55:36.298 +00:00] [INFO] [querynodev2/server.go:385] ["query node init successfully"] [queryNodeID=8] [Address=172.18.0.4:21123] milvus-standalone | [2024/07/23 23:55:36.298 +00:00] [DEBUG] [querynode/service.go:234] ["QueryNode init done ..."] milvus-standalone | [2024/07/23 23:55:36.298 +00:00] [INFO] [querynodev2/server.go:405] ["query node start successfully"] [queryNodeID=8] [Address=172.18.0.4:21123] [mmapEnabled=false] milvus-standalone | [2024/07/23 23:55:36.298 +00:00] [INFO] [tasks/concurrent_safe_scheduler.go:213] ["start execute loop"] milvus-standalone | [2024/07/23 23:55:36.298 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=querynode] [ServerID=8] milvus-standalone | [2024/07/23 23:55:36.482 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/querynode-8] [value="{\"ServerID\":8,\"ServerName\":\"querynode\",\"Address\":\"172.18.0.4:21123\",\"TriggerKill\":true,\"Version\":\"2.4.4\",\"IndexEngineVersion\":{\"CurrentIndexVersion\":4},\"LeaseID\":7587880247619074670,\"HostName\":\"120ed2a7ad41\"}"] milvus-standalone | [2024/07/23 23:55:36.482 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=querynode] [serverID=8] milvus-standalone | [2024/07/23 23:55:36.482 +00:00] [DEBUG] [sessionutil/session_util.go:779] ["watch services"] ["add kv"="key:\"by-dev/meta/session/querynode-8\" create_revision:9302 mod_revision:9302 version:1 value:\"{\\\"ServerID\\\":8,\\\"ServerName\\\":\\\"querynode\\\",\\\"Address\\\":\\\"172.18.0.4:21123\\\",\\\"TriggerKill\\\":true,\\\"Version\\\":\\\"2.4.4\\\",\\\"IndexEngineVersion\\\":{\\\"CurrentIndexVersion\\\":4},\\\"LeaseID\\\":7587880247619074670,\\\"HostName\\\":\\\"120ed2a7ad41\\\"}\" lease:7587880247619074670 "] milvus-standalone | [2024/07/23 23:55:36.482 +00:00] [DEBUG] [sessionutil/session_util.go:807] [WatchService] ["event type"=SessionAddEvent] milvus-standalone | [2024/07/23 23:55:36.482 +00:00] [INFO] [datacoord/server.go:976] ["received querynode register"] [address=172.18.0.4:21123] [serverID=8] milvus-standalone | [2024/07/23 23:55:36.482 +00:00] [INFO] [datacoord/channel_manager_v2.go:515] ["Reassign standby channels to node"] [nodeID=-9223372036854775808] [channels="[by-dev-rootcoord-dml_0_451326693849694588v0,by-dev-rootcoord-dml_1_451326693849694588v1,by-dev-rootcoord-dml_2_451326693849694588v2,by-dev-rootcoord-dml_3_451326693849694588v3,by-dev-rootcoord-dml_4_451326693850695112v0,by-dev-rootcoord-dml_5_451326693850695112v1,by-dev-rootcoord-dml_6_451326693850695112v2,by-dev-rootcoord-dml_7_451326693850695112v3]"] milvus-standalone | [2024/07/23 23:55:36.482 +00:00] [DEBUG] [querynode/service.go:239] ["QueryNode start done ..."] milvus-standalone | [2024/07/23 23:55:36.482 +00:00] [DEBUG] [components/query_node.go:59] ["QueryNode successfully started"] milvus-standalone | [2024/07/23 23:55:36.482 +00:00] [INFO] [datacoord/index_engine_version_manager.go:65] ["addOrUpdate version"] [nodeId=8] [minimal=0] [current=4] milvus-standalone | [2024/07/23 23:55:36.491 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=querynode] [key=by-dev/meta/session/querynode-8] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [rootcoord/root_coord.go:787] ["RootCoord current state"] [StateCode=Healthy] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [proxy/service.go:607] ["Proxy wait for RootCoord to be healthy done"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [proxy/service.go:609] ["set RootCoord client for Proxy"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [proxy/service.go:611] ["set RootCoord client for Proxy done"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [proxy/service.go:615] ["create DataCoord client for Proxy"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [rootcoord/root_coord.go:787] ["RootCoord current state"] [StateCode=Healthy] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [proxy/service.go:621] ["create DataCoord client for Proxy done"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [INFO] [datanode/service.go:277] ["RootCoord client is ready for DataNode"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [datanode/service.go:285] ["starting DataCoord client for DataNode"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [proxy/service.go:624] ["Proxy wait for DataCoord to be healthy"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [rootcoord/root_coord.go:787] ["RootCoord current state"] [StateCode=Healthy] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [querycoord/service.go:178] ["QueryCoord report RootCoord ready"] milvus-standalone | [2024/07/23 23:55:36.563 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [querycoord/service.go:189] ["QueryCoord try to wait for DataCoord ready"] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=datacoord] [key=datacoord] [address=172.18.0.4:13333] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [client/client.go:93] ["DataCoordClient GetSessions success"] [address=172.18.0.4:13333] [serverID=8] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=datacoord] [key=datacoord] [address=172.18.0.4:13333] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [client/client.go:93] ["DataCoordClient GetSessions success"] [address=172.18.0.4:13333] [serverID=8] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [datacoord/services.go:660] ["DataCoord current state"] [StateCode=Healthy] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [datacoord/services.go:660] ["DataCoord current state"] [StateCode=Healthy] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [querycoord/service.go:198] ["QueryCoord report DataCoord ready"] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [INFO] [querycoordv2/server.go:186] ["QueryCoord start init"] [meta-root-path=by-dev/meta] [address=172.18.0.4:19531] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [proxy/service.go:629] ["Proxy wait for DataCoord to be healthy done"] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [proxy/service.go:631] ["set DataCoord client for Proxy"] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [proxy/service.go:633] ["set DataCoord client for Proxy done"] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [proxy/service.go:637] ["create QueryCoord client for Proxy"] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:36.564 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=datacoord] [key=datacoord] [address=172.18.0.4:13333] milvus-standalone | [2024/07/23 23:55:36.565 +00:00] [DEBUG] [client/client.go:93] ["DataCoordClient GetSessions success"] [address=172.18.0.4:13333] [serverID=8] milvus-standalone | [2024/07/23 23:55:36.565 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:36.565 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:36.565 +00:00] [DEBUG] [proxy/service.go:643] ["create QueryCoord client for Proxy done"] milvus-standalone | [2024/07/23 23:55:36.565 +00:00] [DEBUG] [proxy/service.go:646] ["Proxy wait for QueryCoord to be healthy"] milvus-standalone | [2024/07/23 23:55:36.570 +00:00] [DEBUG] [datacoord/services.go:660] ["DataCoord current state"] [StateCode=Healthy] milvus-standalone | [2024/07/23 23:55:36.570 +00:00] [INFO] [componentutil/componentutil.go:61] ["WaitForComponentStates success"] ["current state"=Healthy] milvus-standalone | [2024/07/23 23:55:36.570 +00:00] [INFO] [datanode/service.go:296] ["DataCoord client is ready for DataNode"] milvus-standalone | [2024/07/23 23:55:36.570 +00:00] [INFO] [sync/once.go:74] ["DataNode server initializing"] [TimeTickChannelName=by-dev-datacoord-timetick-channel] milvus-standalone | [2024/07/23 23:55:36.570 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:36.592 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_6] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=110] ["updatePage elapse"=111] ["produce total elapse"=221] milvus-standalone | [2024/07/23 23:55:36.592 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_2] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=110] ["updatePage elapse"=111] ["produce total elapse"=221] milvus-standalone | [2024/07/23 23:55:36.592 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_5] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=110] ["updatePage elapse"=111] ["produce total elapse"=221] milvus-standalone | [2024/07/23 23:55:36.592 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_4] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=110] ["updatePage elapse"=111] ["produce total elapse"=221] milvus-standalone | [2024/07/23 23:55:36.592 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_0] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=110] ["updatePage elapse"=111] ["produce total elapse"=221] milvus-standalone | [2024/07/23 23:55:36.592 +00:00] [WARN] [rootcoord/timeticksync.go:313] ["rootcoord send tt to all channels too slowly"] [chanNum=8] [span=221] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [DEBUG] [client/client.go:78] ["QueryCoordClient msess key not existed"] [key=querycoord] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available querycoord, check querycoord state"] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [WARN] [grpcclient/client.go:554] ["fail to get grpc client"] [client_role=querycoord] [error="find no available querycoord, check querycoord state"] milvus-standalone | [2024/07/23 23:55:36.748 +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"] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=querycoord] [address=172.18.0.4:19531] [id=8] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [INFO] [querycoordv2/server.go:218] ["start init querycoord"] [State=Initializing] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [INFO] [querycoordv2/server.go:222] ["query coordinator connecting to etcd."] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [INFO] [querycoordv2/server.go:234] ["query coordinator successfully connected to etcd."] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [DEBUG] [client/client.go:78] ["QueryCoordClient msess key not existed"] [key=querycoord] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [WARN] [grpcclient/client.go:213] ["failed to get client address"] [error="find no available querycoord, check querycoord state"] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [WARN] [grpcclient/client.go:476] ["fail to get grpc client in the retry state"] [client_role=querycoord] [error="find no available querycoord, check querycoord state"] milvus-standalone | [2024/07/23 23:55:36.748 +00:00] [WARN] [grpcclient/client.go:467] ["retry func failed"] [retried=0] [error="empty grpc client: find no available querycoord, check querycoord state"] milvus-standalone | [2024/07/23 23:55:36.750 +00:00] [DEBUG] [sessionutil/session_util.go:315] [getServerID] [reuse=true] milvus-standalone | [2024/07/23 23:55:36.750 +00:00] [INFO] [sessionutil/session_util.go:289] ["start server"] [name=datanode] [address=172.18.0.4:21124] [id=8] milvus-standalone | [2024/07/23 23:55:36.750 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="datanode-8\n"] [filePath=/tmp/milvus/server_id_8] milvus-standalone | [2024/07/23 23:55:36.750 +00:00] [INFO] [sync/once.go:74] ["DataNode server init rateCollector done"] [role=datanode] [nodeID=8] milvus-standalone | [2024/07/23 23:55:36.750 +00:00] [INFO] [sync/once.go:74] ["DataNode server init dispatcher client done"] [role=datanode] [nodeID=8] milvus-standalone | [2024/07/23 23:55:36.750 +00:00] [INFO] [dependency/factory.go:86] ["try to init mq"] [standalone=true] [mqType=rocksmq] milvus-standalone | [2024/07/23 23:55:36.750 +00:00] [INFO] [msgstream/mq_factory.go:18] ["init rocksmq msgstream success"] [path=/var/lib/milvus/rdb_data] milvus-standalone | [2024/07/23 23:55:36.750 +00:00] [INFO] [sync/once.go:74] ["DataNode server init succeeded"] [role=datanode] [nodeID=8] [MsgChannelSubName=by-dev-dataNode] milvus-standalone | [2024/07/23 23:55:36.751 +00:00] [INFO] [tso/tso.go:122] ["sync and save timestamp"] [last=2024/07/23 23:21:31.864 +00:00] [save=2024/07/23 23:55:39.748 +00:00] [next=2024/07/23 23:55:36.748 +00:00] milvus-standalone | [2024/07/23 23:55:36.751 +00:00] [INFO] [querycoordv2/server.go:245] ["init ID allocator done"] milvus-standalone | [2024/07/23 23:55:36.751 +00:00] [INFO] [querycoordv2/server.go:348] ["init meta"] milvus-standalone | [2024/07/23 23:55:36.751 +00:00] [INFO] [querycoordv2/server.go:357] ["recover meta..."] milvus-standalone | [2024/07/23 23:55:36.752 +00:00] [INFO] [storage/remote_chunk_manager.go:92] ["remote chunk manager init success."] [remote=aws] [bucketname=a-bucket] [root=files] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [querycoordv2/server.go:358] ["recover collections and partitions from kv store"] [traceID=1721778936753026148] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [querycoordv2/server.go:364] ["recovering collections..."] [collections="[451326693849694588,451326693850695112]"] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [syncmgr/sync_manager.go:73] ["sync manager initialized"] [initPoolSize=256] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [sync/once.go:74] ["init datanode done"] [role=datanode] [nodeID=8] [Address=172.18.0.4:21124] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [datanode/service.go:308] ["current DataNode state"] [state=Initializing] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [datanode/service.go:192] ["DataNode gRPC services successfully initialized"] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [datanode/data_node.go:364] ["start id allocator done"] [role=datanode] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [DEBUG] [datanode/data_node.go:191] ["node begin to register to etcd"] [serverName=datanode] [ServerID=8] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=datanode] [ServerID=8] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [datanode/data_node.go:343] ["DataNode Background GC Start"] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [importv2/scheduler.go:71] ["start import scheduler"] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [meta/replica_manager.go:68] ["recover replica"] [collectionID=451326693849694588] [replicaID=451326693982076929] [nodes="[7]"] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [meta/replica_manager.go:68] ["recover replica"] [collectionID=451326693850695112] [replicaID=451326693982076930] [nodes="[7]"] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [datanode/channel_checkpoint_updater.go:64] ["channel checkpoint updater start"] milvus-standalone | [2024/07/23 23:55:36.753 +00:00] [INFO] [datanode/channel_manager.go:171] ["DataNode ChannelManager start"] milvus-standalone | [2024/07/23 23:55:36.755 +00:00] [INFO] [meta/resource_manager.go:101] ["Recover resource group"] [rgName=__default_resource_group] [nodes="[]"] [config="requests:<> limits:<node_num:1000000 > "] milvus-standalone | [2024/07/23 23:55:36.755 +00:00] [DEBUG] [sessionutil/session_util.go:779] ["watch services"] ["add kv"="key:\"by-dev/meta/session/datanode-8\" create_revision:9304 mod_revision:9304 version:1 value:\"{\\\"ServerID\\\":8,\\\"ServerName\\\":\\\"datanode\\\",\\\"Address\\\":\\\"172.18.0.4:21124\\\",\\\"TriggerKill\\\":true,\\\"Version\\\":\\\"2.4.4\\\",\\\"IndexEngineVersion\\\":{},\\\"LeaseID\\\":7587880247619074701,\\\"HostName\\\":\\\"120ed2a7ad41\\\"}\" lease:7587880247619074701 "] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [DEBUG] [sessionutil/session_util.go:807] [WatchService] ["event type"=SessionAddEvent] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datacoord/server.go:925] ["received datanode register"] [address=172.18.0.4:21124] [serverID=8] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datacoord/channel_manager_v2.go:190] ["register node"] ["registered node"=8] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datacoord/policy.go:425] ["Assign channels to nodes by channel count"] ["toAssign channel count"=8] ["original nodeID"=-9223372036854775808] ["exclusive nodes"="[]"] [operations="[\"{type=Watch,nodeID=8,channels=\\\"[by-dev-rootcoord-dml_7_451326693850695112v3, by-dev-rootcoord-dml_0_451326693849694588v0, by-dev-rootcoord-dml_1_451326693849694588v1, by-dev-rootcoord-dml_2_451326693849694588v2, by-dev-rootcoord-dml_3_451326693849694588v3, by-dev-rootcoord-dml_4_451326693850695112v0, by-dev-rootcoord-dml_5_451326693850695112v1, by-dev-rootcoord-dml_6_451326693850695112v2]\\\"}\",\"{type=Delete,nodeID=-9223372036854775808,channels=\\\"[by-dev-rootcoord-dml_7_451326693850695112v3, by-dev-rootcoord-dml_0_451326693849694588v0, by-dev-rootcoord-dml_1_451326693849694588v1, by-dev-rootcoord-dml_2_451326693849694588v2, by-dev-rootcoord-dml_3_451326693849694588v3, by-dev-rootcoord-dml_4_451326693850695112v0, by-dev-rootcoord-dml_5_451326693850695112v1, by-dev-rootcoord-dml_6_451326693850695112v2]\\\"}\"]"] [nodesLackOfChannels="[8]"] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693850695112] [channel=by-dev-rootcoord-dml_7_451326693850695112v3] [numOfSegments=6] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_7_451326693850695112v3] [posTs=451353771802361896] [posTime=2024/07/23 23:39:59.124 +00:00] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/datanode-8] [value="{\"ServerID\":8,\"ServerName\":\"datanode\",\"Address\":\"172.18.0.4:21124\",\"TriggerKill\":true,\"Version\":\"2.4.4\",\"IndexEngineVersion\":{},\"LeaseID\":7587880247619074701,\"HostName\":\"120ed2a7ad41\"}"] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=datanode] [serverID=8] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datanode/data_node.go:195] ["DataNode Register Finished"] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [querycoordv2/server.go:394] ["QueryCoord server initMeta done"] [duration=5.127843ms] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [querycoordv2/server.go:257] ["init session"] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [querycoordv2/server.go:261] ["init schedulers"] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [querycoordv2/server.go:281] ["init proxy manager done"] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [querycoordv2/server.go:284] ["init dist controller"] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [querycoordv2/server.go:294] ["init checker controller"] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [querycoordv2/server.go:399] ["init observers"] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [querycoordv2/server.go:341] ["init querycoord done"] [nodeID=8] [Address=172.18.0.4:19531] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [DEBUG] [querycoord/service.go:103] ["QueryCoord init done ..."] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [DEBUG] [sessionutil/session_util.go:436] ["service begin to register to etcd"] [serverName=querycoord] [ServerID=8] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693849694588] [channel=by-dev-rootcoord-dml_0_451326693849694588v0] [numOfSegments=20] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_0_451326693849694588v0] [posTs=451353771802361896] [posTime=2024/07/23 23:39:59.124 +00:00] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693849694588] [channel=by-dev-rootcoord-dml_1_451326693849694588v1] [numOfSegments=20] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_1_451326693849694588v1] [posTs=451352185728401421] [posTime=2024/07/23 21:59:08.732 +00:00] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693849694588] [channel=by-dev-rootcoord-dml_2_451326693849694588v2] [numOfSegments=20] milvus-standalone | [2024/07/23 23:55:36.756 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_2_451326693849694588v2] [posTs=451352196273405957] [posTime=2024/07/23 21:59:48.958 +00:00] milvus-standalone | [2024/07/23 23:55:36.757 +00:00] [INFO] [datanode/service.go:197] ["DataNode gRPC services successfully started"] milvus-standalone | [2024/07/23 23:55:36.757 +00:00] [DEBUG] [components/data_node.go:59] ["Datanode successfully started"] milvus-standalone | [2024/07/23 23:55:36.757 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693849694588] [channel=by-dev-rootcoord-dml_3_451326693849694588v3] [numOfSegments=20] milvus-standalone | [2024/07/23 23:55:36.757 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_3_451326693849694588v3] [posTs=451352196273405957] [posTime=2024/07/23 21:59:48.958 +00:00] milvus-standalone | [2024/07/23 23:55:36.757 +00:00] [INFO] [sessionutil/session_util.go:466] ["put session key into etcd"] [key=by-dev/meta/session/querycoord] [value="{\"ServerID\":8,\"ServerName\":\"querycoord\",\"Address\":\"172.18.0.4:19531\",\"Exclusive\":true,\"TriggerKill\":true,\"Version\":\"2.4.4\",\"IndexEngineVersion\":{},\"LeaseID\":7587880247619074706,\"HostName\":\"120ed2a7ad41\"}"] milvus-standalone | [2024/07/23 23:55:36.757 +00:00] [INFO] [sessionutil/session_util.go:476] ["Service registered successfully"] [ServerName=querycoord] [serverID=8] milvus-standalone | [2024/07/23 23:55:36.758 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693850695112] [channel=by-dev-rootcoord-dml_4_451326693850695112v0] [numOfSegments=8] milvus-standalone | [2024/07/23 23:55:36.758 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_4_451326693850695112v0] [posTs=451353760058310671] [posTime=2024/07/23 23:39:14.324 +00:00] milvus-standalone | [2024/07/23 23:55:36.758 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693850695112] [channel=by-dev-rootcoord-dml_5_451326693850695112v1] [numOfSegments=6] milvus-standalone | [2024/07/23 23:55:36.758 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_5_451326693850695112v1] [posTs=451353782366765057] [posTime=2024/07/23 23:40:39.424 +00:00] milvus-standalone | [2024/07/23 23:55:36.758 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693850695112] [channel=by-dev-rootcoord-dml_6_451326693850695112v2] [numOfSegments=8] milvus-standalone | [2024/07/23 23:55:36.758 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_6_451326693850695112v2] [posTs=451353771802361896] [posTime=2024/07/23 23:39:59.124 +00:00] milvus-standalone | [2024/07/23 23:55:36.770 +00:00] [INFO] [querycoordv2/server.go:441] ["start watcher..."] milvus-standalone | [2024/07/23 23:55:36.793 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=querycoord] [key=by-dev/meta/session/querycoord] milvus-standalone | [2024/07/23 23:55:36.793 +00:00] [INFO] [sessionutil/session_util.go:914] ["register session success"] [role=datanode] [key=by-dev/meta/session/datanode-8] milvus-standalone | [2024/07/23 23:55:36.949 +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"] milvus-standalone | [2024/07/23 23:55:36.985 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_2] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=137] ["updatePage elapse"=76] ["produce total elapse"=213] milvus-standalone | [2024/07/23 23:55:36.986 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_1] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=176] ["updatePage elapse"=38] ["produce total elapse"=214] milvus-standalone | [2024/07/23 23:55:36.986 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_4] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=176] ["updatePage elapse"=38] ["produce total elapse"=214] milvus-standalone | [2024/07/23 23:55:36.986 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_7] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=177] ["updatePage elapse"=37] ["produce total elapse"=214] milvus-standalone | [2024/07/23 23:55:36.986 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_0] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=177] ["updatePage elapse"=37] ["produce total elapse"=214] milvus-standalone | [2024/07/23 23:55:36.987 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_6] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=176] ["updatePage elapse"=38] ["produce total elapse"=214] milvus-standalone | [2024/07/23 23:55:36.987 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_3] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=177] ["updatePage elapse"=37] ["produce total elapse"=214] milvus-standalone | [2024/07/23 23:55:36.987 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_5] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=177] ["updatePage elapse"=37] ["produce total elapse"=214] milvus-standalone | [2024/07/23 23:55:36.987 +00:00] [WARN] [rootcoord/timeticksync.go:313] ["rootcoord send tt to all channels too slowly"] [chanNum=8] [span=215] milvus-standalone | [2024/07/23 23:55:37.135 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:37.136 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=querynode] [key=querynode-8] [address=172.18.0.4:21123] milvus-standalone | [2024/07/23 23:55:37.136 +00:00] [INFO] [task/scheduler.go:238] ["add executor for new QueryNode"] [nodeID=8] milvus-standalone | [2024/07/23 23:55:37.136 +00:00] [INFO] [runtime/asm_arm64.s:1172] ["start dist handler"] [nodeID=8] milvus-standalone | [2024/07/23 23:55:37.137 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:37.138 +00:00] [DEBUG] [sessionutil/session_util.go:620] ["SessionUtil GetSessions"] [prefix=querycoord] [key=querycoord] [address=172.18.0.4:19531] milvus-standalone | [2024/07/23 23:55:37.138 +00:00] [DEBUG] [client/client.go:82] ["QueryCoordClient GetSessions success"] [address=172.18.0.4:19531] [serverID=8] milvus-standalone | [2024/07/23 23:55:37.138 +00:00] [DEBUG] [datacoord/import_scheduler.go:167] ["peek slots done"] [nodeSlots="{\"8\":16}"] milvus-standalone | [2024/07/23 23:55:37.211 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_0] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=149] ["updatePage elapse"=75] ["produce total elapse"=224] milvus-standalone | [2024/07/23 23:55:37.211 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_2] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=149] ["updatePage elapse"=75] ["produce total elapse"=224] milvus-standalone | [2024/07/23 23:55:37.211 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_3] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=149] ["updatePage elapse"=75] ["produce total elapse"=224] milvus-standalone | [2024/07/23 23:55:37.212 +00:00] [INFO] [meta/resource_manager.go:805] ["transfer node to resource group"] [rgName=__default_resource_group] [originalRG=_] [node=8] milvus-standalone | [2024/07/23 23:55:37.212 +00:00] [INFO] [meta/resource_manager.go:444] ["HandleNodeUp: add node to resource group"] [rgName=__default_resource_group] [node=8] [] milvus-standalone | [2024/07/23 23:55:37.212 +00:00] [DEBUG] [sessionutil/session_util.go:646] ["Session version out of range"] [version=2.4.4] [serverID=8] milvus-standalone | [2024/07/23 23:55:37.212 +00:00] [INFO] [querycoordv2/server.go:797] ["all old query node down, enable auto balance!"] milvus-standalone | [2024/07/23 23:55:37.212 +00:00] [INFO] [proxyutil/proxy_watcher.go:96] ["succeed to init sessions on etcd"] [sessions=null] [revision=9308] milvus-standalone | [2024/07/23 23:55:37.212 +00:00] [DEBUG] [sessionutil/session_util.go:257] ["Session try to connect to etcd"] milvus-standalone | [2024/07/23 23:55:37.212 +00:00] [INFO] [proxyutil/proxy_watcher.go:119] ["start to watch etcd"] milvus-standalone | [2024/07/23 23:55:37.212 +00:00] [DEBUG] [sessionutil/session_util.go:272] ["Session connect to etcd success"] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [WARN] [dist/dist_handler.go:96] ["node last heart beat time lag too behind"] [now=2024/07/23 23:55:37.213 +00:00] [lastHeartBeatTime=1970/01/01 00:00:00.000 +00:00] [nodeID=8] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [querycoordv2/server.go:491] ["start cluster..."] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [querycoordv2/server.go:494] ["start observers..."] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [observers/target_observer.go:131] ["Start update next target loop"] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [observers/target_observer.go:208] ["observer trigger update next target"] [collectionID=451326693850695112] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [querycoordv2/server.go:500] ["start task scheduler..."] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [querycoordv2/server.go:503] ["start checker controller..."] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [observers/replica_observer.go:69] ["Start check replica loop"] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [DEBUG] [meta/target_manager.go:196] ["start to pull next targets for collection"] [collectionID=451326693850695112] [chosenPartitionIDs="[451326693850695113]"] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [querycoordv2/server.go:506] ["start job scheduler..."] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [sessionutil/session_util.go:1234] ["save server info into file"] [content="querycoord-8\n"] [filePath=/tmp/milvus/server_id_8] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [querycoordv2/server.go:435] ["QueryCoord started"] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [DEBUG] [querycoord/service.go:108] ["QueryCoord start done ..."] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [meta/replica_manager.go:357] ["new replica recovery found"] [replicaID=451326693982076929] [newRONodes="[7]"] [roToRWNodes="[]"] [newIncomingNodes="[8]"] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [DEBUG] [components/query_coord.go:59] ["QueryCoord successfully started"] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [observers/resource_observer.go:67] ["Start check resource group loop"] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [DEBUG] [observers/resource_observer.go:93] ["start to check resource group"] [enableRGAutoRecover=true] [resourceGroupNum=1] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [DEBUG] [observers/resource_observer.go:101] ["recover resource groups..."] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [DEBUG] [observers/resource_observer.go:121] ["check resource group done"] [enableRGAutoRecover=true] [resourceGroupNum=1] milvus-standalone | [2024/07/23 23:55:37.213 +00:00] [INFO] [datacoord/service.go:335] ["get recovery info request received"] [collectionID=451326693850695112] [partitionIDs="[]"] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/handler.go:117] [GetQueryVChanPositions] [collectionID=451326693850695112] [channel=by-dev-rootcoord-dml_7_451326693850695112v3] [numOfSegments=6] ["indexed segment"=6] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_7_451326693850695112v3] [posTs=451353771802361896] [posTime=2024/07/23 23:39:59.124 +00:00] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/service.go:335] ["datacoord append channelInfo in GetRecoveryInfo"] [collectionID=451326693850695112] [partitionIDs="[]"] [channel=by-dev-rootcoord-dml_7_451326693850695112v3] ["# of unflushed segments"=0] ["# of flushed segments"=6] ["# of dropped segments"=0] ["# of indexed segments"=0] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/handler.go:117] [GetQueryVChanPositions] [collectionID=451326693850695112] [channel=by-dev-rootcoord-dml_4_451326693850695112v0] [numOfSegments=8] ["indexed segment"=8] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_4_451326693850695112v0] [posTs=451353760058310671] [posTime=2024/07/23 23:39:14.324 +00:00] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/service.go:335] ["datacoord append channelInfo in GetRecoveryInfo"] [collectionID=451326693850695112] [partitionIDs="[]"] [channel=by-dev-rootcoord-dml_4_451326693850695112v0] ["# of unflushed segments"=0] ["# of flushed segments"=8] ["# of dropped segments"=0] ["# of indexed segments"=0] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/handler.go:117] [GetQueryVChanPositions] [collectionID=451326693850695112] [channel=by-dev-rootcoord-dml_5_451326693850695112v1] [numOfSegments=6] ["indexed segment"=6] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_5_451326693850695112v1] [posTs=451353782366765057] [posTime=2024/07/23 23:40:39.424 +00:00] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/service.go:335] ["datacoord append channelInfo in GetRecoveryInfo"] [collectionID=451326693850695112] [partitionIDs="[]"] [channel=by-dev-rootcoord-dml_5_451326693850695112v1] ["# of unflushed segments"=0] ["# of flushed segments"=6] ["# of dropped segments"=0] ["# of indexed segments"=0] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/handler.go:117] [GetQueryVChanPositions] [collectionID=451326693850695112] [channel=by-dev-rootcoord-dml_6_451326693850695112v2] [numOfSegments=8] ["indexed segment"=8] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_6_451326693850695112v2] [posTs=451353771802361896] [posTime=2024/07/23 23:39:59.124 +00:00] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [INFO] [datacoord/service.go:335] ["datacoord append channelInfo in GetRecoveryInfo"] [collectionID=451326693850695112] [partitionIDs="[]"] [channel=by-dev-rootcoord-dml_6_451326693850695112v2] ["# of unflushed segments"=0] ["# of flushed segments"=8] ["# of dropped segments"=0] ["# of indexed segments"=0] milvus-standalone | [2024/07/23 23:55:37.214 +00:00] [DEBUG] [meta/target_manager.go:137] ["finish to update next targets for collection"] [collectionID=451326693850695112] [PartitionIDs="[451326693850695113]"] [segments="[451326693851389241,451326693851125053,451326693851175783,451326693851389239,451326693850896777,451326693851175786,451326693850901730,451326693850901739,451326693850896783,451326693851389238,451326693851102459,451326693851383425,451326693851125037,451326693851383426,451326693851403679,451326693851383435,451326693851125031,451326693851383440,451326693851102461,451326693851117767,451326693851389242,451326693851125042,451326693851403671,451326693851175787,451326693851117770,451326693851403676,451326693851403672,451326693851175784]"] [channels="[by-dev-rootcoord-dml_7_451326693850695112v3,by-dev-rootcoord-dml_4_451326693850695112v0,by-dev-rootcoord-dml_5_451326693850695112v1,by-dev-rootcoord-dml_6_451326693850695112v2]"] milvus-standalone | [2024/07/23 23:55:37.254 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_5] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=149] ["updatePage elapse"=117] ["produce total elapse"=266] milvus-standalone | [2024/07/23 23:55:37.254 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_7] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=149] ["updatePage elapse"=118] ["produce total elapse"=267] milvus-standalone | [2024/07/23 23:55:37.254 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_4] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=149] ["updatePage elapse"=118] ["produce total elapse"=267] milvus-standalone | [2024/07/23 23:55:37.254 +00:00] [WARN] [server/rocksmq_impl.go:670] ["rocksmq produce too slowly"] [topic=by-dev-rootcoord-dml_6] ["get lock elapse"=0] ["alloc elapse"=0] ["write elapse"=149] ["updatePage elapse"=117] ["produce total elapse"=266] milvus-standalone | [2024/07/23 23:55:37.254 +00:00] [WARN] [rootcoord/timeticksync.go:313] ["rootcoord send tt to all channels too slowly"] [chanNum=8] [span=267] milvus-standalone | [2024/07/23 23:55:37.254 +00:00] [DEBUG] [datanode/timetick_sender.go:170] ["timeTickSender send datanode timetick message"] [toSendMsgs=null] [sendLastTss={}] milvus-standalone | [2024/07/23 23:55:37.367 +00:00] [INFO] [datacoord/channel_manager_v2.go:540] ["Notify channel operations to datanode"] [assignment=8] ["total operation count"=8] ["channel names"="[by-dev-rootcoord-dml_4_451326693850695112v0,by-dev-rootcoord-dml_5_451326693850695112v1,by-dev-rootcoord-dml_6_451326693850695112v2,by-dev-rootcoord-dml_7_451326693850695112v3,by-dev-rootcoord-dml_0_451326693849694588v0,by-dev-rootcoord-dml_1_451326693849694588v1,by-dev-rootcoord-dml_2_451326693849694588v2,by-dev-rootcoord-dml_3_451326693849694588v3]"] milvus-standalone | [2024/07/23 23:55:37.368 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693850695112] [channel=by-dev-rootcoord-dml_5_451326693850695112v1] [numOfSegments=6] milvus-standalone | [2024/07/23 23:55:37.368 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_5_451326693850695112v1] [posTs=451353782366765057] [posTime=2024/07/23 23:40:39.424 +00:00] milvus-standalone | [2024/07/23 23:55:37.368 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693850695112] [channel=by-dev-rootcoord-dml_6_451326693850695112v2] [numOfSegments=8] milvus-standalone | [2024/07/23 23:55:37.368 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_6_451326693850695112v2] [posTs=451353771802361896] [posTime=2024/07/23 23:39:59.124 +00:00] milvus-standalone | [2024/07/23 23:55:37.368 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693850695112] [channel=by-dev-rootcoord-dml_7_451326693850695112v3] [numOfSegments=6] milvus-standalone | [2024/07/23 23:55:37.368 +00:00] [INFO] [datacoord/handler.go:302] ["channel seek position set from channel checkpoint meta"] [channel=by-dev-rootcoord-dml_7_451326693850695112v3] [posTs=451353771802361896] [posTime=2024/07/23 23:39:59.124 +00:00] milvus-standalone | [2024/07/23 23:55:37.368 +00:00] [INFO] [datacoord/handler.go:63] [GetDataVChanPositions] [collectionID=451326693849694588] [channel=by-dev-rootcoord-dml_0_451326693849694588v0] [numOfSegments=20] milvus-etcd | {"level":"info","ts":"2024-07-23T23:59:02.560Z","caller":"traceutil/trace.go:171","msg":"trace[667579997] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9361; }","duration":"3.906732391s","start":"2024-07-23T23:58:58.653Z","end":"2024-07-23T23:59:02.560Z","steps":["trace[667579997] 'process raft request' (duration: 683.329411ms)","trace[667579997] 'get key's previous created_revision and leaseID' (duration: 3.223291104s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:59:02.560Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:58:58.653Z","time spent":"3.9067616s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:59:06.081Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"2.973679814s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074792 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:59:06.082Z","caller":"traceutil/trace.go:171","msg":"trace[1236381610] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9362; }","duration":"3.521499441s","start":"2024-07-23T23:59:02.560Z","end":"2024-07-23T23:59:06.082Z","steps":["trace[1236381610] 'process raft request' (duration: 547.375666ms)","trace[1236381610] 'get key's previous created_revision and leaseID' (duration: 2.973403855s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:59:06.082Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:59:02.560Z","time spent":"3.521651025s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:59:08.991Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"1.925790364s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074793 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:59:08.991Z","caller":"traceutil/trace.go:171","msg":"trace[269637204] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9363; }","duration":"2.908017998s","start":"2024-07-23T23:59:06.083Z","end":"2024-07-23T23:59:08.991Z","steps":["trace[269637204] 'process raft request' (duration: 982.161426ms)","trace[269637204] 'get key's previous created_revision and leaseID' (duration: 1.925640571s)"],"step_count":2} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:59:08.991Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-07-23T23:59:06.083Z","time spent":"2.90810004s","remote":"172.18.0.4:53844","response type":"/etcdserverpb.KV/Put","request count":1,"request size":35,"response count":0,"response size":29,"request content":"key:\"by-dev/kv/gid/timestamp\" value_size:8 "} milvus-etcd | {"level":"warn","ts":"2024-07-23T23:59:12.897Z","caller":"etcdserver/util.go:166","msg":"apply request took too long","took":"3.088113331s","expected-duration":"100ms","prefix":"","request":"header:<ID:7587880247619074794 > put:<key:\"by-dev/kv/gid/timestamp\" value_size:8 >","response":"size:5"} milvus-etcd | {"level":"info","ts":"2024-07-23T23:59:12.897Z","caller":"traceutil/trace.go:171","msg":"trace[1117767534] put","detail":"{key:by-dev/kv/gid/timestamp; req_size:35; response_revision:9364; }","duration":"3.775638415s","start":"2024-07-23T23:59:09.121Z","end":"2024-07-23T23:59:12.897Z","steps":["trace[1117767534] 'process raft request' (duration: 687.420291ms)","trace[1117767534] 'get key's previous created_revision and leaseID' (duration: 3.088014623s)"],"step_count":2}

xiaofan-luan commented 3 months ago

from the log, everthing is working except for disk slow.

apply request took too long","took":"3.088113331s"

Sorry we can do nothing about. use our cloud service, or change a machine with local ssd.

xiaofan-luan commented 3 months ago

just remember if any of etcd request slower than 10s, milvus will reboot. The expect latency is less than 100ms, and that is easily achievable with local or cloud SSD

lukezx3 commented 3 months ago

from the log, everthing is working except for disk slow.

apply request took too long","took":"3.088113331s"

Sorry we can do nothing about. use our cloud service, or change a machine with local ssd.

I see. Just confused why disk is slow if all the memory/cpu configurations seem ok. Any ideas? Thanks for your help by the way

xiaofan-luan commented 3 months ago

sata disk has low very iops, 100+

maybe etcd requires more iops than that. Sata ssd offers thousand iops and nvme ssd offers 100k+ iops.

but agreed etcd might not be best performed because in rocksdb or other databases you can still get reasonable performance on sata. But we can't do anything about it.

We do in house meta store for zilliz cloud but etcd seems to be the only choice for oss so far

lukezx3 commented 3 months ago

sata disk has low very iops, 100+

maybe etcd requires more iops than that. Sata ssd offers thousand iops and nvme ssd offers 100k+ iops.

but agreed etcd might not be best performed because in rocksdb or other databases you can still get reasonable performance on sata. But we can't do anything about it.

We do in house meta store for zilliz cloud but etcd seems to be the only choice for oss so far

i see, thanks for your help. ill close the issue now

lukezx3 commented 3 months ago

closed