search

signalapp / Signal-Desktop

A private messenger for Windows, macOS, and Linux.
https://signal.org/download
GNU Affero General Public License v3.0
14.7k stars 2.68k forks source link

Signal fails to connect on pure IPV6 system #2327

Closed Maverik closed 6 years ago

Maverik commented 6 years ago

Bug description

Signal desktop app fails to connect on a pure IPV6 system trying to reach an IPV4 address (52.207.57.189 / 52.6.64.115) (which of course fails).

Steps to reproduce

  1. Ensure you only have IPV6 address assigned and IPV4 is only reachable via 6to4 tunneling
  2. Start Signal

Actual result:

Signal will keep trying to connect forever. (I can get signal to work on this same system if I reactivate IPV4 on the interface)

Expected result:

Signal connects as normal on IPV4 systems.

Screenshots

image (Screenshot after I attempted to connect with IPV4 enabled once to confirm & then changed back to IPV6 only system - contacts redacted)

Platform info

Signal version: v1.9.0

Operating System: Windows 10 - 1803

Linked device version: Android Signal 4.18.3

Link to debug log

If it's really required, I can post the log, but it really is chalk full (about 6000 lines as of this writing) of the following message (with variations on IP it's trying to connect to):

INFO  2018-05-02T15:17:17.818Z rotateSignedPrekey() failed. Trying again in five seconds
INFO  2018-05-02T15:17:22.820Z Rotating signed prekey...
INFO  2018-05-02T15:17:22.822Z Next signed key rotation scheduled for 2018-05-04T15:17:22.819Z
INFO  2018-05-02T15:17:22.883Z Saving new signed prekey 47
INFO  2018-05-02T15:17:22.885Z PUT https://textsecure-service.whispersystems.org/v2/keys/signed
INFO  2018-05-02T15:17:22.892Z PUT https://textsecure-service.whispersystems.org/v2/keys/signed 0 Error
INFO  2018-05-02T15:17:23.901Z PUT https://textsecure-service.whispersystems.org/v2/keys/signed
INFO  2018-05-02T15:17:23.912Z PUT https://textsecure-service.whispersystems.org/v2/keys/signed 0 Error
INFO  2018-05-02T15:17:24.927Z PUT https://textsecure-service.whispersystems.org/v2/keys/signed
INFO  2018-05-02T15:17:24.938Z PUT https://textsecure-service.whispersystems.org/v2/keys/signed 0 Error
INFO  2018-05-02T15:17:24.941Z rotateSignedPrekey error: HTTPError: promise_ajax catch; code: -1
    at HTTPError (file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37626:17)
    at file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37595:18
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:188:7)
Original stack:
FetchError: request to https://textsecure-service.whispersystems.org/v2/keys/signed failed, reason: connect EHOSTUNREACH 52.6.64.115:443
    at ClientRequest.<anonymous> ([REDACTED]\app.asar\node_modules\node-fetch\index.js:133:11)
    at emitOne (events.js:115:13)
    at ClientRequest.emit (events.js:210:7)
    at TLSSocket.socketErrorListener (_http_client.js:401:9)
    at emitOne (events.js:115:13)
    at TLSSocket.emit (events.js:210:7)
    at emitErrorNT (internal/streams/destroy.js:64:8)
    at _combinedTickCallback (internal/process/next_tick.js:138:11)
    at process._tickCallback (internal/process/next_tick.js:180:9)
Initial stack:
Error
    at ajax (file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37618:25)
    at TextSecureServer.ajax (file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37662:20)
    at TextSecureServer.setSignedPreKey (file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37806:25)
    at file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:38094:32
    at <anonymous>
INFO  2018-05-02T15:17:24.942Z rotateSignedPrekey() failed. Trying again in five seconds
INFO  2018-05-02T15:17:25.880Z connect
INFO  2018-05-02T15:17:25.880Z MessageReceiver.close()
INFO  2018-05-02T15:17:25.881Z opening message socket https://textsecure-service.whispersystems.org
INFO  2018-05-02T15:17:25.886Z drained
INFO  2018-05-02T15:17:25.887Z Sync read receipt configuration status: {"status":"skipped","reason":"hasPreviouslySynced"}
INFO  2018-05-02T15:17:25.889Z websocket error
INFO  2018-05-02T15:17:25.890Z websocket closed 1006 connection failed calledClose: 
INFO  2018-05-02T15:17:25.891Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-05-02T15:17:25.897Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-05-02T15:17:26.900Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-05-02T15:17:26.972Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-05-02T15:17:27.949Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-05-02T15:17:27.962Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-05-02T15:17:27.965Z background onError: HTTPError: promise_ajax catch; code: -1
    at HTTPError (file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37626:17)
    at file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37595:18
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:188:7)
Original stack:
FetchError: request to https://textsecure-service.whispersystems.org/v1/devices failed, reason: connect EHOSTUNREACH 52.207.57.189:443
    at ClientRequest.<anonymous> ([REDACTED]\app.asar\node_modules\node-fetch\index.js:133:11)
    at emitOne (events.js:115:13)
    at ClientRequest.emit (events.js:210:7)
    at TLSSocket.socketErrorListener (_http_client.js:401:9)
    at emitOne (events.js:115:13)
    at TLSSocket.emit (events.js:210:7)
    at emitErrorNT (internal/streams/destroy.js:64:8)
    at _combinedTickCallback (internal/process/next_tick.js:138:11)
    at process._tickCallback (internal/process/next_tick.js:180:9)
Initial stack:
Error
    at ajax (file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37618:25)
    at TextSecureServer.ajax (file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37662:20)
    at TextSecureServer.getDevices (file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37772:25)
    at MessageReceiver.onclose (file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:38718:24)
    at W3CWebSocket._dispatchEvent [as dispatchEvent] ([REDACTED]\app.asar\node_modules\yaeti\lib\EventTarget.js:107:17)
    at W3CWebSocket.onConnectFailed ([REDACTED]\app.asar\node_modules\websocket\lib\W3CWebSocket.js:219:14)
    at WebSocketClient.<anonymous> ([REDACTED]\app.asar\node_modules\websocket\lib\W3CWebSocket.js:59:25)
    at emitOne (events.js:115:13)
    at WebSocketClient.emit (events.js:210:7)
    at ClientRequest.handleRequestError ([REDACTED]\app.asar\node_modules\websocket\lib\WebSocketClient.js:215:14)
Maverik commented 6 years ago

I just made another observation: this may be an issue with Electron apps in general (or perhaps even just Node.js problem?). I was just doing PostMan session and their new app refuses to connect to anything unless I switch on IPV4 despite the fact that underlying windows system has no problem connecting to these endpoints. Unfortunately I'm totally out of my depth when it comes to JS world of things (i'm a c# developer) so can't really make much sense of code myself.

gasi-signal commented 6 years ago

@Venomed Thanks for reporting this. This is the first report I know about regarding IPv6. It would be helpful if you could find more information regarding the root cause of this, i.e. is it Node, Electron, or just us. Have you tried using other Electron apps, e.g. Slack, Microsoft VS Code, etc. via your IPv6 setup? Getting more information would help us understand the issue better. Thanks.

Maverik commented 6 years ago

@gasi-signal Thanks for your quick response. I've tried Slack Desktop / Whatsapp Desktop and they both work fine on pure IPv6. VS Code (insider) also has no problem downloading it's update over IPv6. So I guess that rules out limitation of Node.js / Electron in this context. I'm happy to help with any further information gathering but might need some hand holding just because I'm operating in uncharted territory when it comes to JS world in general and of course Node/Electron world specifically (just a pointer to some reference on how to dig information out will be enough).

Though I doubt this matters much but I also tried this with the latest beta build (v1.10.0-beta.1) and have the same issue.

Maverik commented 6 years ago

Here's an additional stack trace that runs infinitely when you start a fresh install of signal with pure IPV6 (pulled from v1.10.0-beta.1 session):

Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) SignalBeta/1.10.0-beta.1 Chrome/59.0.3071.115 Electron/1.8.4 Safari/537.36 node/8.2.1 env/production
INFO  2018-05-03T14:55:43.643Z app ready
INFO  2018-05-03T14:55:43.652Z Ensure attachments directory exists
INFO  2018-05-03T14:55:43.782Z Location reset needed
INFO  2018-05-03T14:55:43.782Z Initializing BrowserWindow config: {"show":true,"width":800,"height":610,"minWidth":640,"minHeight":360,"autoHideMenuBar":false,"webPreferences":{"nodeIntegration":false,"preload":"[REDACTED]\\app.asar\\preload.js"},"icon":"[REDACTED]\\app.asar\\images\\icon_256.png"}
INFO  2018-05-03T14:55:47.995Z Using OS-level spell check API with locale en_GB
INFO  2018-05-03T14:55:48.340Z pre-main prep time: 3 ms
INFO  2018-05-03T14:55:48.385Z Build expires:  2018-07-30T00:06:44.000Z
INFO  2018-05-03T14:55:48.423Z background page reloaded
INFO  2018-05-03T14:55:48.423Z environment: production
INFO  2018-05-03T14:55:48.424Z Start IndexedDB migrations
INFO  2018-05-03T14:55:48.424Z Run migrations on database with attachment data
INFO  2018-05-03T14:55:48.541Z Database status {"firstMigrationVersion":12,"lastMigrationVersion":18,"databaseVersion":1,"isAlreadyUpgraded":false}
INFO  2018-05-03T14:55:48.546Z Migration 12
INFO  2018-05-03T14:55:48.547Z creating object stores
INFO  2018-05-03T14:55:48.550Z creating debug log
INFO  2018-05-03T14:55:48.550Z Migration 13
INFO  2018-05-03T14:55:48.550Z Adding fields to identity keys
INFO  2018-05-03T14:55:48.566Z Migration 14
INFO  2018-05-03T14:55:48.567Z Adding unprocessed message store
INFO  2018-05-03T14:55:48.567Z Migration 15
INFO  2018-05-03T14:55:48.567Z Adding messages index for de-duplication
INFO  2018-05-03T14:55:48.567Z Migration 16
INFO  2018-05-03T14:55:48.568Z Dropping log table, since we now log to disk
INFO  2018-05-03T14:55:48.568Z Migration 17
INFO  2018-05-03T14:55:48.568Z Create index from attachment schema version to attachment
INFO  2018-05-03T14:55:48.569Z Complete migration to database version 17 Duration: 0ms
INFO  2018-05-03T14:55:48.569Z Migration 18
INFO  2018-05-03T14:55:48.569Z Create message attachment metadata index: 'hasAttachments'
INFO  2018-05-03T14:55:48.569Z Create message attachment metadata index: 'hasVisualMediaAttachments'
INFO  2018-05-03T14:55:48.569Z Create message attachment metadata index: 'hasFileAttachments'
INFO  2018-05-03T14:55:48.570Z Complete migration to database version 18 Duration: 0ms
INFO  2018-05-03T14:55:48.619Z Close database connection
INFO  2018-05-03T14:55:48.619Z Storage fetch
INFO  2018-05-03T14:55:48.623Z ConversationController: starting initial fetch
INFO  2018-05-03T14:55:48.624Z ConversationController: done with initial fetch
INFO  2018-05-03T14:55:48.626Z New version detected: 1.10.0-beta.1
INFO  2018-05-03T14:55:48.626Z listening for registration events
INFO  2018-05-03T14:55:48.867Z opening provisioning socket https://textsecure-service.whispersystems.org
INFO  2018-05-03T14:55:50.036Z provisioning socket closed 1006
INFO  2018-05-03T14:55:50.042Z provisioning failed Error: websocket closed
    at W3CWebSocket.socket.onclose (file:///C:/Users/[REDACTED]/AppData/Local/Programs/signal-desktop-beta/resources/app.asar/js/libtextsecure.js:37955:36)
    at W3CWebSocket._dispatchEvent [as dispatchEvent] ([REDACTED]\app.asar\node_modules\yaeti\lib\EventTarget.js:107:17)
    at W3CWebSocket.onConnectFailed ([REDACTED]\app.asar\node_modules\websocket\lib\W3CWebSocket.js:219:14)
    at WebSocketClient.<anonymous> ([REDACTED]\app.asar\node_modules\websocket\lib\W3CWebSocket.js:59:25)
    at emitOne (events.js:115:13)
    at WebSocketClient.emit (events.js:210:7)
    at ClientRequest.handleRequestError ([REDACTED]\app.asar\node_modules\websocket\lib\WebSocketClient.js:215:14)
    at emitOne (events.js:115:13)
    at ClientRequest.emit (events.js:210:7)
    at TLSSocket.socketErrorListener (_http_client.js:401:9)

The above socket close exception occurs infinitely on pure IPv6 system.

This stack trace had initially confused me so I ended up turning on IPv4 and found out that it was stuck at IP (and then I took the snippet out of logs and opened this issue) but thought I'll post this stacktrace as well to be complete.

Maverik commented 6 years ago

OK this is embarrassing: I found the problem!

TL;DR

DNS problem. Not a bug with Signal/Electron/Node.js

Long version

I had been using Googles DNS64 addresses (2001:4860:4860::6464, 2001:4860:4860::64) as resolver when everything was working fine. Then came along Cloudflare public DNS and me being curious about shiny new things, I switched to 2606:4700:4700::1111 / 2606:4700:4700::1001 as primary DNS which is apparently not DNS64 (certainly my fault for not digging through documentation more thoroughly). During my troubleshooting, at some point Windows lost the IPv6 DNS settings and my own network DNS64 took over and things started working again (at this point I had stopped trying to connect signal so realization of the problem took time).

Today when I started fresh I realized every IPv4 only site had gone down since I switched manually to Cloudflare DNS again to fix Windows amnesia and at that point it hit me. I've assumed it to be DNS64 which might not be the case and well I switched to Google DNS and everything is back to normal! Coincidentally I've also got Postman working fine now :)

Lesson Learned

If an application is trying to connect to IPv4 on an IPv6 only system, absence of DNS64 is the most likely culprit.

I hope this saves somebody else from head-scratching time I spent on this. Sorry to have added to your bug list when it really was PEBCAK :)

Suggestion

Please add some error message to your application when connections fail. While I'm able to dig through logs and eventually figure out what went wrong, Most users will have no clue if the app is never going to start even (since it stays forever in "Connecting" state).

gasi-signal commented 6 years ago

@Venomed Thanks for the great write-up and no worries, we all have days like these 😉 FWIW, one of my brilliant co-workers found out that maybe our backend (textsecure-service.whispersystems.org) is not (yet) configured for IPv6. Were you able to connect via IPv6 in the end?

Re: error message. Good suggestion. Created an issue to track: https://github.com/signalapp/Signal-Desktop/issues/2336

Maverik commented 6 years ago

Yes indeed @gasi I've now got NAT64 working to hit the IPv4 address of textsecure... and indeed I don't see any IPv6 associated with that end point but that's not a problem for me at least (because of DNS64/NAT64 combo). Keep up the good work 👍

gasi-signal commented 6 years ago

@Venomed Thanks for confirming.

mdavids commented 4 years ago

As far as I am concerned, this problem still exists. I have an IPv6-only system (with IPv4 disabled on my interface) and a NAT64/DNS64 setup. I can see the Signal desktop app is attempting A and AAAA queries for textsecure-service.whispersystems.org (among other things like cdn.signal.org and updates2.signal.org) and then trying to prefer the A-record over the AAAA record, even though there is no IPv4-connectivity possible. When I reconfigure my DNS64 resolver in such a way that an A-query gives a NODATA result, everything works.

It seems to me that Signal (or Electron, or NodeJS for that matter) has no, or a dysfunctional 'Happy Eyeballs'-implementation. Could be NodeJS: https://github.com/nodejs/node/issues/6307

treysis commented 3 years ago

It's more or less a NodeJS thing that is solved since v17. Although still no happy eyeballs. However, electron will only support that after the NodeJS fix makes it into v18 (LTS) and electron switching over to v18, and then Signal switching to the latest electron release. I don't expect that to happen well into 2022, maybe even 2023.

NodeJS generally gives the option to override the reordering of DNS results in favor of IPv4. Not sure if electron has the option to pass this on. In that case it could be 'fixed' by Signal itself.

mdavids commented 3 years ago

I would like to add to this issue another finding; if the loopback interface has the 127.0.0.1 IPv4 address completely removed (leaving only IPv6 ::1 available), the Signal app will no longer update. It notices there is an update available, but refuses to fetch it.

Here are two screenshots; one with the 127.0.0.1 available, the other with that address missing:

127.0.0.1 and ::1 present

only ::1 present

I tried this on a Macbook with OSX 11.6 in a DNS64/NAT64 environment made working with the trick mentioned in https://github.com/signalapp/Signal-Desktop/issues/2327#issuecomment-565377322