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.

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

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

Open
huan opened this issue Sep 7, 2021 · 17 comments

Comments

@huan
Copy link
Member

huan commented Sep 7, 2021

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
Copy link

binsee commented Feb 7, 2022

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
Copy link
Collaborator

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
Copy link
Member Author

huan commented May 17, 2022

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
Copy link
Member Author

huan commented May 18, 2022

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.

@huan huan pinned this issue May 18, 2022
@padlocal
Copy link
Collaborator

Longlink host fail over has been added in [email protected].
Please have a try and feedback is wecome.

@huan
Copy link
Member Author

huan commented Jun 12, 2022

friday@wechaty-contributors:~/git/friday$ npm ls wechaty-puppet-padlocal
[email protected] /home/friday/git/friday
└── [email protected]

[email protected]:

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
Copy link

perowong commented Sep 7, 2022

[email protected]

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
Copy link

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
Copy link

重新遇到这个问题,这里已经接收到 扫码和确认登录的事件。
版本: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
Copy link

Lz020316 commented Jun 6, 2023

重新遇到这个问题,这里已经接收到 扫码和确认登录的事件。 版本: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
Copy link

specialYmx commented Jun 9, 2023

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

@JuoJuo
Copy link

JuoJuo commented Aug 23, 2023

 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
Copy link

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
Copy link

@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
Copy link

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
Copy link

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
Copy link

phigrey commented Jan 16, 2024

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

12 participants