Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[Bug] Error in the producer example in the examples directory: Call canceled (Grpc Error) #741

Closed
3 tasks done
JanYork opened this issue May 1, 2024 · 1 comment
Closed
3 tasks done

[Bug] Error in the producer example in the examples directory: Call canceled (Grpc Error) #741

JanYork opened this issue May 1, 2024 · 1 comment
Labels
type/bug Something isn't working

Comments

@JanYork
Copy link

JanYork commented May 1, 2024

Before Creating the Bug Report

  • I found a bug, not just asking a question, which should be created in GitHub Discussions.

  • I have searched the GitHub Issues and GitHub Discussions of this repository and believe that this is not a duplicate.

  • I have confirmed that this bug belongs to the current repository, not other repositories of RocketMQ.

Programming Language of the Client

Node.js

Runtime Platform Environment

Operating system: Macos
Nodejs version: 18.17.0
Code comes from: https://github.com/apache/rocketmq-clients/tree/master/nodejs

RocketMQ Version of the Client/Server

en-us：git https://github.com/apache/rocketmq-clients master branch
zh-cn：仓库 https://github.com/apache/rocketmq-clients 的 master 分支

Run or Compiler Version

Your own git warehouse example, I shouldn’t need to explain

Describe the Bug

the code：

require('module-alias/register');

import { Producer } from "@/producer";

const producer = new Producer({
  endpoints: '192.168.1.162:9876',
});

(async () => {
  try {
    // 启动生产者
    await producer.startup();
    console.log('Producer started successfully.');

    // 发送消息
    const receipt = await producer.send({
      topic: 'TopicTest',
      tag: 'nodejs-demo',
      body: Buffer.from(JSON.stringify({
        hello: 'rocketmq-client-nodejs world 😄',
        now: new Date().toString(), // 使用 toString 方法确保日期正确格式化为字符串
      })),
    });
    console.log('Message sent successfully:', receipt);
  } catch (error) {
    throw error;
  }
})();

The following error will occur when the await producer.send method is called(zh-cn：调用await Producer.send方法时会出现如下错误):

❯ GRPC_VERBOSITY=DEBUG GRPC_TRACE=all node ./dist/src/examples/producer.js

Producer started successfully.
D 2024-05-01T09:13:06.185Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 IDLE -> IDLE
D 2024-05-01T09:13:06.185Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 IDLE -> IDLE
D 2024-05-01T09:13:06.186Z | v1.10.6 68223 | dns_resolver | Resolver constructed for target dns:192.168.1.162:9876
D 2024-05-01T09:13:06.186Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 Channel constructed with options {}
D 2024-05-01T09:13:06.187Z | v1.10.6 68223 | channel_stacktrace | (1) Channel constructed 
    at new InternalChannel (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/internal-channel.js:248:23)
    at new ChannelImplementation (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/channel.js:35:32)
    at new Client (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/client.js:66:36)
    at new ServiceClientImpl (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/make-client.js:58:5)
    at new RpcClient (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client.js:19:23)
    at #getRpcClient (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client-manger.js:36:25)
    at RpcClientManger.queryRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client-manger.js:49:45)
    at #fetchTopicRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-base-client.js:160:54)
    at Producer.getRouteData (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-base-client.js:152:57)
    at #getPublishingLoadBalancer (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/producer/producer.js:209:43)
D 2024-05-01T09:13:06.188Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 createResolvingCall [0] method="/apache.rocketmq.v2.MessagingService/QueryRoute", deadline=2024-05-01T09:13:09.188Z
D 2024-05-01T09:13:06.188Z | v1.10.6 68223 | resolving_call | [0] Created
D 2024-05-01T09:13:06.188Z | v1.10.6 68223 | resolving_call | [0] Deadline: 2024-05-01T09:13:09.188Z
D 2024-05-01T09:13:06.189Z | v1.10.6 68223 | resolving_call | [0] Deadline will be reached in 2999ms
D 2024-05-01T09:13:06.189Z | v1.10.6 68223 | resolving_call | [0] start called
D 2024-05-01T09:13:06.190Z | v1.10.6 68223 | dns_resolver | Returning IP address for target dns:192.168.1.162:9876
D 2024-05-01T09:13:06.190Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 IDLE -> CONNECTING
D 2024-05-01T09:13:06.190Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 IDLE -> CONNECTING
D 2024-05-01T09:13:06.190Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 callRefTimer.ref | configSelectionQueue.length=1 pickQueue.length=0
D 2024-05-01T09:13:06.190Z | v1.10.6 68223 | resolving_call | [0] startRead called
D 2024-05-01T09:13:06.191Z | v1.10.6 68223 | resolving_call | [0] write() called with message of length 37
D 2024-05-01T09:13:06.191Z | v1.10.6 68223 | resolving_call | [0] halfClose called
D 2024-05-01T09:13:06.194Z | v1.10.6 68223 | subchannel | (1) 192.168.1.162:9876 Subchannel constructed with options {}
D 2024-05-01T09:13:06.194Z | v1.10.6 68223 | subchannel_refcount | (1) 192.168.1.162:9876 refcount 0 -> 1
D 2024-05-01T09:13:06.194Z | v1.10.6 68223 | subchannel_refcount | (1) 192.168.1.162:9876 refcount 1 -> 2
D 2024-05-01T09:13:06.195Z | v1.10.6 68223 | pick_first | Start connecting to subchannel with address 192.168.1.162:9876
D 2024-05-01T09:13:06.195Z | v1.10.6 68223 | pick_first | IDLE -> CONNECTING
D 2024-05-01T09:13:06.195Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 CONNECTING -> CONNECTING
D 2024-05-01T09:13:06.195Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 CONNECTING -> CONNECTING
D 2024-05-01T09:13:06.195Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2024-05-01T09:13:06.196Z | v1.10.6 68223 | subchannel | (1) 192.168.1.162:9876 IDLE -> CONNECTING
D 2024-05-01T09:13:06.197Z | v1.10.6 68223 | transport | dns:192.168.1.162:9876 creating HTTP/2 session to 192.168.1.162:9876
D 2024-05-01T09:13:06.198Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 createRetryingCall [1] method="/apache.rocketmq.v2.MessagingService/QueryRoute"
D 2024-05-01T09:13:06.198Z | v1.10.6 68223 | resolving_call | [0] Created child [1]
D 2024-05-01T09:13:06.198Z | v1.10.6 68223 | retrying_call | [1] start called
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 createLoadBalancingCall [2] method="/apache.rocketmq.v2.MessagingService/QueryRoute"
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | retrying_call | [1] Created child call [2] for attempt 1
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | load_balancing_call | [2] start called
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | load_balancing_call | [2] Pick called
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | load_balancing_call | [2] Pick result: QUEUE subchannel: null status: undefined undefined
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 callRefTimer.ref | configSelectionQueue.length=0 pickQueue.length=1
D 2024-05-01T09:13:06.200Z | v1.10.6 68223 | retrying_call | [1] startRead called
D 2024-05-01T09:13:06.200Z | v1.10.6 68223 | load_balancing_call | [2] startRead called
D 2024-05-01T09:13:06.200Z | v1.10.6 68223 | retrying_call | [1] write() called with message of length 42
D 2024-05-01T09:13:06.200Z | v1.10.6 68223 | load_balancing_call | [2] write() called with message of length 42
D 2024-05-01T09:13:06.200Z | v1.10.6 68223 | retrying_call | [1] halfClose called
D 2024-05-01T09:13:06.202Z | v1.10.6 68223 | subchannel | (1) 192.168.1.162:9876 CONNECTING -> READY
D 2024-05-01T09:13:06.202Z | v1.10.6 68223 | pick_first | Pick subchannel with address 192.168.1.162:9876
D 2024-05-01T09:13:06.202Z | v1.10.6 68223 | subchannel_refcount | (1) 192.168.1.162:9876 refcount 2 -> 3
D 2024-05-01T09:13:06.202Z | v1.10.6 68223 | subchannel_refcount | (1) 192.168.1.162:9876 refcount 3 -> 2
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | pick_first | CONNECTING -> READY
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 CONNECTING -> READY
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | load_balancing_call | [2] Pick called
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | load_balancing_call | [2] Pick result: COMPLETE subchannel: (1) 192.168.1.162:9876 status: undefined undefined
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 CONNECTING -> READY
D 2024-05-01T09:13:06.204Z | v1.10.6 68223 | transport_flowctrl | (1) 192.168.1.162:9876 local window size: 65535 remote window size: 65535
D 2024-05-01T09:13:06.205Z | v1.10.6 68223 | transport_internals | (1) 192.168.1.162:9876 session.closed=false session.destroyed=false session.socket.destroyed=false
D 2024-05-01T09:13:06.205Z | v1.10.6 68223 | load_balancing_call | [2] Created child call [3]
D 2024-05-01T09:13:06.205Z | v1.10.6 68223 | subchannel_call | [3] write() called with message of length 42
D 2024-05-01T09:13:06.205Z | v1.10.6 68223 | subchannel_call | [3] sending data chunk of length 42
D 2024-05-01T09:13:06.206Z | v1.10.6 68223 | load_balancing_call | [2] halfClose called
D 2024-05-01T09:13:06.206Z | v1.10.6 68223 | subchannel_call | [3] end() called
D 2024-05-01T09:13:06.206Z | v1.10.6 68223 | subchannel_call | [3] calling end() on HTTP/2 stream
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | transport | (1) 192.168.1.162:9876 session closed
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | subchannel | (1) 192.168.1.162:9876 READY -> IDLE
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | subchannel_refcount | (1) 192.168.1.162:9876 refcount 2 -> 1
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | pick_first | READY -> IDLE
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 READY -> IDLE
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 READY -> IDLE
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 IDLE -> CONNECTING
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 IDLE -> CONNECTING
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | subchannel_call | [3] HTTP/2 stream closed with code 8
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | subchannel_call | [3] ended with status: code=1 details="Call cancelled"
D 2024-05-01T09:13:06.212Z | v1.10.6 68223 | load_balancing_call | [2] Received status
D 2024-05-01T09:13:06.212Z | v1.10.6 68223 | load_balancing_call | [2] ended with status: code=1 details="Call cancelled" start time=2024-05-01T09:13:06.199Z
D 2024-05-01T09:13:06.212Z | v1.10.6 68223 | retrying_call | [1] Received status from child [2]
D 2024-05-01T09:13:06.212Z | v1.10.6 68223 | retrying_call | [1] state=TRANSPARENT_ONLY handling status with progress PROCESSED from child [2] in state ACTIVE
D 2024-05-01T09:13:06.212Z | v1.10.6 68223 | retrying_call | [1] ended with status: code=1 details="Call cancelled" start time=2024-05-01T09:13:06.198Z
D 2024-05-01T09:13:06.213Z | v1.10.6 68223 | resolving_call | [0] Received status
D 2024-05-01T09:13:06.213Z | v1.10.6 68223 | resolving_call | [0] ended with status: code=1 details="Call cancelled"
node:internal/process/promises:288
            triggerUncaughtException(err, true /* fromPromise */);
            ^

Error: 1 CANCELLED: Call cancelled
    at callErrorFromStatus (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/call.js:31:19)
    at Object.onReceiveStatus (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/client.js:193:76)
    at Object.onReceiveStatus (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:360:141)
    at Object.onReceiveStatus (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:323:181)
    at /Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/resolving-call.js:129:78
    at process.processTicksAndRejections (node:internal/process/task_queues:77:11)
for call at
    at ServiceClientImpl.makeUnaryRequest (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/client.js:161:32)
    at ServiceClientImpl.queryRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/make-client.js:105:19)
    at /Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client.js:45:20
    at new Promise (<anonymous>)
    at RpcClient.queryRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client.js:44:16)
    at RpcClientManger.queryRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client-manger.js:51:32)
    at #fetchTopicRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-base-client.js:160:54)
    at Producer.getRouteData (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-base-client.js:152:57)
    at #getPublishingLoadBalancer (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/producer/producer.js:209:43)
    at #send (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/producer/producer.js:130:67) {
  code: 1,
  details: 'Call cancelled',
  metadata: Metadata { internalRepr: Map(0) {}, options: {} }
}

Node.js v18.17.0

I didn't find any problems with my RocketMQ service. This is mostly a client problem.(zh-cn：我的RocketMQ服务并没有发现有任何问题，这多半是客户端的问题)

image

Why is this happening? ? ?

Steps to Reproduce

Directly use the code in the git repository https://github.com/apache/rocketmq-clients/tree/master/nodejs. I only modified the Producer test example and the names of some classes.（zh-cn：直接使用https://github.com/apache/rocketmq-clients/tree/master/nodejs这个git仓库中的代码，我只修改了Producer的测试示例和部分类的名称）

What Did You Expect to See?

Correct request for return.

What Did You See Instead?

❯ GRPC_VERBOSITY=DEBUG GRPC_TRACE=all node ./dist/src/examples/producer.js

Producer started successfully.
D 2024-05-01T09:13:06.185Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 IDLE -> IDLE
D 2024-05-01T09:13:06.185Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 IDLE -> IDLE
D 2024-05-01T09:13:06.186Z | v1.10.6 68223 | dns_resolver | Resolver constructed for target dns:192.168.1.162:9876
D 2024-05-01T09:13:06.186Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 Channel constructed with options {}
D 2024-05-01T09:13:06.187Z | v1.10.6 68223 | channel_stacktrace | (1) Channel constructed 
    at new InternalChannel (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/internal-channel.js:248:23)
    at new ChannelImplementation (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/channel.js:35:32)
    at new Client (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/client.js:66:36)
    at new ServiceClientImpl (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/make-client.js:58:5)
    at new RpcClient (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client.js:19:23)
    at #getRpcClient (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client-manger.js:36:25)
    at RpcClientManger.queryRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client-manger.js:49:45)
    at #fetchTopicRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-base-client.js:160:54)
    at Producer.getRouteData (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-base-client.js:152:57)
    at #getPublishingLoadBalancer (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/producer/producer.js:209:43)
D 2024-05-01T09:13:06.188Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 createResolvingCall [0] method="/apache.rocketmq.v2.MessagingService/QueryRoute", deadline=2024-05-01T09:13:09.188Z
D 2024-05-01T09:13:06.188Z | v1.10.6 68223 | resolving_call | [0] Created
D 2024-05-01T09:13:06.188Z | v1.10.6 68223 | resolving_call | [0] Deadline: 2024-05-01T09:13:09.188Z
D 2024-05-01T09:13:06.189Z | v1.10.6 68223 | resolving_call | [0] Deadline will be reached in 2999ms
D 2024-05-01T09:13:06.189Z | v1.10.6 68223 | resolving_call | [0] start called
D 2024-05-01T09:13:06.190Z | v1.10.6 68223 | dns_resolver | Returning IP address for target dns:192.168.1.162:9876
D 2024-05-01T09:13:06.190Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 IDLE -> CONNECTING
D 2024-05-01T09:13:06.190Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 IDLE -> CONNECTING
D 2024-05-01T09:13:06.190Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 callRefTimer.ref | configSelectionQueue.length=1 pickQueue.length=0
D 2024-05-01T09:13:06.190Z | v1.10.6 68223 | resolving_call | [0] startRead called
D 2024-05-01T09:13:06.191Z | v1.10.6 68223 | resolving_call | [0] write() called with message of length 37
D 2024-05-01T09:13:06.191Z | v1.10.6 68223 | resolving_call | [0] halfClose called
D 2024-05-01T09:13:06.194Z | v1.10.6 68223 | subchannel | (1) 192.168.1.162:9876 Subchannel constructed with options {}
D 2024-05-01T09:13:06.194Z | v1.10.6 68223 | subchannel_refcount | (1) 192.168.1.162:9876 refcount 0 -> 1
D 2024-05-01T09:13:06.194Z | v1.10.6 68223 | subchannel_refcount | (1) 192.168.1.162:9876 refcount 1 -> 2
D 2024-05-01T09:13:06.195Z | v1.10.6 68223 | pick_first | Start connecting to subchannel with address 192.168.1.162:9876
D 2024-05-01T09:13:06.195Z | v1.10.6 68223 | pick_first | IDLE -> CONNECTING
D 2024-05-01T09:13:06.195Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 CONNECTING -> CONNECTING
D 2024-05-01T09:13:06.195Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 CONNECTING -> CONNECTING
D 2024-05-01T09:13:06.195Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2024-05-01T09:13:06.196Z | v1.10.6 68223 | subchannel | (1) 192.168.1.162:9876 IDLE -> CONNECTING
D 2024-05-01T09:13:06.197Z | v1.10.6 68223 | transport | dns:192.168.1.162:9876 creating HTTP/2 session to 192.168.1.162:9876
D 2024-05-01T09:13:06.198Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 createRetryingCall [1] method="/apache.rocketmq.v2.MessagingService/QueryRoute"
D 2024-05-01T09:13:06.198Z | v1.10.6 68223 | resolving_call | [0] Created child [1]
D 2024-05-01T09:13:06.198Z | v1.10.6 68223 | retrying_call | [1] start called
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 createLoadBalancingCall [2] method="/apache.rocketmq.v2.MessagingService/QueryRoute"
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | retrying_call | [1] Created child call [2] for attempt 1
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | load_balancing_call | [2] start called
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | load_balancing_call | [2] Pick called
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | load_balancing_call | [2] Pick result: QUEUE subchannel: null status: undefined undefined
D 2024-05-01T09:13:06.199Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 callRefTimer.ref | configSelectionQueue.length=0 pickQueue.length=1
D 2024-05-01T09:13:06.200Z | v1.10.6 68223 | retrying_call | [1] startRead called
D 2024-05-01T09:13:06.200Z | v1.10.6 68223 | load_balancing_call | [2] startRead called
D 2024-05-01T09:13:06.200Z | v1.10.6 68223 | retrying_call | [1] write() called with message of length 42
D 2024-05-01T09:13:06.200Z | v1.10.6 68223 | load_balancing_call | [2] write() called with message of length 42
D 2024-05-01T09:13:06.200Z | v1.10.6 68223 | retrying_call | [1] halfClose called
D 2024-05-01T09:13:06.202Z | v1.10.6 68223 | subchannel | (1) 192.168.1.162:9876 CONNECTING -> READY
D 2024-05-01T09:13:06.202Z | v1.10.6 68223 | pick_first | Pick subchannel with address 192.168.1.162:9876
D 2024-05-01T09:13:06.202Z | v1.10.6 68223 | subchannel_refcount | (1) 192.168.1.162:9876 refcount 2 -> 3
D 2024-05-01T09:13:06.202Z | v1.10.6 68223 | subchannel_refcount | (1) 192.168.1.162:9876 refcount 3 -> 2
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | pick_first | CONNECTING -> READY
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 CONNECTING -> READY
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | channel | (1) dns:192.168.1.162:9876 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | load_balancing_call | [2] Pick called
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | load_balancing_call | [2] Pick result: COMPLETE subchannel: (1) 192.168.1.162:9876 status: undefined undefined
D 2024-05-01T09:13:06.203Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 CONNECTING -> READY
D 2024-05-01T09:13:06.204Z | v1.10.6 68223 | transport_flowctrl | (1) 192.168.1.162:9876 local window size: 65535 remote window size: 65535
D 2024-05-01T09:13:06.205Z | v1.10.6 68223 | transport_internals | (1) 192.168.1.162:9876 session.closed=false session.destroyed=false session.socket.destroyed=false
D 2024-05-01T09:13:06.205Z | v1.10.6 68223 | load_balancing_call | [2] Created child call [3]
D 2024-05-01T09:13:06.205Z | v1.10.6 68223 | subchannel_call | [3] write() called with message of length 42
D 2024-05-01T09:13:06.205Z | v1.10.6 68223 | subchannel_call | [3] sending data chunk of length 42
D 2024-05-01T09:13:06.206Z | v1.10.6 68223 | load_balancing_call | [2] halfClose called
D 2024-05-01T09:13:06.206Z | v1.10.6 68223 | subchannel_call | [3] end() called
D 2024-05-01T09:13:06.206Z | v1.10.6 68223 | subchannel_call | [3] calling end() on HTTP/2 stream
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | transport | (1) 192.168.1.162:9876 session closed
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | subchannel | (1) 192.168.1.162:9876 READY -> IDLE
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | subchannel_refcount | (1) 192.168.1.162:9876 refcount 2 -> 1
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | pick_first | READY -> IDLE
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 READY -> IDLE
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 READY -> IDLE
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | resolving_load_balancer | dns:192.168.1.162:9876 IDLE -> CONNECTING
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | connectivity_state | (1) dns:192.168.1.162:9876 IDLE -> CONNECTING
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | subchannel_call | [3] HTTP/2 stream closed with code 8
D 2024-05-01T09:13:06.211Z | v1.10.6 68223 | subchannel_call | [3] ended with status: code=1 details="Call cancelled"
D 2024-05-01T09:13:06.212Z | v1.10.6 68223 | load_balancing_call | [2] Received status
D 2024-05-01T09:13:06.212Z | v1.10.6 68223 | load_balancing_call | [2] ended with status: code=1 details="Call cancelled" start time=2024-05-01T09:13:06.199Z
D 2024-05-01T09:13:06.212Z | v1.10.6 68223 | retrying_call | [1] Received status from child [2]
D 2024-05-01T09:13:06.212Z | v1.10.6 68223 | retrying_call | [1] state=TRANSPARENT_ONLY handling status with progress PROCESSED from child [2] in state ACTIVE
D 2024-05-01T09:13:06.212Z | v1.10.6 68223 | retrying_call | [1] ended with status: code=1 details="Call cancelled" start time=2024-05-01T09:13:06.198Z
D 2024-05-01T09:13:06.213Z | v1.10.6 68223 | resolving_call | [0] Received status
D 2024-05-01T09:13:06.213Z | v1.10.6 68223 | resolving_call | [0] ended with status: code=1 details="Call cancelled"
node:internal/process/promises:288
            triggerUncaughtException(err, true /* fromPromise */);
            ^

Error: 1 CANCELLED: Call cancelled
    at callErrorFromStatus (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/call.js:31:19)
    at Object.onReceiveStatus (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/client.js:193:76)
    at Object.onReceiveStatus (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:360:141)
    at Object.onReceiveStatus (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:323:181)
    at /Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/resolving-call.js:129:78
    at process.processTicksAndRejections (node:internal/process/task_queues:77:11)
for call at
    at ServiceClientImpl.makeUnaryRequest (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/client.js:161:32)
    at ServiceClientImpl.queryRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/node_modules/.pnpm/@grpc+grpc-js@1.10.6/node_modules/@grpc/grpc-js/build/src/make-client.js:105:19)
    at /Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client.js:45:20
    at new Promise (<anonymous>)
    at RpcClient.queryRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client.js:44:16)
    at RpcClientManger.queryRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-client-manger.js:51:32)
    at #fetchTopicRoute (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-base-client.js:160:54)
    at Producer.getRouteData (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/server/client/rpc-base-client.js:152:57)
    at #getPublishingLoadBalancer (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/producer/producer.js:209:43)
    at #send (/Users/muyouzhi/Code/rocketmq-grpc-client/dist/src/producer/producer.js:130:67) {
  code: 1,
  details: 'Call cancelled',
  metadata: Metadata { internalRepr: Map(0) {}, options: {} }
}

Node.js v18.17.0

Additional Context

The method that caused the error（zh-cn：错误导致的方法）：

const receipt = await producer.send({
      topic: 'TopicTest',
      tag: 'nodejs-demo',
      body: Buffer.from(JSON.stringify({
        hello: 'rocketmq-client-nodejs world 😄',
        now: new Date().toString(),
      })),
    });

The method in which the error is thrown(zh-cn：错误被抛出的方法）:

    async queryRoute(request, metadata, duration) {
        const client = this.#getAndActivityRpcClient();
        const deadline = this.#getDeadline(duration);
        return new Promise((resolve, reject) => {
            client.queryRoute(request, metadata, { deadline }, (e, res) => {
                if (e)
                    return reject(e);
                resolve(res);
            });
        });
    }
@JanYork JanYork added the type/bug Something isn't working label May 1, 2024
@JanYork
Copy link
Author

JanYork commented May 1, 2024

@fengmk2 Hi, can you help me look into this issue?

@JanYork JanYork closed this as completed May 2, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
type/bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@JanYork