wechaty / wechaty-puppet-padpro

Apache License 2.0
238 stars 64 forks source link

个别文件 toFileBox() 会失败 #117

Open fatesinger opened 5 years ago

fatesinger commented 5 years ago

重要:请不要删除模板自行填写,所有不按照模板填写的issue,我们将不会处理。

0. 发 Issue 指南

  1. 请运行下面的命令,看问题是否可以被解决:

    rm -rf package-lock.json
    rm -rf node_modules
    npm install
  2. 请在 FAQ 清单 看是否已有解决办法。

  3. 请先在issue 中搜关键信息,确认你要发的内容和之前的issue 不重复。

1. 提供你的包版本信息

2. Bug 描述

个别文件获取失败

3. 复现的步骤 (或者解决的步骤)

给bot发送文件,通过 toFileBox 获取失败

例子:

const file = await message.toFileBox();

4. 期待程序运行的结果

正确获取到文件

5. 程序实际运行的结果

报错,大致是解密出错

6. 完整的日志信息:

silly 日志 ```shell 18:55:49 VERB Puppet messagePayload(1002093824) 获取文件失败 Error: error:0606506D:digital envelope routines:EVP_DecryptFinal_ex:wrong final block length at Decipheriv.final (internal/crypto/cipher.js:164:28) at Object.exports.decryptAes (/node_modules/wechaty-puppet-padpro/dist/src/utils/aes-utils.js:18:41) at CDNManager. (/node_modules/wechaty-puppet-padpro/dist/src/manager/cdn-manager.js:153:28) at Generator.next () at fulfilled (/node_modules/wechaty-puppet-padpro/dist/src/manager/cdn-manager.js:4:58) at process._tickCallback (internal/process/next_tick.js:68:7) ```

7. 其他信息

不能正确获取的文件

导入项目测试.xlsx

windmemory commented 5 years ago

please try with v0.0.58

fatesinger commented 5 years ago

更新到 v0.0.58 还是不行。

windmemory commented 5 years ago

需要提供详细log,不仅是报错部分的,需要上下文

fatesinger commented 5 years ago
收到消息后的日志 ```shell 11:25:12 VERB Message static load(1002094040) 11:25:12 SILL Accessory #89 constructor() 11:25:12 VERB Message constructor(1002094040) for class Message 11:25:12 VERB Message ready() 11:25:12 VERB Puppet messagePayload(1002094040) 11:25:12 SILL Puppet messagePayloadCache(1002094040) cache MISS 11:25:12 SILL Puppet messagePayload(1002094040) cache SET 11:25:12 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:12 SILL Contact ready() isReady() true 11:25:12 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:12 SILL Contact ready() isReady() true 11:25:12 VERB Puppet selfId() 11:25:12 VERB Message mention() 11:25:12 VERB Puppet selfId() 11:25:12 VERB Puppet messagePayload(1002094040) 11:25:12 VERB Puppet selfId() 11:25:12 VERB Message mention() 11:25:12 VERB Puppet selfId() 11:25:12 VERB Message mention() 11:25:15 VERB Contact findAll() 11:25:15 VERB Puppet contactSearch(query=undefined, ) 11:25:15 SILL Puppet contactSearch() searchIdList.length = 86 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 11:25:15 SILL Contact ready() isReady() true 11:25:15 VERB Contact say(抱歉,你的文档[624f138e903a8c22.xlsx]上传失败了,请稍后重试) 11:25:20 SILL Wechaty memoryCheck() free: 1428 MB, require: 4 MB 11:25:32 INFO PadproManager initData() finished with contacts: 86, rooms: 536 11:26:02 SILL Wechaty memoryCheck() free: 1380 MB, require: 4 MB ```

之前的报错是 捕获 message.toFileBox() 异常 报的错。silly 日志没有报错

windmemory commented 5 years ago

@fatesinger 你能找到这个问题的复现方法么?

关于这个报错,大概是什么类型的文件会报错?是不是文件名是中文名?文件是通过什么客户端发送的?

fatesinger commented 5 years ago

1. 提供你的包版本信息

wechaty 版本:0.27.59
wechaty-puppet-padpro 版本:0.3.12
node 版本: v10.13.0
你使用的操作系统:ubuntu

3. 复现的步骤 (或者解决的步骤)

  1. 通过 pc 端微信给 bot 发送文件

  2. bot 收到消息后调用 message.toFileBox() 方法

  3. 查看手机微信消息,点击发送的文件(iphone)

  4. 如果文件提示需要下载,这个文件肯定会获取失败

如图

会失败的文件

image

成功的文件

image

代码报错位置

wechaty-puppet-padpro/src/manager/cdn-manager.ts

private async _sendCdnRequest (
    data: Buffer,
    url: string,
  ): Promise<Buffer> {
    log.silly(PRE, `sendCdnRequest(${url})`)
    if (!this.cdnInfo) {
      throw new Error(`Can not send cdn request to cdn server since there is no cdn info yet.`)
    }
    ...

    return new Promise<Buffer>((resolve, reject) => {
      const req: ClientRequest = http.request(options, async (response: IncomingMessage) => {
        const rawData: any = []
        let dataLen = 0

        if (response.statusCode !== 200) {
          // 这里会报错
          // response.statusCode 400
          // response.statusMessage  400 Bad Request
          reject(new Error(`sendCdnRequest failed, status code: ${response.statusCode}, status message: ${response.statusMessage}`))
        }
         ...
      })
      req.setTimeout(SEND_SHORT_TIMEOUT)
      req.on('error', (error: Error) => {
        console.error(error)
        reject(error)
      })
      req.on('timeout', () => {
        req.abort()
        reject(new Error(`TIMEOUT`))
      })
      req.write(data)
      req.end()
    })
  }

6. 完整的日志信息:

silly 部分日志 ```shell 21:11:22 SILL PadproManager syncMessage() 21:11:22 SILL DedupeApi dedupe() no need to dedupe api GrpcSyncMessage. 21:11:22 SILL WechatGateway _callApi(GrpcSyncMessage, undefined) the 185 times, booted 853.64 seconds since boot. 21:11:22 SILL WechatGateway sendLong() reqSeq: 2928712520 21:11:22 SILL WechatGateway sendLong() receive back package size: 918 21:11:22 SILL GrpcGateway parse(GrpcSyncMessage) get response: {"data":[{"MsgId":1431031211,"FromUserName":"wxid_zbmv092s1a0q12","ToUserName":"wxid_uua6les58i3y22","MsgType":49,"Content":"bilibili-backup-master.zip</tit 21:11:22 VERB PadproManager syncMessage() got 1 message(s). 21:11:22 SILL CacheManager setFileCache(304e020100044730450201000204156bbe5c02033d0af802046934feb602045d418e8c0420777869645f38666a626837713431766564313231305f313536343537373337370204010400070201000400, {"aesKey":{"type":"Buffer","data":[239,213,234,92,117,36,88,29,202,152,167,123,36,4,70,37]},"fileId":"304e020100044730450201000204156bbe5c02033d0af802046934feb602045d418e8c0420777869645f38666a626837713431766564313231305f313536343537373337370204010400070201000400","timestamp":1564578682258}) 21:11:22 VERB PuppetPadpro onPadproMessage({id=1431031211, type=App(49)}) 21:11:22 VERB PuppetPadpro onPadproMessageRoomInvitation([object Object]) 21:11:22 VERB Message static load(1431031211) 21:11:22 SILL Accessory #50<Message> constructor() 21:11:22 VERB Message constructor(1431031211) for class Message 21:11:22 VERB Message ready() 21:11:22 VERB Puppet messagePayload(1431031211) 21:11:22 SILL Puppet messagePayloadCache(1431031211) cache MISS 21:11:22 VERB PuppetPadpro messageRawPayloadParser({messageId="1431031211"}) 21:11:22 SILL messageRawPayloadParser messageType 1 21:11:22 SILL PuppetPadpro messagePayload({"id":"1431031211","timestamp":1564578681,"type":1,"filename":"bilibili-backup-master.zip","fromId":"wxid_zbmv092s1a0q12","text":"<msg><appmsg appid=\"\" sdkver=\"0\"><title>bilibili-backup-master.zip6049245091@cdn_304e020100044730450201000204156bbe5c02033d0af802046934feb602045d418e8c0420777869645f38666a626837713431766564313231305f313536343537373337370204010400070201000400_efd5ea5c7524581dca98a77b24044625_1zip304e020100044730450201000204156bbe5c02033d0af802046934feb602045d418e8c0420777869645f38666a626837713431766564313231305f313536343537373337370204010400070201000400efd5ea5c7524581dca98a77b240446255cbab9c9a5801b0990640ffbf20bb6f0wxid_zbmv092s1a0q1201","toId":"wxid_uua6les58i3y22"}) 21:11:22 SILL Puppet messagePayload(1431031211) cache SET 21:11:22 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 21:11:22 SILL Contact ready() isReady() true 21:11:22 SILL Contact ready() @ Puppet#0()/PuppetPadpro#0 21:11:22 SILL Contact ready() isReady() true 21:11:22 VERB Puppet selfId() 21:11:22 VERB Message mention() 21:11:22 VERB Puppet selfId() 21:11:22 VERB Puppet selfId() 21:11:22 VERB Message mention() 21:11:22 VERB Puppet selfId() 21:11:22 VERB Message mention() 21:11:22 SILL PuppetPadpro messageFile(1431031211) 21:11:22 VERB Puppet messagePayload(1431031211) 21:11:22 SILL CDNManager downloadFile(304e020100044730450201000204156bbe5c02033d0af802046934feb602045d418e8c0420777869645f38666a626837713431766564313231305f313536343537373337370204010400070201000400, 49245091) started. 21:11:22 SILL CDNManager _downloadFile(1, 0, 65536) 21:11:22 SILL CDNManager sendCdnRequest(/download) ```

7. 其他信息

总结: ios没有自动下载的文件,调用 message.toFileBox() 方法就会失败,请求下载时cdn地址报错400,猜测可能大文件的下载方式不同,组包信息可能有变化。

windmemory commented 5 years ago

Thanks for the very detailed issue, we will look into this issue later.