search

wechaty / puppet-padlocal

Puppet PadLocal is a Pad Protocol for WeChat
https://wechaty.js.org/docs/puppet-providers/padlocal
Apache License 2.0
626 stars 88 forks source link

VError: longlink fail to connect, host:120.241.21.110, port:80: longlink socket connect timeout #98

Open huan opened 2 years ago

huan commented 2 years ago 
17:09:05 ERR Config ###########################
17:09:05 ERR Config unhandledRejection: VError: longlink fail to connect, host:120.241.21.110, port:80: longlink socket connect timeout
at WeChatLongLinkProxy.<anonymous> (/app/node_modules/padlocal-client-ts/dist/link/WeChatLongLinkProxy.js:91:23)
at Generator.throw (<anonymous>)
at rejected (/app/node_modules/padlocal-client-ts/dist/link/WeChatLongLinkProxy.js:6:65)
at runMicrotasks (<anonymous>)
at processTicksAndRejections (node:internal/process/task_queues:96:5) [object Promise]
17:09:05 ERR Config ###########################
17:09:05 ERR Config process.on(unhandledRejection) promise.catch(longlink fail to connect, host:120.241.21.110, port:80: longlink socket connect timeout)
Config IOError [VError]: longlink fail to connect, host:120.241.21.110, port:80: longlink socket connect timeout
at WeChatLongLinkProxy.<anonymous> (/app/node_modules/padlocal-client-ts/dist/link/WeChatLongLinkProxy.js:91:23)
at Generator.throw (<anonymous>)
at rejected (/app/node_modules/padlocal-client-ts/dist/link/WeChatLongLinkProxy.js:6:65)
at runMicrotasks (<anonymous>)
at processTicksAndRejections (node:internal/process/task_queues:96:5) {
jse_shortmsg: 'longlink fail to connect, host:120.241.21.110, port:80',
jse_cause: IOError [VError]: longlink socket connect timeout
at Timeout.<anonymous> (/app/node_modules/padlocal-client-ts/dist/link/WeChatLongLinkProxy.js:276:39)
at listOnTimeout (node:internal/timers:557:17)
at processTimers (node:internal/timers:500:7) {
jse_shortmsg: 'longlink socket connect timeout',
jse_info: {}
},
jse_info: {}
}
(node:17) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 2)
(Use `node --trace-warnings ...` to show where the warning was created)
binsee commented 2 years ago

WeChat has a cgi /cgi-bin/micromsg-bin/newgetdns for returning a set of dns lists, which will provide users with multiple optional server IPs.

In mars, the server will be selected in order. If the first ip connection fails, the second ip will be connected. The official app ensures higher usability through this mechanism.

Not sure if padlocal supports this mechanism?

padlocal commented 2 years ago

Thanks for @binsee 's suggestion, it's a greate solution which will work hopefully.

But it's really hard to verify that whether the sibling server ip got via /cgi-bin/micromsg-bin/newgetdns will work, since the first ip fails which may be caused by network jitter.

Call for volunteers: if you are running into this issue frequently, leave your message in this thread. Then we can tune the new stragety together to see if it really works.

huan commented 2 years ago

Today I have upgraded Friday BOT with Puppet PadLocal v1.11, and when AutoLogin it keeps retrying with the following error:

IOError: longlink socket connect timeout

Update: after about two hours retrying, login successfully finally.

21:44:52 INFO [PuppetPadlocal] start login with type: AutoLogin
21:45:03 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
21:45:04 INFO [PuppetPadlocal] start login with type: AutoLogin
21:45:18 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
21:45:33 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
21:45:48 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
21:46:03 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
21:46:05 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
21:46:06 INFO [PuppetPadlocal] start login with type: AutoLogin
21:46:20 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
21:46:28 ERR Config ###########################
21:46:28 ERR Config Wechaty unhandledRejection: IOError: longlink socket connect timeout
    at Timeout.<anonymous> (/home/friday/git/friday/node_modules/padlocal-client-ts/src/link/WeChatLongLinkProxy.ts:365:25)
    at listOnTimeout (node:internal/timers:559:17)
    at processTimers (node:internal/timers:502:7) [object Promise]
21:46:28 ERR Config ###########################
21:46:28 ERR Config process.on(unhandledRejection) promise.catch(longlink socket connect timeout)
Config IOError: longlink socket connect timeout
    at Timeout.<anonymous> (/home/friday/git/friday/node_modules/padlocal-client-ts/src/link/WeChatLongLinkProxy.ts:365:25)
    at listOnTimeout (node:internal/timers:559:17)
    at processTimers (node:internal/timers:502:7) {
  jse_shortmsg: 'longlink socket connect timeout',
  jse_info: {},
  cause: [Function: ve_cause]
}
(node:783959) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 2)
(Use `node --trace-warnings ...` to show where the warning was created)
21:46:35 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
21:46:50 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
21:46:51 ERR Config ###########################
21:46:51 ERR Config Wechaty unhandledRejection: IOError: longlink socket connect timeout
    at Timeout.<anonymous> (/home/friday/git/friday/node_modules/padlocal-client-ts/src/link/WeChatLongLinkProxy.ts:365:25)
    at listOnTimeout (node:internal/timers:559:17)
    at processTimers (node:internal/timers:502:7) [object Promise]
21:46:51 ERR Config ###########################
21:46:51 ERR Config process.on(unhandledRejection) promise.catch(longlink socket connect timeout)
Config IOError: longlink socket connect timeout
    at Timeout.<anonymous> (/home/friday/git/friday/node_modules/padlocal-client-ts/src/link/WeChatLongLinkProxy.ts:365:25)
    at listOnTimeout (node:internal/timers:559:17)
    at processTimers (node:internal/timers:502:7) {
  jse_shortmsg: 'longlink socket connect timeout',
  jse_info: {},
  cause: [Function: ve_cause]
}
(node:783959) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 3)
21:47:05 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
21:47:08 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
21:47:09 INFO [PuppetPadlocal] start login with type: AutoLogin

Old version (0.4) has the same problem

13:55:54 INFO [PuppetPadlocal] start login with type: AutoLogin
13:56:16 ERR Config ###########################
13:56:16 ERR Config unhandledRejection: VError: longlink socket connect timeout
    at Timeout.<anonymous> (/wechaty/node_modules/padlocal-client-ts/src/link/WeChatLongLinkProxy.ts:365:25)
    at listOnTimeout (node:internal/timers:557:17)
    at processTimers (node:internal/timers:500:7) [object Promise]
13:56:16 ERR Config ###########################
13:56:16 ERR Config process.on(unhandledRejection) promise.catch(longlink socket connect timeout)
Config IOError [VError]: longlink socket connect timeout
    at Timeout.<anonymous> (/wechaty/node_modules/padlocal-client-ts/src/link/WeChatLongLinkProxy.ts:365:25)
    at listOnTimeout (node:internal/timers:557:17)
    at processTimers (node:internal/timers:500:7) {
  jse_shortmsg: 'longlink socket connect timeout',
  jse_info: {}
}
13:56:54 VERB StateSwitch <PuppetState> off(pending) <- (false)
13:56:54 VERB StateSwitch <PuppetState> off(true) <- (pending)
13:56:55 VERB StateSwitch <PuppetState> on(pending) <- (false)
13:56:56 INFO [PuppetPadlocal] start login with type: AutoLogin
13:57:06 VERB StateSwitch <PuppetState> off(pending) <- (false)
13:57:06 VERB StateSwitch <PuppetState> off(true) <- (pending)
13:57:07 VERB StateSwitch <PuppetState> on(pending) <- (false)
13:57:07 INFO [PuppetPadlocal] start login with type: AutoLogin
13:57:29 ERR Config ###########################
13:57:29 ERR Config unhandledRejection: VError: longlink socket connect timeout
    at Timeout.<anonymous> (/wechaty/node_modules/padlocal-client-ts/src/link/WeChatLongLinkProxy.ts:365:25)
    at listOnTimeout (node:internal/timers:557:17)
    at processTimers (node:internal/timers:500:7) [object Promise]
13:57:29 ERR Config ###########################
13:57:29 ERR Config process.on(unhandledRejection) promise.catch(longlink socket connect timeout)
Config IOError [VError]: longlink socket connect timeout
    at Timeout.<anonymous> (/wechaty/node_modules/padlocal-client-ts/src/link/WeChatLongLinkProxy.ts:365:25)
    at listOnTimeout (node:internal/timers:557:17)
    at processTimers (node:internal/timers:500:7) {
  jse_shortmsg: 'longlink socket connect timeout',
  jse_info: {}
}
huan commented 2 years ago

OSS.Chat (running on Heroku) is experiencing the same problems today (with Wechaty Puppet PadLocal v0.4):

01:57:19 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
01:57:20 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
01:57:21 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
01:57:21 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
01:57:30 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
01:57:30 INFO [PuppetPadlocal] start login with type: AutoLogin
01:57:31 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
01:57:32 INFO [PuppetPadlocal] start login with type: AutoLogin
01:58:06 ERR [PadLocalClient] error while syncing onpush: VError: [tid:a17c2298] request has been cancelled for reason: SERVER_ERROR: 4 DEADLINE_EXCEEDED: Deadline exceeded
    at Request._failAllPendingRequest (/app/node_modules/padlocal-client-ts/dist/Request.js:262:19)
    at ClientDuplexStreamImpl.<anonymous> (/app/node_modules/padlocal-client-ts/dist/Request.js:56:18)
    at ClientDuplexStreamImpl.emit (node:events:526:28)
    at ClientDuplexStreamImpl.emit (node:domain:475:12)
    at Object.onReceiveStatus (/app/node_modules/@grpc/grpc-js/build/src/client.js:391:28)
    at Object.onReceiveStatus (/app/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:328:181)
    at /app/node_modules/@grpc/grpc-js/build/src/call-stream.js:182:78
    at processTicksAndRejections (node:internal/process/task_queues:78:11)
    at runNextTicks (node:internal/process/task_queues:65:3)
    at listOnTimeout (node:internal/timers:528:9)
    at processTimers (node:internal/timers:502:7)
01:58:13 ERR [PadLocalClient] error while syncing onpush: VError: [tid:63cb7212] request has been cancelled for reason: SERVER_ERROR: 4 DEADLINE_EXCEEDED: Deadline exceeded
    at Request._failAllPendingRequest (/app/node_modules/padlocal-client-ts/dist/Request.js:262:19)
    at ClientDuplexStreamImpl.<anonymous> (/app/node_modules/padlocal-client-ts/dist/Request.js:56:18)
    at ClientDuplexStreamImpl.emit (node:events:526:28)
    at ClientDuplexStreamImpl.emit (node:domain:475:12)
    at Object.onReceiveStatus (/app/node_modules/@grpc/grpc-js/build/src/client.js:391:28)
    at Object.onReceiveStatus (/app/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:328:181)
    at /app/node_modules/@grpc/grpc-js/build/src/call-stream.js:182:78
    at processTicksAndRejections (node:internal/process/task_queues:78:11)
    at runNextTicks (node:internal/process/task_queues:65:3)
    at listOnTimeout (node:internal/timers:528:9)
    at processTimers (node:internal/timers:502:7)
01:58:30 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
01:58:30 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
01:58:32 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
01:58:32 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
01:58:40 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
01:58:41 INFO [PuppetPadlocal] start login with type: AutoLogin
01:58:42 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
01:58:43 INFO [PuppetPadlocal] start login with type: AutoLogin
01:59:41 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
01:59:41 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
01:59:43 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
01:59:43 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
01:59:51 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
01:59:52 INFO [PuppetPadlocal] start login with type: AutoLogin
01:59:53 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
01:59:54 INFO [PuppetPadlocal] start login with type: AutoLogin
02:00:52 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:00:52 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:00:54 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:00:54 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:01:02 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:01:03 INFO [PuppetPadlocal] start login with type: AutoLogin
02:01:04 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:01:05 INFO [PuppetPadlocal] start login with type: AutoLogin
02:01:10 VERB HAWechaty nodes() total 3 wechaty instances are under management
02:02:03 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:02:04 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:02:05 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:02:05 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:02:14 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:02:14 INFO [PuppetPadlocal] start login with type: AutoLogin
02:02:15 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:02:16 INFO [PuppetPadlocal] start login with type: AutoLogin
02:03:14 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:03:15 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:03:16 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:03:16 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:03:25 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:03:25 INFO [PuppetPadlocal] start login with type: AutoLogin
02:03:26 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:03:27 INFO [PuppetPadlocal] start login with type: AutoLogin
02:04:25 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:04:25 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:04:27 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:04:27 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:04:35 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:04:36 INFO [PuppetPadlocal] start login with type: AutoLogin
02:04:37 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:04:38 INFO [PuppetPadlocal] start login with type: AutoLogin
02:05:36 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:05:36 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:05:38 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:05:38 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:05:46 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:05:47 INFO [PuppetPadlocal] start login with type: AutoLogin
02:05:48 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:05:49 INFO [PuppetPadlocal] start login with type: AutoLogin
02:06:47 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:06:47 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:06:49 VERB StateSwitch <PuppetPadlocal> off(pending) <- (false)
02:06:49 VERB StateSwitch <PuppetPadlocal> off(true) <- (pending)
02:06:57 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:06:58 INFO [PuppetPadlocal] start login with type: AutoLogin
02:06:59 VERB StateSwitch <PuppetPadlocal> on(pending) <- (false)
02:07:00 INFO [PuppetPadlocal] start login with type: AutoLogin

Retrying for more than ten times already.

Let's wait and see.

padlocal commented 2 years ago

Longlink host fail over has been added in wechaty-puppet-padlocal@1.11.14. Please have a try and feedback is wecome.

huan commented 2 years ago 
friday@wechaty-contributors:~/git/friday$ npm ls wechaty-puppet-padlocal
friday.bot@1.14.3 /home/friday/git/friday
└── wechaty-puppet-padlocal@1.20.1

wechaty-puppet-padlocal@1.20.1:

00:15:25 ERR [Request] [tid:382e6e57], padlocal grpc request failed: 3, error: IOError: [tid:382e6e57] Exception while handling wechat request: long link send request timeout
00:15:25 WARN [LongLink] [120.241.21.110:80] close connection on error,IOError: long link init failed: [tid:382e6e57] request has been cancelled for reason: CLIENT_ERROR: [tid:382e6e57] Exception while handling wechat request: long link send request timeout
00:15:25 WARN [LongLink] longlink reconnect [2] after delay:1000ms
...
00:15:37 ERR [Request] [tid:0addbe21], padlocal grpc request failed: 3, error: IOError: [tid:0addbe21] Exception while handling wechat request: long link send request timeout
00:15:37 WARN [LongLink] [120.241.21.110:80] close connection on error,IOError: long link init failed: [tid:0addbe21] request has been cancelled for reason: CLIENT_ERROR: [tid:0addbe21] Exception while handling wechat request: long link send request timeout
00:15:37 WARN [LongLink] longlink reconnect [3] after delay:2000ms
00:15:46 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
...
00:15:49 ERR [Request] [tid:15f222c3], padlocal grpc request failed: 3, error: IOError: [tid:15f222c3] Exception while handling wechat request: long link send request timeout
00:15:49 WARN [LongLink] [120.241.21.110:80] close connection on error,IOError: long link init failed: [tid:15f222c3] request has been cancelled for reason: CLIENT_ERROR: [tid:15f222c3] Exception while handling wechat request: long link send request timeout
00:15:49 WARN [LongLink] longlink reconnect [4] after delay:3000ms
...
00:18:06 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
00:18:07 ERR [Request] [tid:ff2314a5], padlocal grpc request failed: 3, error: IOError: [tid:ff2314a5] Exception while handling wechat request: long link send request timeout
00:18:07 WARN [LongLink] [120.241.21.110:80] close connection on error,IOError: long link init failed: [tid:ff2314a5] request has been cancelled for reason: CLIENT_ERROR: [tid:ff2314a5] Exception while handling wechat request: long link send request timeout
00:18:07 WARN [LongLink] longlink reconnect [5] after delay:5000ms
00:18:07 ERR [Request] [tid:10202e19], padlocal grpc request failed: 1, error: Error: 2 UNKNOWN: [tid:10202e19] login failed
00:18:07 ERR start client failed: SubRequestCancelError: [tid:10202e19] request has been cancelled for reason: SERVER_ERROR: 2 UNKNOWN: [tid:10202e19] login failed
    at Request._failAllPendingRequest (/home/friday/git/friday/node_modules/padlocal-client-ts/src/Request.ts:338:15)
    at ClientDuplexStreamImpl.<anonymous> (/home/friday/git/friday/node_modules/padlocal-client-ts/src/Request.ts:82:12)
    at ClientDuplexStreamImpl.emit (node:events:520:28)
    at Object.onReceiveStatus (/home/friday/git/friday/node_modules/@grpc/grpc-js/src/client.ts:689:18)
    at Object.onReceiveStatus (/home/friday/git/friday/node_modules/@grpc/grpc-js/src/client-interceptors.ts:424:48)
    at /home/friday/git/friday/node_modules/@grpc/grpc-js/src/call-stream.ts:330:24
    at processTicksAndRejections (node:internal/process/task_queues:78:11) 
00:18:09 INFO WechatyPluginContrib EventLogger heartbeat: heartbeat@padlocal
00:18:10 INFO [PuppetPadlocal] start login with type: AutoLogin
...
00:18:21 ERR [Request] [tid:5a32546a], padlocal grpc request failed: 3, error: IOError: [tid:5a32546a] Exception while handling wechat request: long link send request timeout
00:18:21 WARN [LongLink] [120.241.21.110:80] close connection on error,IOError: long link init failed: [tid:5a32546a] request has been cancelled for reason: CLIENT_ERROR: [tid:5a32546a] Exception while handling wechat request: long link send request timeout
00:18:21 WARN [LongLink] longlink reconnect [1] after delay:1000ms
...

The above problem will result in a QR Code that can not show problem: from http://friday.chatie.io:5200/ we can not get any QR Code for scan.

Update (2 hours later)

It connects successes and the bot back online!

image
perowong commented 1 year ago

wechaty-puppet-padlocal@1.20.1

I met the err report today, but it seems like no matter, that receving and sending some message is running fine.

07:48:18 ERR [Request] [tid:d5272cfe], padlocal grpc request failed: 3, error: IOError: [tid:d5272cfe] Exception while handling wechat request: long link send request timeout
07:48:18 ERR [PadLocalClient] error while syncing onpush: VError: [tid:d5272cfe] request has been cancelled for reason: CLIENT_ERROR: [tid:d5272cfe] Exception while handling wechat request: long link send request timeout
    at Request._failAllPendingRequest (xxx/node_modules/padlocal-client-ts/src/Request.ts:338:15)
    at Request.error (xxx/node_modules/padlocal-client-ts/src/Request.ts:351:10)
    at Request.<anonymous> (xxx/node_modules/padlocal-client-ts/src/Request.ts:221:16)
    at Generator.throw (<anonymous>)
    at rejected (xxx/node_modules/padlocal-client-ts/dist/Request.js:6:65)
JingruiLea commented 1 year ago

17:07:42 ERR [Request] [tid:50f0aef6], padlocal grpc request failed: 3, error: IOError: [tid:50f0aef6] Exception while handling wechat request: long link send request timeout 17:07:42 WARN [LongLink] [120.232.51.42:80] close connection on error,IOError: long link init failed: [tid:50f0aef6] request has been cancelled for reason: CLIENT_ERROR: [tid:50f0aef6] Exception while handling wechat request: long link send request timeout 17:07:42 WARN [LongLink] longlink reconnect [1] after delay:1000ms

是的一直有这个错误

hayate-hsu commented 1 year ago

重新遇到这个问题，这里已经接收到 扫码和确认登录的事件。 版本：0.65 抑或是 1.20.1

  09:52:32 INFO [PadLocalDemo] onScan: Scanned(3)

09:52:43 INFO [PadLocalDemo] onScan: Confirmed(4) 09:52:55 ERR [Request] [tid:e1c2e9b4], padlocal grpc request failed: 3, error: IOError: [tid:e1c2e9b4] Exception while handling wechat request: long link send request timeout 09:52:55 WARN [LongLink] [120.232.51.42:80] close connection on error,IOError: long link init failed: [tid:e1c2e9b4] request has been cancelled for reason: CLIENT_ERROR: [tid:e1c2e9b4] Exception while handling wechat request: long link send request timeout 09:52:55 WARN [LongLink] longlink reconnect [1] after delay:1000ms 09:53:07 ERR [Request] [tid:27f5451e], padlocal grpc request failed: 3, error: IOError: [tid:27f5451e] Exception while handling wechat request: long link send request timeout 09:53:07 WARN [LongLink] [120.232.51.42:80] close connection on error,IOError: long link init failed: [tid:27f5451e] request has been cancelled for reason: CLIENT_ERROR: [tid:27f5451e] Exception while handling wechat request: long link send request timeout 09:53:07 WARN [LongLink] longlink reconnect [2] after delay:1000ms 09:53:19 ERR [Request] [tid:03b7a4af], padlocal grpc request failed: 3, error: IOError: [tid:03b7a4af] Exception while handling wechat request: long link send request timeout 09:53:19 WARN [LongLink] [120.232.51.42:80] close connection on error,IOError: long link init failed: [tid:03b7a4af] request has been cancelled for reason: CLIENT_ERROR: [tid:03b7a4af] Exception while handling wechat request: long link send request timeout 09:53:19 WARN [LongLink] longlink reconnect [3] after delay:2000ms 09:53:32 ERR [Request] [tid:5f46612c], padlocal grpc request failed: 3, error: IOError: [tid:5f46612c] Exception while handling wechat request: long link send request timeout 09:53:32 WARN [LongLink] [120.232.51.42:80] close connection on error,IOError: long link init failed: [tid:5f46612c] request has been cancelled for reason: CLIENT_ERROR: [tid:5f46612c] Exception while handling wechat request: long link send request timeout 09:53:32 WARN [LongLink] longlink reconnect [4] after delay:3000ms 09:53:45 ERR [Request] [tid:47f6d370], padlocal grpc request failed: 1, error: Error: 2 UNKNOWN: [tid:47f6d370] login failed 09:53:45 ERR start client failed: VError: [tid:47f6d370] request has been cancelled for reason: SERVER_ERROR: 2 UNKNOWN: [tid:47f6d370] login failed at Request._failAllPendingRequest (/home/ubuntu/wechaty-puppet-padlocal-demo/node_modules/padlocal-client-ts/src/Request.ts:338:15) at ClientDuplexStreamImpl. (/home/ubuntu/wechaty-puppet-padlocal-demo/node_modules/padlocal-client-ts/src/Request.ts:82:12) at ClientDuplexStreamImpl.emit (node:events:513:28) at ClientDuplexStreamImpl.emit (node:domain:489:12) at Object.onReceiveStatus (/home/ubuntu/wechaty-puppet-padlocal-demo/node_modules/@grpc/grpc-js/src/client.ts:692:18) at Object.onReceiveStatus (/home/ubuntu/wechaty-puppet-padlocal-demo/node_modules/@grpc/grpc-js/src/client-interceptors.ts:417:48) at /home/ubuntu/wechaty-puppet-padlocal-demo/node_modules/@grpc/grpc-js/src/resolving-call.ts:111:24 at processTicksAndRejections (node:internal/process/task_queues:78:11) 09:53:48 INFO [PuppetPadlocal] start login with type: QrLogin 09:53:51 INFO [PadLocalDemo] onScan: Waiting(2)

Lz020316 commented 1 year ago

重新遇到这个问题，这里已经接收到 扫码和确认登录的事件。 版本：0.65 抑或是 1.20.1

  09:52:32 INFO [PadLocalDemo] onScan: Scanned(3)

09:52:43 INFO [PadLocalDemo] onScan: Confirmed(4) 09:52:55 ERR [Request] [tid:e1c2e9b4], padlocal grpc request failed: 3, error: IOError: [tid:e1c2e9b4] Exception while handling wechat request: long link send request timeout 09:52:55 WARN [LongLink] [120.232.51.42:80] close connection on error,IOError: long link init failed: [tid:e1c2e9b4] request has been cancelled for reason: CLIENT_ERROR: [tid:e1c2e9b4] Exception while handling wechat request: long link send request timeout 09:52:55 WARN [LongLink] longlink reconnect [1] after delay:1000ms 09:53:07 ERR [Request] [tid:27f5451e], padlocal grpc request failed: 3, error: IOError: [tid:27f5451e] Exception while handling wechat request: long link send request timeout 09:53:07 WARN [LongLink] [120.232.51.42:80] close connection on error,IOError: long link init failed: [tid:27f5451e] request has been cancelled for reason: CLIENT_ERROR: [tid:27f5451e] Exception while handling wechat request: long link send request timeout 09:53:07 WARN [LongLink] longlink reconnect [2] after delay:1000ms 09:53:19 ERR [Request] [tid:03b7a4af], padlocal grpc request failed: 3, error: IOError: [tid:03b7a4af] Exception while handling wechat request: long link send request timeout 09:53:19 WARN [LongLink] [120.232.51.42:80] close connection on error,IOError: long link init failed: [tid:03b7a4af] request has been cancelled for reason: CLIENT_ERROR: [tid:03b7a4af] Exception while handling wechat request: long link send request timeout 09:53:19 WARN [LongLink] longlink reconnect [3] after delay:2000ms 09:53:32 ERR [Request] [tid:5f46612c], padlocal grpc request failed: 3, error: IOError: [tid:5f46612c] Exception while handling wechat request: long link send request timeout 09:53:32 WARN [LongLink] [120.232.51.42:80] close connection on error,IOError: long link init failed: [tid:5f46612c] request has been cancelled for reason: CLIENT_ERROR: [tid:5f46612c] Exception while handling wechat request: long link send request timeout 09:53:32 WARN [LongLink] longlink reconnect [4] after delay:3000ms 09:53:45 ERR [Request] [tid:47f6d370], padlocal grpc request failed: 1, error: Error: 2 UNKNOWN: [tid:47f6d370] login failed 09:53:45 ERR start client failed: VError: [tid:47f6d370] request has been cancelled for reason: SERVER_ERROR: 2 UNKNOWN: [tid:47f6d370] login failed at Request._failAllPendingRequest (/home/ubuntu/wechaty-puppet-padlocal-demo/node_modules/padlocal-client-ts/src/Request.ts:338:15) at ClientDuplexStreamImpl. (/home/ubuntu/wechaty-puppet-padlocal-demo/node_modules/padlocal-client-ts/src/Request.ts:82:12) at ClientDuplexStreamImpl.emit (node:events:513:28) at ClientDuplexStreamImpl.emit (node:domain:489:12) at Object.onReceiveStatus (/home/ubuntu/wechaty-puppet-padlocal-demo/node_modules/@grpc/grpc-js/src/client.ts:692:18) at Object.onReceiveStatus (/home/ubuntu/wechaty-puppet-padlocal-demo/node_modules/@grpc/grpc-js/src/client-interceptors.ts:417:48) at /home/ubuntu/wechaty-puppet-padlocal-demo/node_modules/@grpc/grpc-js/src/resolving-call.ts:111:24 at processTicksAndRejections (node:internal/process/task_queues:78:11) 09:53:48 INFO [PuppetPadlocal] start login with type: QrLogin 09:53:51 INFO [PadLocalDemo] onScan: Waiting(2)

Have you solved it?

specialYmx commented 1 year ago

遇到了huan那个问题，也不知道padlocal所说的1.11.14版本解决了么？看报错发现项目部署的环境突然ping不通120.232.51.42这个ip了，是我项目运行的ip地址被封了么，已经运行了几个月，突然报错的然后发现ping不通了。 9e53b057-e34c-4aeb-b34e-8f8f4d019b6b

JuoJuo commented 1 year ago 
 20:17:37 ERR [Request] [tid:a39fe124], padlocal grpc request failed: 1, error: Error: 2 UNKNOWN: [tid:a39fe124] internal error
0|wx  | SubRequestCancelError [VError]: [tid:a39fe124] request has been cancelled for reason: SERVER_ERROR: 2 UNKNOWN: [tid:a39fe124] internal error
0|wx  |     at Request._failAllPendingRequest (/root/pad-demo/node_modules/padlocal-client-ts/dist/Request.js:265:19)
0|wx  |     at ClientDuplexStreamImpl.<anonymous> (/root/pad-demo/node_modules/padlocal-client-ts/dist/Request.js:56:18)
0|wx  |     at ClientDuplexStreamImpl.emit (node:events:394:28)
0|wx  |     at Object.onReceiveStatus (/root/pad-demo/node_modules/@grpc/grpc-js/build/src/client.js:410:28)
0|wx  |     at Object.onReceiveStatus (/root/pad-demo/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:323:181)
0|wx  |     at /root/pad-demo/node_modules/@grpc/grpc-js/build/src/resolving-call.js:94:78
0|wx  |     at processTicksAndRejections (node:internal/process/task_queues:78:11) {
0|wx  |   jse_shortmsg: '[tid:a39fe124] request has been cancelled for reason: SERVER_ERROR',
0|wx  |   jse_cause: Error: 2 UNKNOWN: [tid:a39fe124] internal error
0|wx  |       at callErrorFromStatus (/root/pad-demo/node_modules/@grpc/grpc-js/build/src/call.js:31:19)
0|wx  |       at Object.onReceiveStatus (/root/pad-demo/node_modules/@grpc/grpc-js/build/src/client.js:410:73)
0|wx  |       at Object.onReceiveStatus (/root/pad-demo/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:323:181)
0|wx  |       at /root/pad-demo/node_modules/@grpc/grpc-js/build/src/resolving-call.js:94:78
0|wx  |       at processTicksAndRejections (node:internal/process/task_queues:78:11)
0|wx  |   for call at
0|wx  |       at ServiceClientImpl.makeBidiStreamRequest (/root/pad-demo/node_modules/@grpc/grpc-js/build/src/client.js:394:34)
0|wx  |       at ServiceClientImpl.action (/root/pad-demo/node_modules/@grpc/grpc-js/build/src/make-client.js:105:19)
0|wx  |       at new Request (/root/pad-demo/node_modules/padlocal-client-ts/dist/Request.js:41:51)
0|wx  |       at PadLocalClient.createRequest (/root/pad-demo/node_modules/padlocal-client-ts/dist/PadLocalClient.js:93:21)
0|wx  |       at PadLocalClientApi.<anonymous> (/root/pad-demo/node_modules/padlocal-client-ts/dist/PadLocalClientApi.js:276:41)
0|wx  |       at Generator.next (<anonymous>)
0|wx  |       at /root/pad-demo/node_modules/padlocal-client-ts/dist/PadLocalClientApi.js:27:71
0|wx  |       at new Promise (<anonymous>)
0|wx  |       at __awaiter (/root/pad-demo/node_modules/padlocal-client-ts/dist/PadLocalClientApi.js:23:12)
0|wx  |       at PadLocalClientApi.getMessageImage (/root/pad-demo/node_modules/padlocal-client-ts/dist/PadLocalClientApi.js:273:16) {
0|wx  |     code: 2,
0|wx  |     details: '[tid:a39fe124] internal error',
0|wx  |     metadata: Metadata { internalRepr: [Map], options: {} }
0|wx  |   },
0|wx  |   jse_info: {},
0|wx  |   reason: 1
0|wx  | }
wenzai007 commented 11 months ago

Hi @huan , is there any update on this? This issue caused the login not able to be shown up, which is a big issue here.

8 VERB PuppetMemoryMixin setMemory(PadLocalDemo) 13:34:58 VERB WechatyPuppetMixin init() setting memory ... done 13:34:58 VERB WechatyPuppetMixin init() setting up events ... 13:34:58 VERB WechatyPuppetMixin setupPuppetEvents(Puppet(PadLocalDemo)) 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(friendship) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(login) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(logout) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(message) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(post) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(room-invite) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(room-join) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(room-leave) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(room-topic) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(scan) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(dirty) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(dong) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(error) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(heartbeat) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(ready) (listenerCount:0) registering... 13:34:58 VERB PuppetMixin setupPuppetEvents() puppet.on(reset) (listenerCount:0) registering... 13:34:58 VERB WechatyPuppetMixin setupPuppetEvents() ... done 13:34:58 VERB WechatyPuppetMixin init() setting up events ... done 13:34:58 VERB WechatyPuppetMixin init() emitting "puppet" event ... 13:34:58 VERB WechatyPuppetMixin init() emitting "puppet" event ... done 13:34:58 VERB ServiceCtl start() 13:34:58 SILL StateSwitch active() is false 13:34:58 SILL StateSwitch inactive() is true 13:34:58 SILL StateSwitch active() is false 13:34:58 VERB StateSwitch active(pending) <- (false) 13:34:58 VERB ServiceCtl start() super.start() ... 13:34:58 VERB WechatyPuppetMixin start() 13:34:58 VERB WechatyPuppetMixin start() super.start() ... 13:34:58 VERB WechatyIoMixin start() 13:34:58 VERB WechatySkeleton start() 13:34:58 VERB WechatyLoginMixin init() 13:34:58 VERB WechatyPuppetMixin init() 13:34:58 VERB WechatifyUserModuleMixin init() 13:34:58 VERB WechatySkeleton init() 13:34:58 VERB Wechaty init() Raven disabled (import("raven") failed) 13:34:58 VERB WechatifyUserModuleMixin init() Wechaty User Module (WUM)s have already wechatified: skip 13:34:58 VERB WechatyPuppetMixin init() skipped because this puppet has already been inited before. 13:34:58 VERB WechatyPuppetMixin start() super.start() ... done 13:34:58 SILL StateSwitch active() is false 13:34:58 VERB WechatyPuppetMixin start() starting puppet ... 13:34:58 VERB ReadyMixin start() 13:34:58 VERB PuppetServiceMixin start() 13:34:58 VERB ServiceCtl start() 13:34:58 SILL StateSwitch active() is false 13:34:58 SILL StateSwitch inactive() is true 13:34:58 SILL StateSwitch active() is false 13:34:58 VERB StateSwitch active(pending) <- (false) 13:34:58 VERB ServiceCtl start() super.start() ... 13:34:58 VERB PuppetCacheMixin start() 13:34:58 VERB PuppetLoginMixin start() 13:34:58 VERB PuppetMemoryMixin start() 13:34:58 VERB PuppetSkeleton start() 13:34:58 VERB PuppetCacheAgent start() 13:34:58 VERB PuppetCacheMixin start() "dirty" event listener added 13:34:58 VERB ServiceCtl start() super.start() ... done 13:34:58 VERB ServiceCtl start() this.onStart() ... 13:34:59 INFO

   Welcome to Wechaty PadLocal puppet!

   - puppet-padlocal version: 1.20.1
   - padlocal-ts-client version: 0.5.3
  ============================================================

13:34:59 SILL [Request] [tid:5b13a81b] send event to server, seq:1, ack:undefined, type: 200, payload: {"policy":0} 13:34:59 VERB ServiceCtl start() this.onStart() ... done 13:34:59 SILL StateSwitch active() is pending 13:34:59 VERB StateSwitch active(true) <- (pending) 13:34:59 VERB ServiceCtl start() ... done 13:34:59 VERB PuppetWatchdogAgent start() "heartbeat" event listener added 13:34:59 VERB PuppetWatchdogAgent start() "reset" event listener added 13:34:59 VERB WechatyPuppetMixin start() starting puppet ... done 13:34:59 VERB ServiceCtl start() super.start() ... done 13:34:59 VERB ServiceCtl start() this.onStart() ... 13:34:59 VERB Wechaty onStart() 13:34:59 VERB Wechaty <Puppet(PadLocalDemo)>(PadLocalDemo) onStart() v1.20.2 is starting... 13:34:59 VERB Wechaty id: dcdba843-e8a4-4940-84da-84cc7f5a8026 13:34:59 VERB Wechaty onStart() ... done 13:34:59 VERB ServiceCtl start() this.onStart() ... done 13:34:59 SILL StateSwitch active() is pending 13:34:59 VERB StateSwitch active(true) <- (pending) 13:34:59 VERB ServiceCtl start() ... done 13:34:59 INFO StarterBot Starter Bot Started. 13:34:59 SILL [Request] [tid:5b13a81b] receive event from server, seq:1 ack:0, type:15, payload:{"longlinkupdateevent":{"longlinkhost":{"host":"117.184.242.106","port":80},"reconnectimmediately":false,"longlinkhostlistList":[{"host":"117.184.242.106","port":80},{"host":"117.184.242.105","port":80},{"host":"223.166.152.105","port":80},{"host":"223.166.152.106","port":80},{"host":"101.89.15.106","port":80},{"host":"101.89.15.105","port":80}]}} 13:34:59 SILL [Request] [tid:5b13a81b] send event to server, seq:undefined, ack:1, type: 16, payload: {} 13:34:59 SILL [LongLink] update longlink host: [{"host":"117.184.242.106","port":80,"quality":30,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}] 13:35:00 SILL [Request] [tid:5b13a81b] receive event from server, seq:0 ack:0, type:201, payload:{"status":0,"logintype":1} 13:35:00 INFO [PuppetPadlocal] start login with type: AutoLogin 13:35:00 SILL [Request] [tid:5b13a81b] receive event from server, seq:2 ack:0, type:10, payload:{"longlinkrequest":{"messageid":"6e5ed507ed7d485389ca45be4c9ea6a2","longlinkid":"","initphase":false}} 13:35:00 SILL [LongLink] longlink start connect: 117.184.242.106:80 13:35:10 WARN [LongLink] [] longlink socket connect timeout 13:35:10 SILL [LongLink] adjust host quality:{"host":"117.184.242.106","port":80,"quality":28,"initialQuality":30}, connect success:false, host list:[{"host":"117.184.242.106","port":80,"quality":28,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}] 13:35:10 WARN [LongLink] [] close connection on error,IOError: longlink socket connect timeout 13:35:10 WARN [LongLink] longlink reconnect [1] after delay:1000ms 13:35:10 ERR [Request] [tid:5b13a81b], padlocal grpc request failed: 3, error: IOError: [tid:5b13a81b] Exception while handling wechat request: longlink fail to connect: longlink socket connect timeout 13:35:10 ERR start client failed: VError: [tid:5b13a81b] request has been cancelled for reason: CLIENT_ERROR: [tid:5b13a81b] Exception while handling wechat request: longlink fail to connect: longlink socket connect timeout at Request._failAllPendingRequest (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:338:15) at Request.error (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:351:10) at Request. (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:221:16) at Generator.throw () at rejected (E:\getting-started\node_modules\padlocal-client-ts\dist\Request.js:6:65) at processTicksAndRejections (node:internal/process/task_queues:96:5) 13:35:10 SILL [LongLink] [] longlink shutdown 13:35:10 SILL [Request] [tid:dcd77744] send event to server, seq:1, ack:undefined, type: 15, payload: {"clientstopevent":{}} 13:35:10 SILL [Request] [tid:dcd77744] receive event from server, seq:0 ack:1, type:16, payload:{} 13:35:12 SILL [Request] [tid:43656ae1] send event to server, seq:1, ack:undefined, type: 200, payload: {"policy":1} 13:35:12 SILL [Request] [tid:43656ae1] receive event from server, seq:1 ack:0, type:15, payload:{"longlinkupdateevent":{"longlinkhost":{"host":"117.184.242.106","port":80},"reconnectimmediately":false,"longlinkhostlistList":[{"host":"117.184.242.106","port":80},{"host":"117.184.242.105","port":80},{"host":"223.166.152.105","port":80},{"host":"223.166.152.106","port":80},{"host":"101.89.15.106","port":80},{"host":"101.89.15.105","port":80}]}} 13:35:12 SILL [Request] [tid:43656ae1] send event to server, seq:undefined, ack:1, type: 16, payload: {} 13:35:12 SILL [LongLink] update longlink host: [{"host":"117.184.242.106","port":80,"quality":30,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}] 13:35:12 SILL [Request] [tid:43656ae1] receive event from server, seq:0 ack:0, type:201, payload:{"status":0,"logintype":1} 13:35:12 INFO [PuppetPadlocal] start login with type: AutoLogin 13:35:12 SILL [Request] [tid:43656ae1] receive event from server, seq:2 ack:0, type:10, payload:{"longlinkrequest":{"messageid":"b7fcc20430ea44b1a8a7c5a3c10d846c","longlinkid":"","initphase":false}} 13:35:12 SILL [LongLink] longlink start connect: 117.184.242.106:80 13:35:22 WARN [LongLink] [] longlink socket connect timeout 13:35:22 SILL [LongLink] adjust host quality:{"host":"117.184.242.106","port":80,"quality":28,"initialQuality":30}, connect success:false, host list:[{"host":"117.184.242.106","port":80,"quality":28,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}] 13:35:22 WARN [LongLink] [] close connection on error,IOError: longlink socket connect timeout 13:35:22 WARN [LongLink] longlink reconnect [1] after delay:1000ms 13:35:22 ERR [Request] [tid:43656ae1], padlocal grpc request failed: 3, error: IOError: [tid:43656ae1] Exception while handling wechat request: longlink fail to connect: longlink socket connect timeout 13:35:23 ERR start client failed: VError: [tid:43656ae1] request has been cancelled for reason: CLIENT_ERROR: [tid:43656ae1] Exception while handling wechat request: longlink fail to connect: longlink socket connect timeout at Request._failAllPendingRequest (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:338:15) at Request.error (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:351:10) at Request. (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:221:16) at Generator.throw () at rejected (E:\getting-started\node_modules\padlocal-client-ts\dist\Request.js:6:65) at processTicksAndRejections (node:internal/process/task_queues:96:5) 13:35:23 SILL [LongLink] [] longlink shutdown 13:35:23 SILL [Request] [tid:0189a1b3] send event to server, seq:1, ack:undefined, type: 15, payload: {"clientstopevent":{}} 13:35:23 SILL [Request] [tid:0189a1b3] receive event from server, seq:0 ack:1, type:16, payload:{} 13:35:24 SILL [Request] [tid:00e01c15] send event to server, seq:1, ack:undefined, type: 200, payload: {"policy":1} 13:35:25 SILL [Request] [tid:00e01c15] receive event from server, seq:1 ack:0, type:15, payload:{"longlinkupdateevent":{"longlinkhost":{"host":"117.184.242.106","port":80},"reconnectimmediately":false,"longlinkhostlistList":[{"host":"117.184.242.106","port":80},{"host":"117.184.242.105","port":80},{"host":"223.166.152.105","port":80},{"host":"223.166.152.106","port":80},{"host":"101.89.15.106","port":80},{"host":"101.89.15.105","port":80}]}} 13:35:25 SILL [Request] [tid:00e01c15] send event to server, seq:undefined, ack:1, type: 16, payload: {} 13:35:25 SILL [LongLink] update longlink host: [{"host":"117.184.242.106","port":80,"quality":30,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}] 13:35:25 SILL [Request] [tid:00e01c15] receive event from server, seq:0 ack:0, type:201, payload:{"status":0,"logintype":1} 13:35:25 INFO [PuppetPadlocal] start login with type: AutoLogin 13:35:25 SILL [Request] [tid:00e01c15] receive event from server, seq:2 ack:0, type:10, payload:{"longlinkrequest":{"messageid":"4656320f03f548a988c159d5b7aba988","longlinkid":"","initphase":false}} 13:35:25 SILL [LongLink] longlink start connect: 117.184.242.106:80 13:35:35 WARN [LongLink] [] longlink socket connect timeout 13:35:35 SILL [LongLink] adjust host quality:{"host":"117.184.242.106","port":80,"quality":28,"initialQuality":30}, connect success:false, host list:[{"host":"117.184.242.106","port":80,"quality":28,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}] 13:35:35 WARN [LongLink] [] close connection on error,IOError: longlink socket connect timeout 13:35:35 WARN [LongLink] longlink reconnect [1] after delay:1000ms 13:35:35 ERR [Request] [tid:00e01c15], padlocal grpc request failed: 3, error: IOError: [tid:00e01c15] Exception while handling wechat request: longlink fail to connect: longlink socket connect timeout 13:35:35 ERR start client failed: VError: [tid:00e01c15] request has been cancelled for reason: CLIENT_ERROR: [tid:00e01c15] Exception while handling wechat request: longlink fail to connect: longlink socket connect timeout at Request._failAllPendingRequest (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:338:15) at Request.error (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:351:10) at Request. (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:221:16) at Generator.throw () at rejected (E:\getting-started\node_modules\padlocal-client-ts\dist\Request.js:6:65) at processTicksAndRejections (node:internal/process/task_queues:96:5) 13:35:35 SILL [LongLink] [] longlink shutdown 13:35:35 SILL [Request] [tid:c498558b] send event to server, seq:1, ack:undefined, type: 15, payload: {"clientstopevent":{}} 13:35:36 SILL [Request] [tid:c498558b] receive event from server, seq:0 ack:1, type:16, payload:{} 13:35:38 SILL [Request] [tid:869981a2] send event to server, seq:1, ack:undefined, type: 200, payload: {"policy":1} 13:35:39 SILL [Request] [tid:869981a2] receive event from server, seq:1 ack:0, type:15, payload:{"longlinkupdateevent":{"longlinkhost":{"host":"117.184.242.106","port":80},"reconnectimmediately":false,"longlinkhostlistList":[{"host":"117.184.242.106","port":80},{"host":"117.184.242.105","port":80},{"host":"223.166.152.105","port":80},{"host":"223.166.152.106","port":80},{"host":"101.89.15.106","port":80},{"host":"101.89.15.105","port":80}]}} 13:35:39 SILL [Request] [tid:869981a2] send event to server, seq:undefined, ack:1, type: 16, payload: {} 13:35:39 SILL [LongLink] update longlink host: [{"host":"117.184.242.106","port":80,"quality":30,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}] 13:35:39 SILL [Request] [tid:869981a2] receive event from server, seq:0 ack:0, type:201, payload:{"status":0,"logintype":1} 13:35:39 INFO [PuppetPadlocal] start login with type: AutoLogin 13:35:39 SILL [Request] [tid:869981a2] receive event from server, seq:2 ack:0, type:10, payload:{"longlinkrequest":{"messageid":"5a3da407c8e94cd78a5ef3d07c3bcb53","longlinkid":"","initphase":false}} 13:35:39 SILL [LongLink] longlink start connect: 117.184.242.106:80 13:35:49 WARN [LongLink] [] longlink socket connect timeout 13:35:49 SILL [LongLink] adjust host quality:{"host":"117.184.242.106","port":80,"quality":28,"initialQuality":30}, connect success:false, host list:[{"host":"117.184.242.106","port":80,"quality":28,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}] 13:35:49 WARN [LongLink] [] close connection on error,IOError: longlink socket connect timeout 13:35:49 WARN [LongLink] longlink reconnect [1] after delay:1000ms 13:35:49 ERR [Request] [tid:869981a2], padlocal grpc request failed: 3, error: IOError: [tid:869981a2] Exception while handling wechat request: longlink fail to connect: longlink socket connect timeout 13:35:49 ERR start client failed: VError: [tid:869981a2] request has been cancelled for reason: CLIENT_ERROR: [tid:869981a2] Exception while handling wechat request: longlink fail to connect: longlink socket connect timeout at Request._failAllPendingRequest (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:338:15) at Request.error (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:351:10) at Request. (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:221:16) at Generator.throw () at rejected (E:\getting-started\node_modules\padlocal-client-ts\dist\Request.js:6:65) at processTicksAndRejections (node:internal/process/task_queues:96:5) 13:35:49 SILL [LongLink] [] longlink shutdown 13:35:49 SILL [Request] [tid:c788c6cc] send event to server, seq:1, ack:undefined, type: 15, payload: {"clientstopevent":{}} 13:35:49 SILL [Request] [tid:c788c6cc] receive event from server, seq:0 ack:1, type:16, payload:{} 13:35:53 SILL [Request] [tid:5f745675] send event to server, seq:1, ack:undefined, type: 200, payload: {"policy":1} 13:35:54 SILL [Request] [tid:5f745675] receive event from server, seq:1 ack:0, type:15, payload:{"longlinkupdateevent":{"longlinkhost":{"host":"117.184.242.106","port":80},"reconnectimmediately":false,"longlinkhostlistList":[{"host":"117.184.242.106","port":80},{"host":"117.184.242.105","port":80},{"host":"223.166.152.105","port":80},{"host":"223.166.152.106","port":80},{"host":"101.89.15.106","port":80},{"host":"101.89.15.105","port":80}]}} 13:35:54 SILL [Request] [tid:5f745675] send event to server, seq:undefined, ack:1, type: 16, payload: {} 13:35:54 SILL [LongLink] update longlink host: [{"host":"117.184.242.106","port":80,"quality":30,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}] 13:35:54 SILL [Request] [tid:5f745675] receive event from server, seq:0 ack:0, type:201, payload:{"status":0,"logintype":1} 13:35:54 INFO [PuppetPadlocal] start login with type: AutoLogin 13:35:54 SILL [Request] [tid:5f745675] receive event from server, seq:2 ack:0, type:10, payload:{"longlinkrequest":{"messageid":"540db1d9d6f54fa3bef5c94e16845d4a","longlinkid":"","initphase":false}} 13:35:54 SILL [LongLink] longlink start connect: 117.184.242.106:80 13:36:04 WARN [LongLink] [] longlink socket connect timeout 13:36:04 SILL [LongLink] adjust host quality:{"host":"117.184.242.106","port":80,"quality":28,"initialQuality":30}, connect success:false, host list:[{"host":"117.184.242.106","port":80,"quality":28,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}] 13:36:04 WARN [LongLink] [] close connection on error,IOError: longlink socket connect timeout 13:36:04 WARN [LongLink] longlink reconnect [1] after delay:1000ms 13:36:04 ERR [Request] [tid:5f745675], padlocal grpc request failed: 3, error: IOError: [tid:5f745675] Exception while handling wechat request: longlink fail to connect: longlink socket connect timeout 13:36:04 ERR start client failed: VError: [tid:5f745675] request has been cancelled for reason: CLIENT_ERROR: [tid:5f745675] Exception while handling wechat request: longlink fail to connect: longlink socket connect timeout at Request._failAllPendingRequest (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:338:15) at Request.error (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:351:10) at Request. (E:\getting-started\node_modules\padlocal-client-ts\src\Request.ts:221:16) at Generator.throw () at rejected (E:\getting-started\node_modules\padlocal-client-ts\dist\Request.js:6:65) at processTicksAndRejections (node:internal/process/task_queues:96:5) 13:36:04 SILL [LongLink] [] longlink shutdown 13:36:04 SILL [Request] [tid:9e7f2fe3] send event to server, seq:1, ack:undefined, type: 15, payload: {"clientstopevent":{}} 13:36:04 SILL [Request] [tid:9e7f2fe3] receive event from server, seq:0 ack:1, type:16, payload:{} 13:36:10 SILL [Request] [tid:084f7218] send event to server, seq:1, ack:undefined, type: 200, payload: {"policy":1} 13:36:11 SILL [Request] [tid:084f7218] receive event from server, seq:1 ack:0, type:15, payload:{"longlinkupdateevent":{"longlinkhost":{"host":"117.184.242.106","port":80},"reconnectimmediately":false,"longlinkhostlistList":[{"host":"117.184.242.106","port":80},{"host":"117.184.242.105","port":80},{"host":"223.166.152.105","port":80},{"host":"223.166.152.106","port":80},{"host":"101.89.15.106","port":80},{"host":"101.89.15.105","port":80}]}} 13:36:11 SILL [Request] [tid:084f7218] send event to server, seq:undefined, ack:1, type: 16, payload: {} 13:36:11 SILL [LongLink] update longlink host: [{"host":"117.184.242.106","port":80,"quality":30,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}] 13:36:11 SILL [Request] [tid:084f7218] receive event from server, seq:0 ack:0, type:201, payload:{"status":0,"logintype":1} 13:36:11 INFO [PuppetPadlocal] start login with type: AutoLogin 13:36:11 SILL [Request] [tid:084f7218] receive event from server, seq:2 ack:0, type:10, payload:{"longlinkrequest":{"messageid":"9e74a287735b48118552aff9aac387cb","longlinkid":"","initphase":false}} 13:36:11 SILL [LongLink] longlink start connect: 117.184.242.106:80 13:36:12 VERB ReadyMixin stop() Terminate batch job (Y/N)?

wenzai007 commented 11 months ago

@padlocal , may I know what is the iplist of the longlink? why it returned those ips? And none of these ips can be pinged successfully, can you folks ping below ips successfully? Is there anything wrong here?

13:34:59 SILL [Request] [tid:5b13a81b] receive event from server, seq:1 ack:0, type:15, payload:{"longlinkupdateevent":{"longlinkhost":{"host":"117.184.242.106","port":80},"reconnectimmediately":false,"longlinkhostlistList":[{"host":"117.184.242.106","port":80},{"host":"117.184.242.105","port":80},{"host":"223.166.152.105","port":80},{"host":"223.166.152.106","port":80},{"host":"101.89.15.106","port":80},{"host":"101.89.15.105","port":80}]}} 13:34:59 SILL [Request] [tid:5b13a81b] send event to server, seq:undefined, ack:1, type: 16, payload: {} 13:34:59 SILL [LongLink] update longlink host: [{"host":"117.184.242.106","port":80,"quality":30,"initialQuality":30},{"host":"117.184.242.105","port":80,"quality":25,"initialQuality":25},{"host":"223.166.152.105","port":80,"quality":20,"initialQuality":20},{"host":"223.166.152.106","port":80,"quality":15,"initialQuality":15},{"host":"101.89.15.106","port":80,"quality":10,"initialQuality":10},{"host":"101.89.15.105","port":80,"quality":5,"initialQuality":5}]

wenzai007 commented 11 months ago

these errors seems to be thrown from this class, https://github.com/padlocal/padlocal-client-ts/blob/master/src/Request.ts

May I know what does the Longlink do? and even I tried several different devices and different networks, they all returned the same set of ip list, is there any cache of it? Just curious is it possible to use some workaround to make me able to login? e.g. Not using this LongLink or switch to another protocol rather than grpc prototocol?

wenzai007 commented 11 months ago

Thanks a lot @padlocal for helping with this! I switched to another token and it no longer has this issue, according to @padlocal it might because the ip list which was used long time ago(already invalid ips) were remebered or cached so that it returned the stale ip list, which of course will be timed out.

However, if this is the case, I would like to know, who remembered those ip list? the weixin server? Or wechaty server? It sounds like this is a bug from one certain side, if the ip cannot be connected, should we tell the server to not return the cached ip list, instead give us the newest ips? Otherwise we will timeout forever.

phigrey commented 7 months ago

My problem has been resolved after I switched to another token. However, is there any client support in the community to refund or regenerate the old token for me? Since I have not received any the reply from wechat support.