tristandunn / pusher-fake

A fake Pusher server for development and testing.
https://rubygems.org/gems/pusher-fake
MIT License
173 stars 32 forks source link

Why am I getting PusherError [1006] ? #60

Closed gustiando closed 5 years ago

gustiando commented 5 years ago

Hello from a rabbit hole! 🕳🐇

After awhile digging through my test logs, I noticed Pusher has been failing quite a bit for a reason I'm not very familiar and unsure how to proceed.

Any ideas?

pusher version: 1.3.2 pusher-fake version: 1.12.0

[0508/172823.638515:INFO:CONSOLE(12)] "Pusher : Error : {"type":"WebSocketError","error":{"type":"PusherError","data":{"code":1006}}}", source: https://js.pusher.com/2.2/pusher.min.js (12)
[1557361703.638][DEBUG]: DevTools WebSocket Event: Network.webSocketClosed BC4FB7FE22313826BBE092594767E80B {
   "requestId": "1000059116.858",
   "timestamp": 19292.117205
}
[1557361703.639][DEBUG]: DevTools WebSocket Event: Runtime.consoleAPICalled BC4FB7FE22313826BBE092594767E80B {
   "args": [ {
      "type": "string",
      "value": "Pusher : Error : {\"type\":\"WebSocketError\",\"error\":{\"type\":\"PusherError\",\"data\":{\"code\":1006}}}"
   } ],
   "executionContextId": 24,
   "stackTrace": {
      "callFrames": [ {
         "columnNumber": 336,
         "functionName": "b.warn",
         "lineNumber": 11,
         "scriptId": "9357",
         "url": "https://js.pusher.com/2.2/pusher.min.js"
      }, {
         "columnNumber": 498,
         "functionName": "",
         "lineNumber": 10,
         "scriptId": "9357",
         "url": "https://js.pusher.com/2.2/pusher.min.js"
      }, {
         "columnNumber": 76,
         "functionName": "a.emit",
         "lineNumber": 32,
         "scriptId": "9357",
         "url": "https://js.pusher.com/2.2/pusher.min.js"
      }, {
         "columnNumber": 133,
         "functionName": "error",
         "lineNumber": 100,
         "scriptId": "9357",
         "url": "https://js.pusher.com/2.2/pusher.min.js"
      }, {
         "columnNumber": 76,
         "functionName": "a.emit",
         "lineNumber": 32,
         "scriptId": "9357",
         "url": "https://js.pusher.com/2.2/pusher.min.js"
      }, {
         "columnNumber": 463,
         "functionName": "c.handleCloseEvent",
         "lineNumber": 90,
         "scriptId": "9357",
         "url": "https://js.pusher.com/2.2/pusher.min.js"
      }, {
         "columnNumber": 148,
         "functionName": "closed",
         "lineNumber": 90,
         "scriptId": "9357",
         "url": "https://js.pusher.com/2.2/pusher.min.js"
      }, {
         "columnNumber": 76,
         "functionName": "a.emit",
         "lineNumber": 32,
         "scriptId": "9357",
         "url": "https://js.pusher.com/2.2/pusher.min.js"
      }, {
         "columnNumber": 257,
         "functionName": "c.changeState",
         "lineNumber": 69,
         "scriptId": "9357",
         "url": "https://js.pusher.com/2.2/pusher.min.js"
      }, {
         "columnNumber": 433,
         "functionName": "c.onClose",
         "lineNumber": 67,
         "scriptId": "9357",
         "url": "https://js.pusher.com/2.2/pusher.min.js"
      }, {
         "columnNumber": 316,
         "functionName": "a.socket.onclose",
         "lineNumber": 68,
         "scriptId": "9357",
         "url": "https://js.pusher.com/2.2/pusher.min.js"
      } ]
   },
   "timestamp": 1557361703638.279,
   "type": "warning"
}
tristandunn commented 5 years ago

Searching through the pusher-js code implies it's an interrupted connection. Do you know if it's connecting at all?

Also, looks like you're using v2.2 of the client, but v4.4 is the latest. Could you try updating and see if that helps any?

gustiando commented 5 years ago

thanks @tristandunn ! It does connect most of the time I believe. The logs also have spec runs where pusher is able to stay connected and do its job. Below is another example form the logs:

[1557376080.584][DEBUG]: DevTools WebSocket Event: Network.webSocketFrameReceived 2CB7BC797DAC8628CC4E3EE05DBBB45E {
   "requestId": "1000074727.252",
   "response": {
      "mask": false,
      "opcode": 1,
      "payloadData": "{\"event\":\"pusher:connection_established\",\"data\":\"{\\\"socket_id\\\":\\\"7011936.1687920\\\",\\\"activity_timeout\\\":120}\"}"
   },
   "timestamp": 23792.453833
}

Upgrading to 4.4 was going to be my next attempt indeed. I'm currently unfamiliar with Pusher, but am starting to look into what it would take for the upgrade to happen seamlessly. Any recommendation for such a major upgrade?

tristandunn commented 5 years ago

Interesting that it's not always happening. What are you running the tests in?

And I don't believe I've had very many issues, at least no major issues that I can recall, when upgrading the library. The changes are generally clean up, bug fixes, and new features as opposed to breaking changes.

gustiando commented 5 years ago

@tristandunn thanks for the guidance. I was able to successfully upgrade to 4.4. The issue I'm having now is a 500 on the server side when triggering the event:

SSL_connect returned=1 errno=0 state=SSLv3/TLS write client hello: wrong version number excluded from capture: DSN not set

OpenSSL::SSL::SSLError (SSL_connect returned=1 errno=0 state=SSLv3/TLS write client hello: wrong version number):

Trigger example:

Pusher["channel-name"].trigger!('event-name', url: file_url, file_name: file_name)

This might not be related to pusher or pusher fake directly, but am curious if you've ever seen this.

tristandunn commented 5 years ago

Can you try disabling SSL?

gustiando commented 5 years ago

That seem to have done it. I'll report shortly after merging the 4.4 upgrade and how is that looking in the Capybara flaky specs error logs we were seeing around Pusher. thanks!

tristandunn commented 5 years ago

@gumatias Great to hear! You might be able to disabled SSL without upgrading to 4.4 if that makes it easier.

tristandunn commented 5 years ago

Guessing this worked out, so closing.