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

App often remains disconnected. #1075

Open
charlesmchen opened this Issue Feb 25, 2017 · 58 comments

Comments

@charlesmchen

charlesmchen commented Feb 25, 2017

Often when I return to the app after a long period away (e.g. laptop closed for a few hours, then reopened), desktop client is stuck in a disconnected state. Restarting Chrome fixes the issue.

https://gist.github.com/5f477d186a8ed2065ed9bcb9c30468d4

screen shot 2017-02-24 at 10 23 10 pm

@charlesmchen

This comment has been minimized.

Show comment
Hide comment
@charlesmchen

charlesmchen Feb 25, 2017

It looks like the websocket is closed and not reopened later when I return to the app and/or reconnect to wifi.

charlesmchen commented Feb 25, 2017

It looks like the websocket is closed and not reopened later when I return to the app and/or reconnect to wifi.

@liliakai

This comment has been minimized.

Show comment
Hide comment
@liliakai

liliakai Feb 25, 2017

Contributor

At the end of this log, it looks like we are actively trying once a minute to reconnect, but websocket connections and http requests are simply failing, as if offline. Did you try just restarting Signal, rather than chrome? I don't see any restarts in the log.

Contributor

liliakai commented Feb 25, 2017

At the end of this log, it looks like we are actively trying once a minute to reconnect, but websocket connections and http requests are simply failing, as if offline. Did you try just restarting Signal, rather than chrome? I don't see any restarts in the log.

@damnyourefine

This comment has been minimized.

Show comment
Hide comment

damnyourefine commented Mar 17, 2017

@textarcana

This comment has been minimized.

Show comment
Hide comment
@textarcana

textarcana Mar 17, 2017

I experienced this issue for the first time on March 17 just a day or so after upgrading to version 0.33.0 from a version that was several months older (sorry I don't know my previous version number).

textarcana commented Mar 17, 2017

I experienced this issue for the first time on March 17 just a day or so after upgrading to version 0.33.0 from a version that was several months older (sorry I don't know my previous version number).

@svevang

This comment has been minimized.

Show comment
Hide comment
@svevang

svevang Mar 17, 2017

Contributor

It looks like the XHR is failing to call its event handlers:

  1. When the websocket is closed (via 1006 error code, laptop goes to sleep), we issue some xhr requests to probe the state of the network connection.
  2. however, once the laptop wakes up, we receive a 'online' event and trigger the init function.
  3. this deallocates the message receiver and consequently deallocates the XHR handlers over here. So our probe in step 1 never returns.

If that's so, we should pull the state of the network-probing up out of the MessageReceiver.onclose, and store/handle it at the same level as the onError method in background.js.

Contributor

svevang commented Mar 17, 2017

It looks like the XHR is failing to call its event handlers:

  1. When the websocket is closed (via 1006 error code, laptop goes to sleep), we issue some xhr requests to probe the state of the network connection.
  2. however, once the laptop wakes up, we receive a 'online' event and trigger the init function.
  3. this deallocates the message receiver and consequently deallocates the XHR handlers over here. So our probe in step 1 never returns.

If that's so, we should pull the state of the network-probing up out of the MessageReceiver.onclose, and store/handle it at the same level as the onError method in background.js.

@liliakai

This comment has been minimized.

Show comment
Hide comment
@liliakai

liliakai Mar 18, 2017

Contributor

I think you're right about the xhr not completing, since both logs above contain a GET to /v1/devices without a corresponding response and I believe that would effectively hang the reconnect process. 🎉

However, I'm not sure I understand your explanation. If we were making it back to the init function, it would immediately instantiate a new MessageReceiver and thus a new websocket connection. Have you verified that the 'online' event is firing on resume? I would guess that maybe the problem is that it doesn't fire in this case, and the xhr fails silently...

Contributor

liliakai commented Mar 18, 2017

I think you're right about the xhr not completing, since both logs above contain a GET to /v1/devices without a corresponding response and I believe that would effectively hang the reconnect process. 🎉

However, I'm not sure I understand your explanation. If we were making it back to the init function, it would immediately instantiate a new MessageReceiver and thus a new websocket connection. Have you verified that the 'online' event is firing on resume? I would guess that maybe the problem is that it doesn't fire in this case, and the xhr fails silently...

@svevang

This comment has been minimized.

Show comment
Hide comment
@svevang

svevang Mar 18, 2017

Contributor

Yep, you're right. I don't see any output from a newly instantiated MessageReceiver. Hmm, so that theory is bust. That lack of XHR response sure is interesting--have to dig into that a bit more.

Contributor

svevang commented Mar 18, 2017

Yep, you're right. I don't see any output from a newly instantiated MessageReceiver. Hmm, so that theory is bust. That lack of XHR response sure is interesting--have to dig into that a bit more.

@ahayes

This comment has been minimized.

Show comment
Hide comment
@ahayes

ahayes May 2, 2017

Are you sure it is actually disconnected or is it just forgetting to remove the "Offline Check your network connection." message?

I ask because I have Signal Desktop set to open at login (only just installed it for the first time yesterday) and this morning it popped that message up, despite syncing a new group conversation I started last night while the system was shut down. I found this bug because I thought it was not reconnecting but I just tried sending someone a message and they received it, even though the "Offline" warning has not gone away.

If it is a different problem, I can open a new issue. I just thought I would try here first since it might be related. Obviously something isn't getting notified that the network has come up.

ahayes commented May 2, 2017

Are you sure it is actually disconnected or is it just forgetting to remove the "Offline Check your network connection." message?

I ask because I have Signal Desktop set to open at login (only just installed it for the first time yesterday) and this morning it popped that message up, despite syncing a new group conversation I started last night while the system was shut down. I found this bug because I thought it was not reconnecting but I just tried sending someone a message and they received it, even though the "Offline" warning has not gone away.

If it is a different problem, I can open a new issue. I just thought I would try here first since it might be related. Obviously something isn't getting notified that the network has come up.

@NoahIMVU

This comment has been minimized.

Show comment
Hide comment
@NoahIMVU

NoahIMVU Jun 9, 2017

I've got the same problem, and I can't seem to clear it (including by restarting Signal). The app simply says "Disconnected\n Check your network connection." Interestingly, I can still send messages just fine, and those messages appear on my android app as well. But I can't receive messages on my mac desktop, nor do I see the messages that I send with my android device on my mac. It's been like this for days now, and I believe it started when I took a vacation to another state in a different time zone (if that matters).

NoahIMVU commented Jun 9, 2017

I've got the same problem, and I can't seem to clear it (including by restarting Signal). The app simply says "Disconnected\n Check your network connection." Interestingly, I can still send messages just fine, and those messages appear on my android app as well. But I can't receive messages on my mac desktop, nor do I see the messages that I send with my android device on my mac. It's been like this for days now, and I believe it started when I took a vacation to another state in a different time zone (if that matters).

@liliakai

This comment has been minimized.

Show comment
Hide comment
@liliakai

liliakai Jun 9, 2017

Contributor

@NoahIMVU If restarting doesn't fix it, then you've got a different problem, and you should open a new issue and post a debug log..

Contributor

liliakai commented Jun 9, 2017

@NoahIMVU If restarting doesn't fix it, then you've got a different problem, and you should open a new issue and post a debug log..

@NoahIMVU

This comment has been minimized.

Show comment
Hide comment
@NoahIMVU

NoahIMVU Jun 9, 2017

My bug on the topic was closed as a duplicate of this one. Note that restarting the computer did fix the problem, so there's that.

NoahIMVU commented Jun 9, 2017

My bug on the topic was closed as a duplicate of this one. Note that restarting the computer did fix the problem, so there's that.

@Evilcry

This comment has been minimized.

Show comment
Hide comment
@Evilcry

Evilcry Jul 29, 2017

Same problem here and I'm able to reproduce systematically, just put machine in sleep mode and wake up.
Solution in my case is to wait ~5 mins.

https://gist.github.com/anonymous/91f66e75e261335542350b4eca99328b

Evilcry commented Jul 29, 2017

Same problem here and I'm able to reproduce systematically, just put machine in sleep mode and wake up.
Solution in my case is to wait ~5 mins.

https://gist.github.com/anonymous/91f66e75e261335542350b4eca99328b

@GuardianMajor

This comment has been minimized.

Show comment
Hide comment
@GuardianMajor

GuardianMajor Sep 11, 2017

I can confirm this is happening on [Electron][1.0.23.256][Win10x64] and it happens in a very almost predictable manner.

  • It occurs less than a minute after the client is loaded and after the contacts, messages and everything are successfully synced.
  • Selecting a different user, clears the problem instantly.
  • If you send a message to anyone then idle for about a minute, you get it again.

It feels as if it has a hard time maintaining the socket active for some reason and it is somehow "timing out". The client has full internet access and the firewall has been set accordingly to not restrict it either.

  • However, with or without the firewall active, it happens.
  • On WiFi or Cable, it happens.
  • Other programs running or not, it happens.

I looked at the log, nothing there that is any different (by much) from what has been reported already, so I won't clutter the issue with it, but available if needed. Let me know if you need anything else.

Currently my go to fix is to select a different user to clear it, but it does make me wonder if while in this state, it will actually sync new messages being sent. I will have to test it while in this state by having a user send me a message to see if it will come through or not. I suspect that message getting pushed out to the client will indeed reset the state and come through but that is just an unconfirmed assumption at the moment.

One last "oddity" if you will that I have observed is that sometimes the longer the client is open, the less it will happen and there are times the longer the client is open the more it happens; that has been inconsistent enough that I have not been able to attribute a pattern to it yet, will keep posted if I figure out the why. I am currently observing the environment as a whole during the "stable period" with the same during the "unstable period" to see if I can attribute the difference to any particular activity during that time which might shed some light.

GuardianMajor commented Sep 11, 2017

I can confirm this is happening on [Electron][1.0.23.256][Win10x64] and it happens in a very almost predictable manner.

  • It occurs less than a minute after the client is loaded and after the contacts, messages and everything are successfully synced.
  • Selecting a different user, clears the problem instantly.
  • If you send a message to anyone then idle for about a minute, you get it again.

It feels as if it has a hard time maintaining the socket active for some reason and it is somehow "timing out". The client has full internet access and the firewall has been set accordingly to not restrict it either.

  • However, with or without the firewall active, it happens.
  • On WiFi or Cable, it happens.
  • Other programs running or not, it happens.

I looked at the log, nothing there that is any different (by much) from what has been reported already, so I won't clutter the issue with it, but available if needed. Let me know if you need anything else.

Currently my go to fix is to select a different user to clear it, but it does make me wonder if while in this state, it will actually sync new messages being sent. I will have to test it while in this state by having a user send me a message to see if it will come through or not. I suspect that message getting pushed out to the client will indeed reset the state and come through but that is just an unconfirmed assumption at the moment.

One last "oddity" if you will that I have observed is that sometimes the longer the client is open, the less it will happen and there are times the longer the client is open the more it happens; that has been inconsistent enough that I have not been able to attribute a pattern to it yet, will keep posted if I figure out the why. I am currently observing the environment as a whole during the "stable period" with the same during the "unstable period" to see if I can attribute the difference to any particular activity during that time which might shed some light.

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Sep 12, 2017

Contributor

Does this ever happen when the application has focus? Or does it only happen when you've switched to another app?

I'm working on a theory that Electron aggressively tunes the event loop down when the application is not in-focus, and on some machines that means losing the connection to the websocket.

Contributor

scottnonnenberg commented Sep 12, 2017

Does this ever happen when the application has focus? Or does it only happen when you've switched to another app?

I'm working on a theory that Electron aggressively tunes the event loop down when the application is not in-focus, and on some machines that means losing the connection to the websocket.

@GuardianMajor

This comment has been minimized.

Show comment
Hide comment
@GuardianMajor

GuardianMajor Sep 12, 2017

@scottnonnenberg I have not observed specifically for focus/blur so can't be sure but it seems it doesn't matter since most of the time it happens comes after starting it where focus is obvious.

GuardianMajor commented Sep 12, 2017

@scottnonnenberg I have not observed specifically for focus/blur so can't be sure but it seems it doesn't matter since most of the time it happens comes after starting it where focus is obvious.

@Dyras

This comment has been minimized.

Show comment
Hide comment

Dyras commented Sep 12, 2017

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Sep 12, 2017

Contributor

@Dyras Thank you very much for providing those logs! I'm noticing an interesting pattern: a big space in the logs before most 'websocket closed' log entries. Not sure what would cause that while the application was focused, aside from IndexedDB compaction or something. Even our various types of cryptography we still do on the primary thread shouldn't take longer than a second each...

About 90 seconds:

2017-09-12T10:11:48.645Z updating notifications 1
2017-09-12T10:13:18.453Z websocket closed 3001 No response to keepalive request

About 90 seconds:

2017-09-12T10:28:01.270Z updating notifications 1
2017-09-12T10:29:30.996Z websocket closed 3001 No response to keepalive request

About 90 seconds:

2017-09-12T10:30:12.189Z removeFromCache +[REDACTED]323.1 1505212210548
2017-09-12T10:31:41.791Z websocket closed 3001 No response to keepalive request

About 90 seconds:

2017-09-12T11:10:21.048Z removeFromCache +[REDACTED]323.1 1505214624128
2017-09-12T11:11:45.466Z GET https://textsecure-service.whispersystems.org/v1/profile/+[REDACTED]323
2017-09-12T11:11:45.514Z message 1505214624128 expires at 1505301105513
2017-09-12T11:11:45.520Z Sending 1 read receipts
2017-09-12T11:11:45.682Z websocket closed 3001 No response to keepalive request

About 90 seconds:

2017-09-12T11:21:25.308Z updating notifications 2
2017-09-12T11:22:54.823Z websocket closed 3001 No response to keepalive request

About 90 seconds:

2017-09-12T11:27:51.675Z removeFromCache +[REDACTED]323.1 1505215669930
2017-09-12T11:29:21.548Z websocket closed 3001 No response to keepalive request
Contributor

scottnonnenberg commented Sep 12, 2017

@Dyras Thank you very much for providing those logs! I'm noticing an interesting pattern: a big space in the logs before most 'websocket closed' log entries. Not sure what would cause that while the application was focused, aside from IndexedDB compaction or something. Even our various types of cryptography we still do on the primary thread shouldn't take longer than a second each...

About 90 seconds:

2017-09-12T10:11:48.645Z updating notifications 1
2017-09-12T10:13:18.453Z websocket closed 3001 No response to keepalive request

About 90 seconds:

2017-09-12T10:28:01.270Z updating notifications 1
2017-09-12T10:29:30.996Z websocket closed 3001 No response to keepalive request

About 90 seconds:

2017-09-12T10:30:12.189Z removeFromCache +[REDACTED]323.1 1505212210548
2017-09-12T10:31:41.791Z websocket closed 3001 No response to keepalive request

About 90 seconds:

2017-09-12T11:10:21.048Z removeFromCache +[REDACTED]323.1 1505214624128
2017-09-12T11:11:45.466Z GET https://textsecure-service.whispersystems.org/v1/profile/+[REDACTED]323
2017-09-12T11:11:45.514Z message 1505214624128 expires at 1505301105513
2017-09-12T11:11:45.520Z Sending 1 read receipts
2017-09-12T11:11:45.682Z websocket closed 3001 No response to keepalive request

About 90 seconds:

2017-09-12T11:21:25.308Z updating notifications 2
2017-09-12T11:22:54.823Z websocket closed 3001 No response to keepalive request

About 90 seconds:

2017-09-12T11:27:51.675Z removeFromCache +[REDACTED]323.1 1505215669930
2017-09-12T11:29:21.548Z websocket closed 3001 No response to keepalive request
@Dyras

This comment has been minimized.

Show comment
Hide comment
@Dyras

Dyras Sep 16, 2017

Do you need more logs now that additional logging has been merged?
https://gist.github.com/anonymous/533c53d89c9d5b6b57210bdc6c6a8533

Also I seem to have been mistaken, Signal never seems to disconnect while focused.

Dyras commented Sep 16, 2017

Do you need more logs now that additional logging has been merged?
https://gist.github.com/anonymous/533c53d89c9d5b6b57210bdc6c6a8533

Also I seem to have been mistaken, Signal never seems to disconnect while focused.

@rainerzufall

This comment has been minimized.

Show comment
Hide comment
@rainerzufall

rainerzufall Sep 18, 2017

A log after I saw Signal Desktop (electron 1.0.25) being disconnected while it was not in focus for some time: https://gist.github.com/anonymous/64d2d5551bd08cd3f7c76f66a7d796c1

rainerzufall commented Sep 18, 2017

A log after I saw Signal Desktop (electron 1.0.25) being disconnected while it was not in focus for some time: https://gist.github.com/anonymous/64d2d5551bd08cd3f7c76f66a7d796c1

@GuardianMajor

This comment has been minimized.

Show comment
Hide comment
@GuardianMajor

GuardianMajor Sep 20, 2017

@scottnonnenberg This has been already provided but wanted to add this to it as I noticed that it happens when you initially start it and then after a while of running, it will do it again, I captured snippets of the log during the times they happen and it seems to confirm that the keep-alive is not completing right.

2017-09-20T16:04:38.269Z Sending a keepalive message
2017-09-20T16:05:12.921Z websocket closed 3001 No response to keepalive request
2017-09-20T16:05:12.921Z GET https://textsecure-service.whispersystems.org/v1/devices
2017-09-20T16:05:12.921Z MessageReceiver: emitting 'empty' event
2017-09-20T16:05:13.354Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
2017-09-20T16:05:13.354Z opening message socket https://textsecure-service.whispersystems.org
2017-09-20T16:05:13.371Z getAllFromCache
2017-09-20T16:05:13.371Z getAllFromCache loaded 0 saved envelopes
2017-09-20T16:05:13.787Z websocket open
2017-09-20T16:05:13.787Z got request PUT /api/v1/queue/empty
2017-09-20T16:05:13.787Z MessageReceiver: emitting 'empty' event
2017-09-20T16:06:08.803Z Sending a keepalive message
2017-09-20T16:07:03.903Z Sending a keepalive message
2017-09-20T16:07:59.020Z Sending a keepalive message
...n^Sending a keepalive message...
2017-09-20T20:00:08.069Z Sending a keepalive message
2017-09-20T20:01:03.187Z Sending a keepalive message
2017-09-20T20:01:58.304Z Sending a keepalive message
2017-09-20T20:03:09.070Z Sending a keepalive message
2017-09-20T20:03:43.172Z websocket closed 3001 No response to keepalive request
2017-09-20T20:03:43.188Z GET https://textsecure-service.whispersystems.org/v1/devices
2017-09-20T20:03:43.188Z MessageReceiver: emitting 'empty' event
2017-09-20T20:03:43.671Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
2017-09-20T20:03:43.671Z opening message socket https://textsecure-service.whispersystems.org
2017-09-20T20:03:43.671Z getAllFromCache
2017-09-20T20:03:43.671Z getAllFromCache loaded 0 saved envelopes
2017-09-20T20:03:44.088Z websocket open
2017-09-20T20:03:44.088Z got request PUT /api/v1/queue/empty
2017-09-20T20:03:44.104Z MessageReceiver: emitting 'empty' event

I have taken the repeated keep-alives out to condense the flow a bit.

GuardianMajor commented Sep 20, 2017

@scottnonnenberg This has been already provided but wanted to add this to it as I noticed that it happens when you initially start it and then after a while of running, it will do it again, I captured snippets of the log during the times they happen and it seems to confirm that the keep-alive is not completing right.

2017-09-20T16:04:38.269Z Sending a keepalive message
2017-09-20T16:05:12.921Z websocket closed 3001 No response to keepalive request
2017-09-20T16:05:12.921Z GET https://textsecure-service.whispersystems.org/v1/devices
2017-09-20T16:05:12.921Z MessageReceiver: emitting 'empty' event
2017-09-20T16:05:13.354Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
2017-09-20T16:05:13.354Z opening message socket https://textsecure-service.whispersystems.org
2017-09-20T16:05:13.371Z getAllFromCache
2017-09-20T16:05:13.371Z getAllFromCache loaded 0 saved envelopes
2017-09-20T16:05:13.787Z websocket open
2017-09-20T16:05:13.787Z got request PUT /api/v1/queue/empty
2017-09-20T16:05:13.787Z MessageReceiver: emitting 'empty' event
2017-09-20T16:06:08.803Z Sending a keepalive message
2017-09-20T16:07:03.903Z Sending a keepalive message
2017-09-20T16:07:59.020Z Sending a keepalive message
...n^Sending a keepalive message...
2017-09-20T20:00:08.069Z Sending a keepalive message
2017-09-20T20:01:03.187Z Sending a keepalive message
2017-09-20T20:01:58.304Z Sending a keepalive message
2017-09-20T20:03:09.070Z Sending a keepalive message
2017-09-20T20:03:43.172Z websocket closed 3001 No response to keepalive request
2017-09-20T20:03:43.188Z GET https://textsecure-service.whispersystems.org/v1/devices
2017-09-20T20:03:43.188Z MessageReceiver: emitting 'empty' event
2017-09-20T20:03:43.671Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
2017-09-20T20:03:43.671Z opening message socket https://textsecure-service.whispersystems.org
2017-09-20T20:03:43.671Z getAllFromCache
2017-09-20T20:03:43.671Z getAllFromCache loaded 0 saved envelopes
2017-09-20T20:03:44.088Z websocket open
2017-09-20T20:03:44.088Z got request PUT /api/v1/queue/empty
2017-09-20T20:03:44.104Z MessageReceiver: emitting 'empty' event

I have taken the repeated keep-alives out to condense the flow a bit.

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Sep 20, 2017

Contributor

@GuardianMajor Thanks for that. I notice that those are two really quick blips. Maybe a second offline at most.

We've uncovered a much more insidious problem which repros for me consistently on Linux, where the app remains offline until you make the app hit the internet for some reason - load a conversation (and therefore a user profile), verify someone's contact number. As you can imagine, we're really interested in ensuring that incoming messages are received even when the app is in the background.

Anyone experiencing a lack of message alerts, or the app showing 'Connecting' for a long time in the top left, please send me your logs. I can get it to happen on Linux if the app is idle in the background, and legitimately loses the websocket connection - when it tries to reconnect, that process seems to hang.

Contributor

scottnonnenberg commented Sep 20, 2017

@GuardianMajor Thanks for that. I notice that those are two really quick blips. Maybe a second offline at most.

We've uncovered a much more insidious problem which repros for me consistently on Linux, where the app remains offline until you make the app hit the internet for some reason - load a conversation (and therefore a user profile), verify someone's contact number. As you can imagine, we're really interested in ensuring that incoming messages are received even when the app is in the background.

Anyone experiencing a lack of message alerts, or the app showing 'Connecting' for a long time in the top left, please send me your logs. I can get it to happen on Linux if the app is idle in the background, and legitimately loses the websocket connection - when it tries to reconnect, that process seems to hang.

@GuardianMajor

This comment has been minimized.

Show comment
Hide comment
@GuardianMajor

GuardianMajor Sep 21, 2017

Actually they are far more frequent, like this morning for example but I just didn't want to send a huge roll that ties up the thread, that's all. If you wish to have the "longer" full on logs, by all means I can send those to you but despite being redacted, I don't particularly feel comfortable for them to be posted publicly.

You have my email, I'd be happy to send the whole kit and caboodle to you if you wish, just shoot me a message if you think they will help. Thanks.

PS. I am experiencing on Windows the condition you described on Linux, especially this morning. The persistent message despite me sending and receiving messages, which confuses the heck out of me as to how it can send/receive but yet have this persistent message about it being disconnected. I am hoping that's somehow a GUI bug rather than a network issue, but when I check the log you have the errors I posted before showing clearly something is triggering that message.

GuardianMajor commented Sep 21, 2017

Actually they are far more frequent, like this morning for example but I just didn't want to send a huge roll that ties up the thread, that's all. If you wish to have the "longer" full on logs, by all means I can send those to you but despite being redacted, I don't particularly feel comfortable for them to be posted publicly.

You have my email, I'd be happy to send the whole kit and caboodle to you if you wish, just shoot me a message if you think they will help. Thanks.

PS. I am experiencing on Windows the condition you described on Linux, especially this morning. The persistent message despite me sending and receiving messages, which confuses the heck out of me as to how it can send/receive but yet have this persistent message about it being disconnected. I am hoping that's somehow a GUI bug rather than a network issue, but when I check the log you have the errors I posted before showing clearly something is triggering that message.

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Sep 21, 2017

Contributor

@GuardianMajor Ah, I'll go do some testing on Windows, see what I see there.

In the meantime, please contact support@whispersystems.org to get that whole log to us. It does sounds like you're dealing with a slightly different behavior from Linux. On Linux, when you see that 'Connecting' state stick around, you actually cannot receive messages. It sounds like you have a different issue, where you are indeed connected but the message in the top-left claims otherwise.

When you say 'far more frequent' can you talk about what that was really like? Maybe go through a timeline for us - what you were doing, what you say, about how long things stuck around, etc. Any errors or weirdnesses you saw. That will pair well with your log, so perhaps send that to the support email address as well. Thanks!

Contributor

scottnonnenberg commented Sep 21, 2017

@GuardianMajor Ah, I'll go do some testing on Windows, see what I see there.

In the meantime, please contact support@whispersystems.org to get that whole log to us. It does sounds like you're dealing with a slightly different behavior from Linux. On Linux, when you see that 'Connecting' state stick around, you actually cannot receive messages. It sounds like you have a different issue, where you are indeed connected but the message in the top-left claims otherwise.

When you say 'far more frequent' can you talk about what that was really like? Maybe go through a timeline for us - what you were doing, what you say, about how long things stuck around, etc. Any errors or weirdnesses you saw. That will pair well with your log, so perhaps send that to the support email address as well. Thanks!

@GuardianMajor

This comment has been minimized.

Show comment
Hide comment
@GuardianMajor

GuardianMajor Sep 21, 2017

@scottnonnenberg My apologies I wasn't more clear. What I mean is that before it would be initially (within a minute or less) and then here and there, sometimes a few minutes, sometimes an hour before it would happen again, but this morning it was triggering literally every 30-120 seconds which I found quite odd. Specially that as I said, it seemed at least that I was able to send and receive just fine, which honestly I don't how or why - but I will send the full log to you via email. I was doing nothing different than I do every morning, Outlook 2016 open (in the tray) for email, Firefox open with a few tabs at most and that's about it. I usually don't have a lot of apps open until mid to later in the day where it could be anything from Photoshop CS6, Illustrator, Word 2016, Excel, OneNote, PushBullet, Line, Edge, Chrome, Visual Studio 2017, Acrobat Pro XI and so on, on top of what I normally have in the morning - of course not all at the same time usually but it could be 3-4 of them at the same time at times. Does that help?

I made a point of closing it out and then opening it fresh and leaving it open all day to get as much log and behavioral data to you as possible. The only "annoyance" if any is that it will tie up my task bar all day long which will certainly be disruptive given how many thing I have open and working on at any given time. Because of the inability to make it go away and remain tidy, I have had to resort to the odd behavior of waiting for a "ding" on my phone to open up the app on the desktop and handle the conversation and then close it out. But for the sake of providing as much useful information as I can, I will open and keep it open all day so I can get you all the logs.

Let me know if anything else I can provide to help you out. By the way, not that it should really matter given most people are on broadband anyway, but I am on a T3 line with multiple OC3 backbones, so my bandwidth is VERY high and my network speed is nearly instant. Also, you already know but just in case, I am on Windows 10 Pro x64 (1703) if it helps. 250 GB SSD internal, 2 x 1TB AS, 4 TB NAS, 16 GB RAM, Dual 1080 Monitors and full disk encryption. I don't think any of that will help you but just for full disclosure.

GuardianMajor commented Sep 21, 2017

@scottnonnenberg My apologies I wasn't more clear. What I mean is that before it would be initially (within a minute or less) and then here and there, sometimes a few minutes, sometimes an hour before it would happen again, but this morning it was triggering literally every 30-120 seconds which I found quite odd. Specially that as I said, it seemed at least that I was able to send and receive just fine, which honestly I don't how or why - but I will send the full log to you via email. I was doing nothing different than I do every morning, Outlook 2016 open (in the tray) for email, Firefox open with a few tabs at most and that's about it. I usually don't have a lot of apps open until mid to later in the day where it could be anything from Photoshop CS6, Illustrator, Word 2016, Excel, OneNote, PushBullet, Line, Edge, Chrome, Visual Studio 2017, Acrobat Pro XI and so on, on top of what I normally have in the morning - of course not all at the same time usually but it could be 3-4 of them at the same time at times. Does that help?

I made a point of closing it out and then opening it fresh and leaving it open all day to get as much log and behavioral data to you as possible. The only "annoyance" if any is that it will tie up my task bar all day long which will certainly be disruptive given how many thing I have open and working on at any given time. Because of the inability to make it go away and remain tidy, I have had to resort to the odd behavior of waiting for a "ding" on my phone to open up the app on the desktop and handle the conversation and then close it out. But for the sake of providing as much useful information as I can, I will open and keep it open all day so I can get you all the logs.

Let me know if anything else I can provide to help you out. By the way, not that it should really matter given most people are on broadband anyway, but I am on a T3 line with multiple OC3 backbones, so my bandwidth is VERY high and my network speed is nearly instant. Also, you already know but just in case, I am on Windows 10 Pro x64 (1703) if it helps. 250 GB SSD internal, 2 x 1TB AS, 4 TB NAS, 16 GB RAM, Dual 1080 Monitors and full disk encryption. I don't think any of that will help you but just for full disclosure.

@deutrino

This comment has been minimized.

Show comment
Hide comment
@deutrino

deutrino Sep 21, 2017

I'm seeing similar issues on Linux where the top left says "disconnected" (not "connecting") and yet I can send messages okay - I don't think I receive them in that state, at least often I don't but I haven't really sat down to try to elucidate the behavior yet. And when I send a message usually the "disconnected" state will clear within a few seconds, though it may come back fairly quickly sometimes.

I'll try to get log snippets and poke at it some to characterize the behavior better, but for me it's quite random, sometimes happens a lot, sometimes not for an entire day.

deutrino commented Sep 21, 2017

I'm seeing similar issues on Linux where the top left says "disconnected" (not "connecting") and yet I can send messages okay - I don't think I receive them in that state, at least often I don't but I haven't really sat down to try to elucidate the behavior yet. And when I send a message usually the "disconnected" state will clear within a few seconds, though it may come back fairly quickly sometimes.

I'll try to get log snippets and poke at it some to characterize the behavior better, but for me it's quite random, sometimes happens a lot, sometimes not for an entire day.

@ivan

This comment has been minimized.

Show comment
Hide comment
@ivan

ivan Sep 22, 2017

I experienced a "Connecting" / "websocket closed 1006" loop because I copied my Chrome profile and was trying to simultaneously use the same paired Signal-Desktop on two computers.

ivan commented Sep 22, 2017

I experienced a "Connecting" / "websocket closed 1006" loop because I copied my Chrome profile and was trying to simultaneously use the same paired Signal-Desktop on two computers.

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Sep 22, 2017

Contributor

@ivan Ah, very interesting. Thanks for that additional datapoint.

Electron users: v1.0.26 was just released, and should address those extended periods of 'disconnected' or 'connecting' states on Linux. Please let us know what you see when you upgrade!

Contributor

scottnonnenberg commented Sep 22, 2017

@ivan Ah, very interesting. Thanks for that additional datapoint.

Electron users: v1.0.26 was just released, and should address those extended periods of 'disconnected' or 'connecting' states on Linux. Please let us know what you see when you upgrade!

@GuardianMajor

This comment has been minimized.

Show comment
Hide comment
@GuardianMajor

GuardianMajor Sep 23, 2017

@scottnonnenberg I will try .26 and check to make sure but in the meantime I spent the whole day leaving it open for the observation I promised you and noticed something both interesting and utterly confusing.

Since I opened it to test it and wasn't immediately writing anyone, when I opened it, just sat on the "Welcome to Signal" screen and for HOURS it never ever once gave the disconnected message and I checked it in the log and every keepalive and whatnot worked fine.

However, the moment I clicked on a user who sent me a message to reply, within 30 seconds of it, BAM there it was and the log showed an error for the keepalive and while the conversation was active, for about 30 minutes, off and on each 30-90 seconds it would pop up but one thing I noticed as a pattern, it does this immediately AFTER sending a message, and BEFORE it gets a message from someone.

So it seems this is somehow tied to how the messages are being transmitted/checked. It seems when it checks for new messages, and there is one, on the client end it will throw an error on the socket and then when it goes away, which it does usually about 30 seconds after the notice pops up, then the message arrives, and then you send a reply, immediately after it will throw the message and the error and then about 30 seconds later it resolves. I can see this with absolute consistency.

But leave it open on the main page or even a conversation page and as long as no activity is coming/going it will sit there happily and successfully sending keepalives until the cows come home. Hope this helps, but as I said, I will give it another full day treatment with the new .26 and see how it goes.

EDIT: Speak of the devil, using the .26 just had to use it to converse with someone and it is back to its old tricks, so didn't resolve this particular issue :( Will still do a full test tomorrow morning.

EDIT 2: Just for the record, I am NOT doing what ivan is doing and have only ONE connection between my phone and electron client and nothing else. As you remember, I scrapped the backing up of it and started fresh, so I have no multiple devices setup, in case it helps.

GuardianMajor commented Sep 23, 2017

@scottnonnenberg I will try .26 and check to make sure but in the meantime I spent the whole day leaving it open for the observation I promised you and noticed something both interesting and utterly confusing.

Since I opened it to test it and wasn't immediately writing anyone, when I opened it, just sat on the "Welcome to Signal" screen and for HOURS it never ever once gave the disconnected message and I checked it in the log and every keepalive and whatnot worked fine.

However, the moment I clicked on a user who sent me a message to reply, within 30 seconds of it, BAM there it was and the log showed an error for the keepalive and while the conversation was active, for about 30 minutes, off and on each 30-90 seconds it would pop up but one thing I noticed as a pattern, it does this immediately AFTER sending a message, and BEFORE it gets a message from someone.

So it seems this is somehow tied to how the messages are being transmitted/checked. It seems when it checks for new messages, and there is one, on the client end it will throw an error on the socket and then when it goes away, which it does usually about 30 seconds after the notice pops up, then the message arrives, and then you send a reply, immediately after it will throw the message and the error and then about 30 seconds later it resolves. I can see this with absolute consistency.

But leave it open on the main page or even a conversation page and as long as no activity is coming/going it will sit there happily and successfully sending keepalives until the cows come home. Hope this helps, but as I said, I will give it another full day treatment with the new .26 and see how it goes.

EDIT: Speak of the devil, using the .26 just had to use it to converse with someone and it is back to its old tricks, so didn't resolve this particular issue :( Will still do a full test tomorrow morning.

EDIT 2: Just for the record, I am NOT doing what ivan is doing and have only ONE connection between my phone and electron client and nothing else. As you remember, I scrapped the backing up of it and started fresh, so I have no multiple devices setup, in case it helps.

@deutrino

This comment has been minimized.

Show comment
Hide comment
@deutrino

deutrino Sep 25, 2017

The problems I'm experiencing have gotten worse with 1.0.26 (I'm on Linux Mint). Now much of the time when the client is in a "disconnected" state, I can't get it to "reconnect" by, for example, sending a message to someone.

Before 1.0.26, often when I would send a message, it would clear the spurious disconnected state. Now, when in such a state, I can send a message (and get a single checkmark!), but Signal does not "reconnect" after I do so. (I put scare quotes on "reconnect" because given that I'm getting a single checkmark, I'm not sure it's actually fully disconnected. I haven't yet characterized whether I can see those sent messages on my phone, though.)

So far I haven't been able to get a log where I saw the "disconnected" state appear. I've just found it that way after some time not paying attention. I'll get the log when I can. But 1.0.26 is behaving differently for me.

deutrino commented Sep 25, 2017

The problems I'm experiencing have gotten worse with 1.0.26 (I'm on Linux Mint). Now much of the time when the client is in a "disconnected" state, I can't get it to "reconnect" by, for example, sending a message to someone.

Before 1.0.26, often when I would send a message, it would clear the spurious disconnected state. Now, when in such a state, I can send a message (and get a single checkmark!), but Signal does not "reconnect" after I do so. (I put scare quotes on "reconnect" because given that I'm getting a single checkmark, I'm not sure it's actually fully disconnected. I haven't yet characterized whether I can see those sent messages on my phone, though.)

So far I haven't been able to get a log where I saw the "disconnected" state appear. I've just found it that way after some time not paying attention. I'll get the log when I can. But 1.0.26 is behaving differently for me.

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Sep 25, 2017

Contributor

Well, as they say, at least we're getting a different result!

First, a single checkmark still means that the server has accepted the message. The double-checkmark just means that the target client has downloaded the message. It has nothing to do with your own connectivity.

When you find yourself in this claimed 'disconnected' state, one way to test is to send a message from your phone. You should see this message show up in Desktop if you're connected to the websocket. So perhaps now we're dealing with an incorrect 'disconnected' notification in the top-left?

Contributor

scottnonnenberg commented Sep 25, 2017

Well, as they say, at least we're getting a different result!

First, a single checkmark still means that the server has accepted the message. The double-checkmark just means that the target client has downloaded the message. It has nothing to do with your own connectivity.

When you find yourself in this claimed 'disconnected' state, one way to test is to send a message from your phone. You should see this message show up in Desktop if you're connected to the websocket. So perhaps now we're dealing with an incorrect 'disconnected' notification in the top-left?

@deutrino

This comment has been minimized.

Show comment
Hide comment
@deutrino

deutrino Sep 26, 2017

I found the desktop client in the "disconnected" state today, sent a message from my phone, and the desktop client cleared its "disconnected" status almost immediately and then displayed the message about 2 seconds later.

My desktop debug log is miles long so I included what I felt was the relevant snippet. I sent a picture message from the desktop client to the same person I'd tested sending the phone message to, after the client reconnected, FWIW. https://gist.github.com/deutrino/5fdc829a72a672db99993c96715934c1

Edit: This is weird, it looks like the timeout on desktop might not have been written to the debug log until I'd sent the message from my phone?

2017-09-26T20:25:40.034Z Sending a keepalive message
2017-09-26T20:42:31.381Z websocket closed 1006 Socket Error: read ETIMEDOUT

deutrino commented Sep 26, 2017

I found the desktop client in the "disconnected" state today, sent a message from my phone, and the desktop client cleared its "disconnected" status almost immediately and then displayed the message about 2 seconds later.

My desktop debug log is miles long so I included what I felt was the relevant snippet. I sent a picture message from the desktop client to the same person I'd tested sending the phone message to, after the client reconnected, FWIW. https://gist.github.com/deutrino/5fdc829a72a672db99993c96715934c1

Edit: This is weird, it looks like the timeout on desktop might not have been written to the debug log until I'd sent the message from my phone?

2017-09-26T20:25:40.034Z Sending a keepalive message
2017-09-26T20:42:31.381Z websocket closed 1006 Socket Error: read ETIMEDOUT
@liliakai

This comment has been minimized.

Show comment
Hide comment
@liliakai

liliakai Sep 28, 2017

Contributor

@deutrino It helps to include the first line of the log which includes info about your installed version, and OS...

Contributor

liliakai commented Sep 28, 2017

@deutrino It helps to include the first line of the log which includes info about your installed version, and OS...

@deutrino

This comment has been minimized.

Show comment
Hide comment
@deutrino

deutrino Sep 28, 2017

Whoops. I edited the gist and put it back in.

deutrino commented Sep 28, 2017

Whoops. I edited the gist and put it back in.

@janvlug

This comment has been minimized.

Show comment
Hide comment
@janvlug

janvlug Oct 1, 2017

This is a debug log while Signal Desktop is disconnected. I sent a message to a contact who I had not been messaging for a long time. On my phone I noticed that this person had sent a message back, but due to the disconnected state it is not in the Desktop (yet?).
https://gist.github.com/anonymous/3b4c62180dda6339c5f97070db0340f0
Currently Signal Desktop is still disconnected. I will post another debug log when it is connected again.

janvlug commented Oct 1, 2017

This is a debug log while Signal Desktop is disconnected. I sent a message to a contact who I had not been messaging for a long time. On my phone I noticed that this person had sent a message back, but due to the disconnected state it is not in the Desktop (yet?).
https://gist.github.com/anonymous/3b4c62180dda6339c5f97070db0340f0
Currently Signal Desktop is still disconnected. I will post another debug log when it is connected again.

@janvlug

This comment has been minimized.

Show comment
Hide comment
@janvlug

janvlug Oct 1, 2017

Interestingly: I sent a message with Signal Desktop to a group in an attempt to get it re-connected. The GUI states still that Signal Desktop is disconnected. But the message did show up in the group on my Android phone. However, there is only one tick next to the message (but maybe this is because other members did not receive it).
Here is the debug log from Signal Android (in case that might be useful):
https://gist.github.com/anonymous/83f5a9d07955fd8a81bdaa9bf160a64e

While writing this comment, Signal Desktop established its connection again. Here is the debug log now Signal Desktop is connected again:
https://gist.github.com/anonymous/003492693d302eed0b0c4ea662b3a6ca
Did Signal Desktop do a contact sync while it stated that is was disconnected?

janvlug commented Oct 1, 2017

Interestingly: I sent a message with Signal Desktop to a group in an attempt to get it re-connected. The GUI states still that Signal Desktop is disconnected. But the message did show up in the group on my Android phone. However, there is only one tick next to the message (but maybe this is because other members did not receive it).
Here is the debug log from Signal Android (in case that might be useful):
https://gist.github.com/anonymous/83f5a9d07955fd8a81bdaa9bf160a64e

While writing this comment, Signal Desktop established its connection again. Here is the debug log now Signal Desktop is connected again:
https://gist.github.com/anonymous/003492693d302eed0b0c4ea662b3a6ca
Did Signal Desktop do a contact sync while it stated that is was disconnected?

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Oct 2, 2017

Contributor

@janvlug Thanks for the logs. Your behavior seems to be related to one very long failed request to our servers (starting here):

2017-10-01T07:51:08.336Z GET https://textsecure-service-ca.whispersystems.org:80/v1/devices
...
2017-10-01T08:07:58.880Z GET https://textsecure-service-ca.whispersystems.org:80/v1/devices 0 Error

Whenever the socket closes unexpectedly, we first check for general internet connectivity by making a request to /v1/devices. If that succeeds, then we try to reconnect immediately. But because that request took over 15 minutes to return an error, we were offline for that long.

I'm going to look into a timeout for all web requests to prevent this kind of extreme event.

Contributor

scottnonnenberg commented Oct 2, 2017

@janvlug Thanks for the logs. Your behavior seems to be related to one very long failed request to our servers (starting here):

2017-10-01T07:51:08.336Z GET https://textsecure-service-ca.whispersystems.org:80/v1/devices
...
2017-10-01T08:07:58.880Z GET https://textsecure-service-ca.whispersystems.org:80/v1/devices 0 Error

Whenever the socket closes unexpectedly, we first check for general internet connectivity by making a request to /v1/devices. If that succeeds, then we try to reconnect immediately. But because that request took over 15 minutes to return an error, we were offline for that long.

I'm going to look into a timeout for all web requests to prevent this kind of extreme event.

@janvlug

This comment has been minimized.

Show comment
Hide comment
@janvlug

janvlug Oct 21, 2017

Another log of disconnected Signal desktop. At the moment of taking the log, Signal desktop was still disconnected:
https://gist.github.com/anonymous/8ffd9bf797edeeebee37cdcc4555321a

janvlug commented Oct 21, 2017

Another log of disconnected Signal desktop. At the moment of taking the log, Signal desktop was still disconnected:
https://gist.github.com/anonymous/8ffd9bf797edeeebee37cdcc4555321a

@janvlug

This comment has been minimized.

Show comment
Hide comment
@janvlug

janvlug Oct 21, 2017

See attached log.
==== Signal Desktop is still disconnected
==== Before here I received a message on my phone via Signal Android.
==== The messaged did not appear on Signal Desktop
==== I answered the contact via Signal Desktop in the hope that this would revive the connection
==== I see a single checkmark next to the message that I sent in Signal Desktop
==== Interestingly enough, the message also appears in Signal Android, where it has a double checkmark.

janvlug commented Oct 21, 2017

See attached log.
==== Signal Desktop is still disconnected
==== Before here I received a message on my phone via Signal Android.
==== The messaged did not appear on Signal Desktop
==== I answered the contact via Signal Desktop in the hope that this would revive the connection
==== I see a single checkmark next to the message that I sent in Signal Desktop
==== Interestingly enough, the message also appears in Signal Android, where it has a double checkmark.

@janvlug

This comment has been minimized.

Show comment
Hide comment
@janvlug

This comment has been minimized.

Show comment
Hide comment
@janvlug

janvlug commented Oct 21, 2017

Corresponding log on Signal Android:
https://gist.github.com/8e4e7d1d601a94101df436698d1a3b27

@janvlug

This comment has been minimized.

Show comment
Hide comment
@janvlug

janvlug commented Oct 21, 2017

And the log after that I restarted Signal Desktop:
https://gist.github.com/anonymous/8a9b7cf3940b918674b0369822722bf7

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Oct 23, 2017

Contributor

@janvlug Again, the issue appears to be with very long /devices requests. v1.0.32 introduces timeouts which will prevent that kind of thing going forward.

Contributor

scottnonnenberg commented Oct 23, 2017

@janvlug Again, the issue appears to be with very long /devices requests. v1.0.32 introduces timeouts which will prevent that kind of thing going forward.

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Nov 3, 2017

Contributor

Well everyone, how's it going? The latest versions of Signal Desktop Standalone should address all of these lingering disconnected states. Lemme know.

Contributor

scottnonnenberg commented Nov 3, 2017

Well everyone, how's it going? The latest versions of Signal Desktop Standalone should address all of these lingering disconnected states. Lemme know.

@deutrino

This comment has been minimized.

Show comment
Hide comment
@deutrino

deutrino Nov 3, 2017

I haven't been watching quite as closely but I also have noticed almost zero time sitting in a "disconnected" state lately.

deutrino commented Nov 3, 2017

I haven't been watching quite as closely but I also have noticed almost zero time sitting in a "disconnected" state lately.

@BidiM

This comment has been minimized.

Show comment
Hide comment
@BidiM

BidiM Nov 3, 2017

I'm getting 'disconnected' on desktop app (Windows) after migrating from Chrome app. This is on a work PC so ports will be limited. Is Chrome app Signal using different ports than Desktop app?

BidiM commented Nov 3, 2017

I'm getting 'disconnected' on desktop app (Windows) after migrating from Chrome app. This is on a work PC so ports will be limited. Is Chrome app Signal using different ports than Desktop app?

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Nov 3, 2017

Contributor

@BidiM I have a suspicion that your issue is different; related to proxies and port availability. The new standalone app no longer tries multiple ports. Everything goes across port 443 like normal encrypted traffic. If you provide logs we can verify that.

Contributor

scottnonnenberg commented Nov 3, 2017

@BidiM I have a suspicion that your issue is different; related to proxies and port availability. The new standalone app no longer tries multiple ports. Everything goes across port 443 like normal encrypted traffic. If you provide logs we can verify that.

@BidiM

This comment has been minimized.

Show comment
Hide comment
@BidiM

BidiM Nov 3, 2017

AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:39529:25)","reason":"Failed to create or send message"}]}
INFO 2017-11-03T16:31:44.232Z websocket error
INFO 2017-11-03T16:31:44.232Z websocket closed 1006 connection failed calledClose:
INFO 2017-11-03T16:31:44.233Z GET https://textsecure-service.whispersystems.org/v1/devices

BidiM commented Nov 3, 2017

AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:39529:25)","reason":"Failed to create or send message"}]}
INFO 2017-11-03T16:31:44.232Z websocket error
INFO 2017-11-03T16:31:44.232Z websocket closed 1006 connection failed calledClose:
INFO 2017-11-03T16:31:44.233Z GET https://textsecure-service.whispersystems.org/v1/devices

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Nov 3, 2017

Contributor

@BidiM Thanks, but that's not quite enough. :0)

Contributor

scottnonnenberg commented Nov 3, 2017

@BidiM Thanks, but that's not quite enough. :0)

@BidiM

This comment has been minimized.

Show comment
Hide comment
@BidiM

BidiM Nov 3, 2017

@scottnonnenberg
I see this loop over and over

INFO  2017-11-03T15:53:40.102Z retrying in 1 minute
INFO  2017-11-03T15:54:40.116Z connect
INFO  2017-11-03T15:54:40.125Z MessageReceiver.close()
INFO  2017-11-03T15:54:40.125Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-03T15:54:40.128Z drained
INFO  2017-11-03T15:54:40.173Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004
INFO  2017-11-03T15:54:45.175Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004 0 Error
INFO  2017-11-03T15:54:45.175Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004","type":"request-timeout"}
INFO  2017-11-03T15:54:46.176Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004
INFO  2017-11-03T15:54:51.182Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004 0 Error
INFO  2017-11-03T15:54:51.183Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004","type":"request-timeout"}
INFO  2017-11-03T15:54:52.187Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004
INFO  2017-11-03T15:54:57.195Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004 0 Error
INFO  2017-11-03T15:54:57.195Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004","type":"request-timeout"}
INFO  2017-11-03T15:54:57.196Z {"successfulNumbers":[],"errors":[{"name":"SendMessageNetworkError","functionCode":3,"args":["+[REDACTED]004",[{"type":1,"destinationDeviceId":1,"destinationRegistrationId":16257,"content":"[REDACTED]"},{"type":1,"destinationDeviceId":3,"destinationRegistrationId":11254,"content":"[REDACTED]"}],1509724480114],"number":"+[REDACTED]004","code":-1,"message":"Failed to connect to the server, please check your network connection.","stack":"Error\n    at ajax (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37557:25)\n    at TextSecureServer.ajax (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37601:20)\n    at TextSecureServer.sendMessages (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37805:25)\n    at OutgoingMessage.transmitMessage (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:39466:28)\n    at OutgoingMessage.<anonymous> (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:39529:25)","reason":"Failed to create or send message"}]}
INFO  2017-11-03T15:55:01.179Z websocket error
INFO  2017-11-03T15:55:01.179Z websocket closed 1006 connection failed calledClose: 
INFO  2017-11-03T15:55:01.179Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-03T15:55:06.186Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2017-11-03T15:55:06.187Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/devices","type":"request-timeout"}
INFO  2017-11-03T15:55:07.190Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-03T15:55:12.196Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2017-11-03T15:55:12.197Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/devices","type":"request-timeout"}
INFO  2017-11-03T15:55:13.200Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-03T15:55:18.205Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2017-11-03T15:55:18.206Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/devices","type":"request-timeout"}
INFO  2017-11-03T15:55:18.206Z {"name":"HTTPError","code":-1,"response":"FetchError: network timeout at: https://textsecure-service.whispersystems.org/v1/devices","message":"Failed to connect to the server, please check your network connection."}
INFO  2017-11-03T15:55:18.207Z Error
    at ajax (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37557:25)
    at TextSecureServer.ajax (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37601:20)
    at TextSecureServer.getDevices (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37711:25)
    at MessageReceiver.onclose (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:38523:28)
    at W3CWebSocket._dispatchEvent [as dispatchEvent] (C:\Users\user\AppData\Local\Programs\signal-desktop\resources\app.asar\node_modules\yaeti\lib\EventTarget.js:107:17)
    at W3CWebSocket.onConnectFailed (C:\Users\user\AppData\Local\Programs\signal-desktop\resources\app.asar\node_modules\websocket\lib\W3CWebSocket.js:219:14)
    at WebSocketClient.<anonymous> (C:\Users\user\AppData\Local\Programs\signal-desktop\resources\app.asar\node_modules\websocket\lib\W3CWebSocket.js:59:25)
    at emitOne (events.js:96:13)
    at WebSocketClient.emit (events.js:188:7)
    at ClientRequest.handleRequestError (C:\Users\user\AppData\Local\Programs\signal-desktop\resources\app.asar\node_modules\websocket\lib\WebSocketClient.js:215:14)
INFO  2017-11-03T15:55:18.207Z retrying in 1 minute

BidiM commented Nov 3, 2017

@scottnonnenberg
I see this loop over and over

INFO  2017-11-03T15:53:40.102Z retrying in 1 minute
INFO  2017-11-03T15:54:40.116Z connect
INFO  2017-11-03T15:54:40.125Z MessageReceiver.close()
INFO  2017-11-03T15:54:40.125Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-03T15:54:40.128Z drained
INFO  2017-11-03T15:54:40.173Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004
INFO  2017-11-03T15:54:45.175Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004 0 Error
INFO  2017-11-03T15:54:45.175Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004","type":"request-timeout"}
INFO  2017-11-03T15:54:46.176Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004
INFO  2017-11-03T15:54:51.182Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004 0 Error
INFO  2017-11-03T15:54:51.183Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004","type":"request-timeout"}
INFO  2017-11-03T15:54:52.187Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004
INFO  2017-11-03T15:54:57.195Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004 0 Error
INFO  2017-11-03T15:54:57.195Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]004","type":"request-timeout"}
INFO  2017-11-03T15:54:57.196Z {"successfulNumbers":[],"errors":[{"name":"SendMessageNetworkError","functionCode":3,"args":["+[REDACTED]004",[{"type":1,"destinationDeviceId":1,"destinationRegistrationId":16257,"content":"[REDACTED]"},{"type":1,"destinationDeviceId":3,"destinationRegistrationId":11254,"content":"[REDACTED]"}],1509724480114],"number":"+[REDACTED]004","code":-1,"message":"Failed to connect to the server, please check your network connection.","stack":"Error\n    at ajax (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37557:25)\n    at TextSecureServer.ajax (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37601:20)\n    at TextSecureServer.sendMessages (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37805:25)\n    at OutgoingMessage.transmitMessage (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:39466:28)\n    at OutgoingMessage.<anonymous> (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:39529:25)","reason":"Failed to create or send message"}]}
INFO  2017-11-03T15:55:01.179Z websocket error
INFO  2017-11-03T15:55:01.179Z websocket closed 1006 connection failed calledClose: 
INFO  2017-11-03T15:55:01.179Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-03T15:55:06.186Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2017-11-03T15:55:06.187Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/devices","type":"request-timeout"}
INFO  2017-11-03T15:55:07.190Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-03T15:55:12.196Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2017-11-03T15:55:12.197Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/devices","type":"request-timeout"}
INFO  2017-11-03T15:55:13.200Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-03T15:55:18.205Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2017-11-03T15:55:18.206Z {"name":"FetchError","message":"network timeout at: https://textsecure-service.whispersystems.org/v1/devices","type":"request-timeout"}
INFO  2017-11-03T15:55:18.206Z {"name":"HTTPError","code":-1,"response":"FetchError: network timeout at: https://textsecure-service.whispersystems.org/v1/devices","message":"Failed to connect to the server, please check your network connection."}
INFO  2017-11-03T15:55:18.207Z Error
    at ajax (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37557:25)
    at TextSecureServer.ajax (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37601:20)
    at TextSecureServer.getDevices (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37711:25)
    at MessageReceiver.onclose (file:///C:/Users/user/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:38523:28)
    at W3CWebSocket._dispatchEvent [as dispatchEvent] (C:\Users\user\AppData\Local\Programs\signal-desktop\resources\app.asar\node_modules\yaeti\lib\EventTarget.js:107:17)
    at W3CWebSocket.onConnectFailed (C:\Users\user\AppData\Local\Programs\signal-desktop\resources\app.asar\node_modules\websocket\lib\W3CWebSocket.js:219:14)
    at WebSocketClient.<anonymous> (C:\Users\user\AppData\Local\Programs\signal-desktop\resources\app.asar\node_modules\websocket\lib\W3CWebSocket.js:59:25)
    at emitOne (events.js:96:13)
    at WebSocketClient.emit (events.js:188:7)
    at ClientRequest.handleRequestError (C:\Users\user\AppData\Local\Programs\signal-desktop\resources\app.asar\node_modules\websocket\lib\WebSocketClient.js:215:14)
INFO  2017-11-03T15:55:18.207Z retrying in 1 minute
@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Nov 3, 2017

Contributor

@BidiM It looks like you can't connect to our servers at all. What happens when you try to go to https://textsecure-service.whispersystems.org/ in your browser? How long does it take to show up? (BTW, it should show a certificate error)

Contributor

scottnonnenberg commented Nov 3, 2017

@BidiM It looks like you can't connect to our servers at all. What happens when you try to go to https://textsecure-service.whispersystems.org/ in your browser? How long does it take to show up? (BTW, it should show a certificate error)

@BidiM

This comment has been minimized.

Show comment
Hide comment
@BidiM

BidiM Nov 13, 2017

I'm getting NET::ERR_CERT_AUTHORITY_INVALID
And that certificate is not trusted etc. But I can continue if i want so it seems I can connect to the server. Unfortunately, signal desktop app is still not working.

BidiM commented Nov 13, 2017

I'm getting NET::ERR_CERT_AUTHORITY_INVALID
And that certificate is not trusted etc. But I can continue if i want so it seems I can connect to the server. Unfortunately, signal desktop app is still not working.

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Nov 13, 2017

Contributor

@BidiM Did you notice how long it took for your browser requests to go through? It looks like the version you had problems with still had 5s timeout; the latest versions have a 10s timeout, so that may help.

Contributor

scottnonnenberg commented Nov 13, 2017

@BidiM Did you notice how long it took for your browser requests to go through? It looks like the version you had problems with still had 5s timeout; the latest versions have a 10s timeout, so that may help.

@BidiM

This comment has been minimized.

Show comment
Hide comment
@BidiM

BidiM Nov 14, 2017

@scottnonnenberg
v1.0.37 desktop app same. Tells me is disconnected.
Chrome app also stopped working.

BidiM commented Nov 14, 2017

@scottnonnenberg
v1.0.37 desktop app same. Tells me is disconnected.
Chrome app also stopped working.

@scottnonnenberg

This comment has been minimized.

Show comment
Hide comment
@scottnonnenberg

scottnonnenberg Nov 14, 2017

Contributor

@BidiM Tell me more about how the Chrome App stopped working. A log from that app would be useful, as well as a log from that latest v1.0.37 build.

Contributor

scottnonnenberg commented Nov 14, 2017

@BidiM Tell me more about how the Chrome App stopped working. A log from that app would be useful, as well as a log from that latest v1.0.37 build.

@scottnonnenberg scottnonnenberg added this to On hold in Next steps Nov 16, 2017

@scottnonnenberg scottnonnenberg moved this from On hold to Waiting in Next steps Nov 16, 2017

@roock

This comment has been minimized.

Show comment
Hide comment
@roock

roock Nov 18, 2017

Same/Similar Issue here. Signal Electron Standalone App v1.0.38

Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_1) AppleWebKit/537.36 (KHTML, like Gecko) Signal/1.0.38 Chrome/56.0.2924.87 Electron/1.6.15 Safari/537.36 node/7.4.0
INFO  2017-11-14T18:23:38.392Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:38.392Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:38.850Z websocket closed 1006 Connection dropped by remote peer. calledClose: 
INFO  2017-11-14T18:23:38.850Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:39.291Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:39.291Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:39.762Z websocket open
INFO  2017-11-14T18:23:39.764Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:39.785Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:40.246Z websocket closed 1006 Connection dropped by remote peer. calledClose: 
INFO  2017-11-14T18:23:40.246Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:40.709Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:40.709Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:41.203Z websocket open
INFO  2017-11-14T18:23:41.205Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:41.205Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:41.670Z websocket closed 1006 Connection dropped by remote peer. calledClose: 
INFO  2017-11-14T18:23:41.671Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:42.129Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:42.129Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:42.571Z websocket open
INFO  2017-11-14T18:23:42.573Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:42.573Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:43.052Z websocket closed 1006 Connection dropped by remote peer. calledClose: 
INFO  2017-11-14T18:23:43.052Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:43.499Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:43.499Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:43.966Z websocket open
INFO  2017-11-14T18:23:43.968Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:43.969Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:44.559Z websocket closed 1000 OK calledClose: 
INFO  2017-11-14T18:23:44.559Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:45.014Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:45.014Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:45.461Z websocket open
INFO  2017-11-14T18:23:45.463Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:45.463Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:46.044Z websocket closed 1006 Connection dropped by remote peer. calledClose: 
INFO  2017-11-14T18:23:46.044Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:46.512Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:46.512Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:46.973Z websocket open
INFO  2017-11-14T18:23:46.975Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:46.975Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:47.456Z websocket closed 1006 Connection dropped by remote peer. calledClose: 

It constantly continues to go on/offline every second instantly after starting the app. New messages are working (sending/receiving).


ignore my comment. apparently my signal chrome app was still installed and not in the migrated state and thus i had two signal apps with the device id running constantly kicking each other on/offline

roock commented Nov 18, 2017

Same/Similar Issue here. Signal Electron Standalone App v1.0.38

Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_1) AppleWebKit/537.36 (KHTML, like Gecko) Signal/1.0.38 Chrome/56.0.2924.87 Electron/1.6.15 Safari/537.36 node/7.4.0
INFO  2017-11-14T18:23:38.392Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:38.392Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:38.850Z websocket closed 1006 Connection dropped by remote peer. calledClose: 
INFO  2017-11-14T18:23:38.850Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:39.291Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:39.291Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:39.762Z websocket open
INFO  2017-11-14T18:23:39.764Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:39.785Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:40.246Z websocket closed 1006 Connection dropped by remote peer. calledClose: 
INFO  2017-11-14T18:23:40.246Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:40.709Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:40.709Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:41.203Z websocket open
INFO  2017-11-14T18:23:41.205Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:41.205Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:41.670Z websocket closed 1006 Connection dropped by remote peer. calledClose: 
INFO  2017-11-14T18:23:41.671Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:42.129Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:42.129Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:42.571Z websocket open
INFO  2017-11-14T18:23:42.573Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:42.573Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:43.052Z websocket closed 1006 Connection dropped by remote peer. calledClose: 
INFO  2017-11-14T18:23:43.052Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:43.499Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:43.499Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:43.966Z websocket open
INFO  2017-11-14T18:23:43.968Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:43.969Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:44.559Z websocket closed 1000 OK calledClose: 
INFO  2017-11-14T18:23:44.559Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:45.014Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:45.014Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:45.461Z websocket open
INFO  2017-11-14T18:23:45.463Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:45.463Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:46.044Z websocket closed 1006 Connection dropped by remote peer. calledClose: 
INFO  2017-11-14T18:23:46.044Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2017-11-14T18:23:46.512Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2017-11-14T18:23:46.512Z opening message socket https://textsecure-service.whispersystems.org
INFO  2017-11-14T18:23:46.973Z websocket open
INFO  2017-11-14T18:23:46.975Z got request PUT /api/v1/queue/empty
INFO  2017-11-14T18:23:46.975Z MessageReceiver: emitting 'empty' event
INFO  2017-11-14T18:23:47.456Z websocket closed 1006 Connection dropped by remote peer. calledClose: 

It constantly continues to go on/offline every second instantly after starting the app. New messages are working (sending/receiving).


ignore my comment. apparently my signal chrome app was still installed and not in the migrated state and thus i had two signal apps with the device id running constantly kicking each other on/offline

@runderwo

This comment has been minimized.

Show comment
Hide comment
@runderwo

runderwo Mar 30, 2018

When my instance gets stuck offline, this is what precedes it:

{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"online","time":"2018-03-30T23:43:36.204Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"Already online. Had a blip in online/offline status.","time":"2018-03-30T23:43:36.204Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"Sending a keepalive message","time":"2018-03-30T23:43:51.357Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"WebSocketResource.close()","time":"2018-03-30T23:43:52.359Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"websocket closed 3001 No response to keepalive request calledClose: ","time":"2018-03-30T23:43:52.364Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"GET https://textsecure-service.whispersystems.org/v1/devices","time":"2018-03-30T23:43:52.364Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"MessageReceiver: emitting 'empty' event","time":"2018-03-30T23:43:52.367Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"GET https://textsecure-service.whispersystems.org/v1/devices 503 Error","time":"2018-03-30T23:44:30.482Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"background onError: HTTPError: promise_ajax: error response; code: 503\n    at HTTPError (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37619:17)\n    at file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37577:22\n    at <anonymous>\n    at process._tickCallback (internal/process/next_tick.js:188:7)\nOriginal stack:\nError\n    at ajax (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37611:25)\n    at TextSecureServer.ajax (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37655:20)\n    at TextSecureServer.getDevices (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37765:25)\n    at MessageReceiver.onclose (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:38663:28)\n    at W3CWebSocket._dispatchEvent [as dispatchEvent] (/opt/Signal/resources/app.asar/node_modules/yaeti/lib/EventTarget.js:107:17)\n    at W3CWebSocket.onClose (/opt/Signal/resources/app.asar/node_modules/websocket/lib/W3CWebSocket.js:228:10)\n    at WebSocketConnection.<anonymous> (/opt/Signal/resources/app.asar/node_modules/websocket/lib/W3CWebSocket.js:201:17)\n    at emitTwo (events.js:125:13)\n    at WebSocketConnection.emit (events.js:213:7)\n    at WebSocketConnection.handleSocketClose (/opt/Signal/resources/app.asar/node_modules/websocket/lib/WebSocketConnection.js:387:14)","time":"2018-03-30T23:44:30.483Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":50,"msg":"Top-level unhandled promise rejection: HTTPError: The server rejected our query, please file a bug report.","time":"2018-03-30T23:44:30.568Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"offline","time":"2018-03-30T23:44:40.204Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"online","time":"2018-03-30T23:44:40.643Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"connect","time":"2018-03-30T23:44:40.644Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"MessageReceiver.close()","time":"2018-03-30T23:44:40.644Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"opening message socket https://textsecure-service.whispersystems.org","time":"2018-03-30T23:44:40.644Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"drained","time":"2018-03-30T23:44:40.742Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"websocket error","time":"2018-03-30T23:44:40.926Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"websocket closed 1006 connection failed calledClose: ","time":"2018-03-30T23:44:40.927Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"GET https://textsecure-service.whispersystems.org/v1/devices","time":"2018-03-30T23:44:40.927Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"GET https://textsecure-service.whispersystems.org/v1/devices 503 Error","time":"2018-03-30T23:44:40.931Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"background onError: HTTPError: promise_ajax: error response; code: 503\n    at HTTPError (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37619:17)\n    at file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37577:22\n    at <anonymous>\n    at process._tickCallback (internal/process/next_tick.js:188:7)\nOriginal stack:\nError\n    at ajax (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37611:25)\n    at TextSecureServer.ajax (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37655:20)\n    at TextSecureServer.getDevices (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37765:25)\n    at MessageReceiver.onclose (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:38663:28)\n    at W3CWebSocket._dispatchEvent [as dispatchEvent] (/opt/Signal/resources/app.asar/node_modules/yaeti/lib/EventTarget.js:107:17)\n    at W3CWebSocket.onConnectFailed (/opt/Signal/resources/app.asar/node_modules/websocket/lib/W3CWebSocket.js:219:14)\n    at WebSocketClient.<anonymous> (/opt/Signal/resources/app.asar/node_modules/websocket/lib/W3CWebSocket.js:59:25)\n    at emitOne (events.js:115:13)\n    at WebSocketClient.emit (events.js:210:7)\n    at WebSocketClient.failHandshake (/opt/Signal/resources/app.asar/node_modules/websocket/lib/WebSocketClient.js:326:10)","time":"2018-03-30T23:44:40.931Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":50,"msg":"Top-level unhandled promise rejection: HTTPError: The server rejected our query, please file a bug report.","time":"2018-03-30T23:44:40.932Z","v":0}

In other words, it retries only once and then gives up forever. This often happens when moving between wifi connections (on a laptop).

runderwo commented Mar 30, 2018

When my instance gets stuck offline, this is what precedes it:

{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"online","time":"2018-03-30T23:43:36.204Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"Already online. Had a blip in online/offline status.","time":"2018-03-30T23:43:36.204Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"Sending a keepalive message","time":"2018-03-30T23:43:51.357Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"WebSocketResource.close()","time":"2018-03-30T23:43:52.359Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"websocket closed 3001 No response to keepalive request calledClose: ","time":"2018-03-30T23:43:52.364Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"GET https://textsecure-service.whispersystems.org/v1/devices","time":"2018-03-30T23:43:52.364Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"MessageReceiver: emitting 'empty' event","time":"2018-03-30T23:43:52.367Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"GET https://textsecure-service.whispersystems.org/v1/devices 503 Error","time":"2018-03-30T23:44:30.482Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"background onError: HTTPError: promise_ajax: error response; code: 503\n    at HTTPError (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37619:17)\n    at file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37577:22\n    at <anonymous>\n    at process._tickCallback (internal/process/next_tick.js:188:7)\nOriginal stack:\nError\n    at ajax (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37611:25)\n    at TextSecureServer.ajax (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37655:20)\n    at TextSecureServer.getDevices (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37765:25)\n    at MessageReceiver.onclose (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:38663:28)\n    at W3CWebSocket._dispatchEvent [as dispatchEvent] (/opt/Signal/resources/app.asar/node_modules/yaeti/lib/EventTarget.js:107:17)\n    at W3CWebSocket.onClose (/opt/Signal/resources/app.asar/node_modules/websocket/lib/W3CWebSocket.js:228:10)\n    at WebSocketConnection.<anonymous> (/opt/Signal/resources/app.asar/node_modules/websocket/lib/W3CWebSocket.js:201:17)\n    at emitTwo (events.js:125:13)\n    at WebSocketConnection.emit (events.js:213:7)\n    at WebSocketConnection.handleSocketClose (/opt/Signal/resources/app.asar/node_modules/websocket/lib/WebSocketConnection.js:387:14)","time":"2018-03-30T23:44:30.483Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":50,"msg":"Top-level unhandled promise rejection: HTTPError: The server rejected our query, please file a bug report.","time":"2018-03-30T23:44:30.568Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"offline","time":"2018-03-30T23:44:40.204Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"online","time":"2018-03-30T23:44:40.643Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"connect","time":"2018-03-30T23:44:40.644Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"MessageReceiver.close()","time":"2018-03-30T23:44:40.644Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"opening message socket https://textsecure-service.whispersystems.org","time":"2018-03-30T23:44:40.644Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"drained","time":"2018-03-30T23:44:40.742Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"websocket error","time":"2018-03-30T23:44:40.926Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"websocket closed 1006 connection failed calledClose: ","time":"2018-03-30T23:44:40.927Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"GET https://textsecure-service.whispersystems.org/v1/devices","time":"2018-03-30T23:44:40.927Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"GET https://textsecure-service.whispersystems.org/v1/devices 503 Error","time":"2018-03-30T23:44:40.931Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":30,"msg":"background onError: HTTPError: promise_ajax: error response; code: 503\n    at HTTPError (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37619:17)\n    at file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37577:22\n    at <anonymous>\n    at process._tickCallback (internal/process/next_tick.js:188:7)\nOriginal stack:\nError\n    at ajax (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37611:25)\n    at TextSecureServer.ajax (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37655:20)\n    at TextSecureServer.getDevices (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:37765:25)\n    at MessageReceiver.onclose (file:///opt/Signal/resources/app.asar/js/libtextsecure.js:38663:28)\n    at W3CWebSocket._dispatchEvent [as dispatchEvent] (/opt/Signal/resources/app.asar/node_modules/yaeti/lib/EventTarget.js:107:17)\n    at W3CWebSocket.onConnectFailed (/opt/Signal/resources/app.asar/node_modules/websocket/lib/W3CWebSocket.js:219:14)\n    at WebSocketClient.<anonymous> (/opt/Signal/resources/app.asar/node_modules/websocket/lib/W3CWebSocket.js:59:25)\n    at emitOne (events.js:115:13)\n    at WebSocketClient.emit (events.js:210:7)\n    at WebSocketClient.failHandshake (/opt/Signal/resources/app.asar/node_modules/websocket/lib/WebSocketClient.js:326:10)","time":"2018-03-30T23:44:40.931Z","v":0}
{"name":"log","hostname":"achpee","pid":31394,"level":50,"msg":"Top-level unhandled promise rejection: HTTPError: The server rejected our query, please file a bug report.","time":"2018-03-30T23:44:40.932Z","v":0}

In other words, it retries only once and then gives up forever. This often happens when moving between wifi connections (on a laptop).

@ProactiveServices

This comment has been minimized.

Show comment
Hide comment
@ProactiveServices

ProactiveServices Apr 2, 2018

Seeing this with v1.6.1 on two different Windows 7 x64 machines when I have LAN/ISP outages. Relevant snippet of log below where Signal remained disconnected for many hours until I opened the developer tools, Network tab then toggled "Offline" on and off, Signal reconnected immediately.

Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Signal/1.6.1 Chrome/59.0.3071.115 Electron/1.8.2 Safari/537.36 node/8.2.1 env/production
<snip a few days of normal operation>
INFO  2018-04-02T13:10:57.896Z Sending a keepalive message
INFO  2018-04-02T13:10:58.899Z WebSocketResource.close()
INFO  2018-04-02T13:11:00.904Z Dispatching our own socket close event
INFO  2018-04-02T13:11:00.904Z websocket closed 3001 No response to keepalive request calledClose: 
INFO  2018-04-02T13:11:00.904Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T13:11:00.904Z MessageReceiver: emitting 'empty' event
INFO  2018-04-02T13:11:10.905Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-04-02T13:11:12.904Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T13:11:22.904Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-04-02T13:11:24.904Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T13:11:35.898Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-04-02T13:11:35.898Z background onError: HTTPError: promise_ajax catch; code: -1
    at HTTPError (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37619:17)
    at file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37588:18
    at <anonymous>
Original stack:
FetchError: network timeout at: https://textsecure-service.whispersystems.org/v1/devices
    at C:\Users\aD\AppData\Local\Programs\signal-desktop\resources\app.asar\node_modules\node-fetch\index.js:126:13
Initial stack:
Error
    at ajax (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37611:25)
    at TextSecureServer.ajax (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37655:20)
    at TextSecureServer.getDevices (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37765:25)
    at MessageReceiver.onclose (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:38663:28)
    at window.WebSocketResource.dispatchEvent (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37403:47)
    at window.WebSocketResource.<anonymous> (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:38492:22)
INFO  2018-04-02T13:11:35.898Z retrying in 1 minute
INFO  2018-04-02T13:12:35.899Z connect
INFO  2018-04-02T13:12:35.899Z MessageReceiver.close()
INFO  2018-04-02T13:12:35.899Z opening message socket https://textsecure-service.whispersystems.org
INFO  2018-04-02T13:12:35.899Z drained
INFO  2018-04-02T13:12:47.917Z websocket error
INFO  2018-04-02T13:12:47.917Z websocket closed 1006 connection failed calledClose: 
INFO  2018-04-02T13:12:47.917Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T13:12:58.904Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-04-02T13:13:00.900Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T13:13:05.820Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2018-04-02T13:13:05.820Z opening message socket https://textsecure-service.whispersystems.org
INFO  2018-04-02T13:13:06.222Z websocket open
INFO  2018-04-02T13:13:06.222Z got request PUT /api/v1/queue/empty
INFO  2018-04-02T13:13:06.222Z MessageReceiver: emitting 'empty' event
INFO  2018-04-02T13:13:06.222Z Update notifications: isFocused: false isEnabled: true numNotifications: 0 shouldPlayNotificationSound: true
INFO  2018-04-02T13:14:01.900Z Sending a keepalive message
<snip normal operation, then suffered a LAN outage of a few minutes>
INFO  2018-04-02T14:26:49.896Z Sending a keepalive message
INFO  2018-04-02T14:26:50.901Z WebSocketResource.close()
INFO  2018-04-02T14:26:52.900Z Dispatching our own socket close event
INFO  2018-04-02T14:26:52.901Z websocket closed 3001 No response to keepalive request calledClose: 
INFO  2018-04-02T14:26:52.901Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T14:26:52.901Z MessageReceiver: emitting 'empty' event
INFO  2018-04-02T14:27:03.903Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-04-02T14:27:05.900Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T14:27:14.831Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2018-04-02T14:27:14.831Z opening message socket https://textsecure-service.whispersystems.org
INFO  2018-04-02T14:27:15.721Z websocket open
INFO  2018-04-02T14:27:15.721Z got request PUT /api/v1/queue/empty
INFO  2018-04-02T14:27:15.721Z MessageReceiver: emitting 'empty' event
INFO  2018-04-02T14:28:10.901Z Sending a keepalive message
<snip normal operation, then LAN outage of a few minutes>
INFO  2018-04-02T16:24:50.901Z Sending a keepalive message
INFO  2018-04-02T16:24:52.901Z WebSocketResource.close()
INFO  2018-04-02T16:24:53.124Z websocket closed 3001 No response to keepalive request calledClose: 
INFO  2018-04-02T16:24:53.124Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T16:24:53.124Z MessageReceiver: emitting 'empty' event
INFO  2018-04-02T16:24:59.724Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2018-04-02T16:24:59.724Z opening message socket https://textsecure-service.whispersystems.org
INFO  2018-04-02T16:35:03.298Z Updating BrowserWindow config: {"maximized":false,"autoHideMenuBar":false,"width":640,"height":439,"x":639,"y":513}
<snip repeats>
INFO  2018-04-02T21:28:16.807Z Loaded this list of log files from logPath: log.log, log.log.0, log.log.1, log.log.2

ProactiveServices commented Apr 2, 2018

Seeing this with v1.6.1 on two different Windows 7 x64 machines when I have LAN/ISP outages. Relevant snippet of log below where Signal remained disconnected for many hours until I opened the developer tools, Network tab then toggled "Offline" on and off, Signal reconnected immediately.

Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Signal/1.6.1 Chrome/59.0.3071.115 Electron/1.8.2 Safari/537.36 node/8.2.1 env/production
<snip a few days of normal operation>
INFO  2018-04-02T13:10:57.896Z Sending a keepalive message
INFO  2018-04-02T13:10:58.899Z WebSocketResource.close()
INFO  2018-04-02T13:11:00.904Z Dispatching our own socket close event
INFO  2018-04-02T13:11:00.904Z websocket closed 3001 No response to keepalive request calledClose: 
INFO  2018-04-02T13:11:00.904Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T13:11:00.904Z MessageReceiver: emitting 'empty' event
INFO  2018-04-02T13:11:10.905Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-04-02T13:11:12.904Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T13:11:22.904Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-04-02T13:11:24.904Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T13:11:35.898Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-04-02T13:11:35.898Z background onError: HTTPError: promise_ajax catch; code: -1
    at HTTPError (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37619:17)
    at file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37588:18
    at <anonymous>
Original stack:
FetchError: network timeout at: https://textsecure-service.whispersystems.org/v1/devices
    at C:\Users\aD\AppData\Local\Programs\signal-desktop\resources\app.asar\node_modules\node-fetch\index.js:126:13
Initial stack:
Error
    at ajax (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37611:25)
    at TextSecureServer.ajax (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37655:20)
    at TextSecureServer.getDevices (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37765:25)
    at MessageReceiver.onclose (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:38663:28)
    at window.WebSocketResource.dispatchEvent (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:37403:47)
    at window.WebSocketResource.<anonymous> (file:///C:/Users/aD/AppData/Local/Programs/signal-desktop/resources/app.asar/js/libtextsecure.js:38492:22)
INFO  2018-04-02T13:11:35.898Z retrying in 1 minute
INFO  2018-04-02T13:12:35.899Z connect
INFO  2018-04-02T13:12:35.899Z MessageReceiver.close()
INFO  2018-04-02T13:12:35.899Z opening message socket https://textsecure-service.whispersystems.org
INFO  2018-04-02T13:12:35.899Z drained
INFO  2018-04-02T13:12:47.917Z websocket error
INFO  2018-04-02T13:12:47.917Z websocket closed 1006 connection failed calledClose: 
INFO  2018-04-02T13:12:47.917Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T13:12:58.904Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-04-02T13:13:00.900Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T13:13:05.820Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2018-04-02T13:13:05.820Z opening message socket https://textsecure-service.whispersystems.org
INFO  2018-04-02T13:13:06.222Z websocket open
INFO  2018-04-02T13:13:06.222Z got request PUT /api/v1/queue/empty
INFO  2018-04-02T13:13:06.222Z MessageReceiver: emitting 'empty' event
INFO  2018-04-02T13:13:06.222Z Update notifications: isFocused: false isEnabled: true numNotifications: 0 shouldPlayNotificationSound: true
INFO  2018-04-02T13:14:01.900Z Sending a keepalive message
<snip normal operation, then suffered a LAN outage of a few minutes>
INFO  2018-04-02T14:26:49.896Z Sending a keepalive message
INFO  2018-04-02T14:26:50.901Z WebSocketResource.close()
INFO  2018-04-02T14:26:52.900Z Dispatching our own socket close event
INFO  2018-04-02T14:26:52.901Z websocket closed 3001 No response to keepalive request calledClose: 
INFO  2018-04-02T14:26:52.901Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T14:26:52.901Z MessageReceiver: emitting 'empty' event
INFO  2018-04-02T14:27:03.903Z GET https://textsecure-service.whispersystems.org/v1/devices 0 Error
INFO  2018-04-02T14:27:05.900Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T14:27:14.831Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2018-04-02T14:27:14.831Z opening message socket https://textsecure-service.whispersystems.org
INFO  2018-04-02T14:27:15.721Z websocket open
INFO  2018-04-02T14:27:15.721Z got request PUT /api/v1/queue/empty
INFO  2018-04-02T14:27:15.721Z MessageReceiver: emitting 'empty' event
INFO  2018-04-02T14:28:10.901Z Sending a keepalive message
<snip normal operation, then LAN outage of a few minutes>
INFO  2018-04-02T16:24:50.901Z Sending a keepalive message
INFO  2018-04-02T16:24:52.901Z WebSocketResource.close()
INFO  2018-04-02T16:24:53.124Z websocket closed 3001 No response to keepalive request calledClose: 
INFO  2018-04-02T16:24:53.124Z GET https://textsecure-service.whispersystems.org/v1/devices
INFO  2018-04-02T16:24:53.124Z MessageReceiver: emitting 'empty' event
INFO  2018-04-02T16:24:59.724Z GET https://textsecure-service.whispersystems.org/v1/devices 200 Success
INFO  2018-04-02T16:24:59.724Z opening message socket https://textsecure-service.whispersystems.org
INFO  2018-04-02T16:35:03.298Z Updating BrowserWindow config: {"maximized":false,"autoHideMenuBar":false,"width":640,"height":439,"x":639,"y":513}
<snip repeats>
INFO  2018-04-02T21:28:16.807Z Loaded this list of log files from logPath: log.log, log.log.0, log.log.1, log.log.2
@PorcelainMouse

This comment has been minimized.

Show comment
Hide comment
@PorcelainMouse

PorcelainMouse Apr 28, 2018

My symptoms are very similar to @runderwo comment. The last message on STDDERR I see is:
{"name":"log","hostname":"<redacted>","pid":2,"level":30,"msg":"Sending a keepalive message","time":"2018-04-28T02:08:38.249Z","v":0}
and is preceeded by almost 200 identical ones. Messages seem to be about 1 minute apart.

In my case, however, I cannot find any evidence of network/Internet connection problems and my system never sleeps. Is anyone else seen that?

This started happening regularly only recently, I think. In the past, I have noticed disconnected messages would occur, often, but didn't very last long. The recent change is that it doesn't go away. When I quite and restart Signal Desktop, there is no evidence of problems. When I go to textsecure-service.whispersystems.org, I just get SEC_ERROR_UNKNOWN_ISSUER, and I assume that is correct, but that's now, not when the disconnect message originally occurs.

PorcelainMouse commented Apr 28, 2018

My symptoms are very similar to @runderwo comment. The last message on STDDERR I see is:
{"name":"log","hostname":"<redacted>","pid":2,"level":30,"msg":"Sending a keepalive message","time":"2018-04-28T02:08:38.249Z","v":0}
and is preceeded by almost 200 identical ones. Messages seem to be about 1 minute apart.

In my case, however, I cannot find any evidence of network/Internet connection problems and my system never sleeps. Is anyone else seen that?

This started happening regularly only recently, I think. In the past, I have noticed disconnected messages would occur, often, but didn't very last long. The recent change is that it doesn't go away. When I quite and restart Signal Desktop, there is no evidence of problems. When I go to textsecure-service.whispersystems.org, I just get SEC_ERROR_UNKNOWN_ISSUER, and I assume that is correct, but that's now, not when the disconnect message originally occurs.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment