Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Stream failed to open Websocket, causing later calls to fail #402

Closed
1 of 6 tasks
rubenvereecken opened this issue Apr 22, 2021 · 29 comments
Closed
1 of 6 tasks

Stream failed to open Websocket, causing later calls to fail #402

rubenvereecken opened this issue Apr 22, 2021 · 29 comments
Labels
bug Something isn't working

Comments

@rubenvereecken
Copy link

Describe the bug
This is a bug that happened in production so all we have are stacktraces. The problem is that queryChannels failed, causing some things to get stuck. The deeper issue seems to be that Stream failed to set up its Websocket connection.

Here's the Websocket error. I could pinpoint the line that triggered it on our part, it's an invocation of client.setUser.

├┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄
2021-04-20 17:51:15.920 11917-12113/? I/flutter: │ 🐛 Setting chat user wF6n9VTqeFbKVQGIaYaxloAGINH3 - Ruben
2021-04-20 17:51:15.920 11917-12113/? I/flutter: └───────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
2021-04-20 17:51:17.161 11917-12113/? E/flutter: [ERROR:flutter/lib/ui/ui_dart_state.cc(177)] Unhandled Exception: Null check operator used on a null value
    #0      ChangeNotifier.notifyListeners (package:flutter/src/foundation/change_notifier.dart:218)
    #1      ValueNotifier.value= (package:flutter/src/foundation/change_notifier.dart:292)
    #2      WebSocket._onData (package:stream_chat/src/api/websocket.dart:167)
    #3      WebSocket.connect.<anonymous closure> (package:stream_chat/src/api/websocket.dart:132)
    #4      _rootRunUnary (dart:async/zone.dart:1198)
    #5      _CustomZone.runUnary (dart:async/zone.dart:1100)
    #6      _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005)
    #7      _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357)
    #8      _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285)
    #9      _ForwardingStreamSubscription._add (dart:async/stream_pipe.dart:127)
    #10     _HandleErrorStream._handleData (dart:async/stream_pipe.dart:266)
    #11     _ForwardingStreamSubscription._handleData (dart:async/stream_pipe.dart:157)
    #12     _rootRunUnary (dart:async/zone.dart:1198)
    #13     _CustomZone.runUnary (dart:async/zone.dart:1100)
    #14     _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005)
    #15     _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357)
    #16     _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285)
    #17     _SyncStreamControllerDispatch._sendData (dart:async/stream_controller.dart:808)
    #18     _StreamController._add (dart:async/stream_controller.dart:682)
    #19     _rootRunUnary (dart:async/zone.dart:1198)
    #20     _CustomZone.runUnary (dart:async/zone.dart:1100)
    #21     _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005)
    #22     _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357)
    #23     _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285)
    #24     _SyncStreamControllerDispatch._sendData (dart:async/stream_controller.dart:808)
    #25     _StreamController._add (dart:async/stream_controller.dart:682)
    #26     _StreamController.add (dart:async/stream_controller.dart:624)
    #27     new _WebSocketImpl._fromSocket.<anonymous closure> (dart:_http/websocket_impl.dart:1145)
    #28     _rootRunUnary (dart:async/zone.dart:1198)
    #29     _CustomZone.runUnary (dart:async/zone.dart:1100)
    #30     _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005)
    #31     _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357)
    #32     _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285)
    #33     _SinkTransformerStreamSubscription._add (dart:async/stream_transformers.dart:69)
    #34     _EventSinkWrapper.add (dart:async/stream_transformers.dart:15)
    #35     _WebSocketProtocolTransformer._messageFrameEnd (dart:_http/websocket_impl.dart:338)
    #36     _WebSocketProtocolTransformer.add (dart:_http/websocket_impl.dart:232)
    #37     _SinkTransformerStreamSubscription._handleData (dart:async/stream_transformers.dart:121)
    #38     _rootRunUnary (dart:async/zone.dart:1198)
    #39     _CustomZone.runUnary (dart:async/zone.dart:1100)
    #40     _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005)
    #41     _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357)
    #42     _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285)
    #43     _SyncStreamControllerDispatch._sendData (dart:async/stream_controller.dart:808)
    #44     _StreamController._add (dart:async/stream_controller.dart:682)
    #45     _StreamController.add (dart:async/stream_controller.dart:624)
    #46     _Socket._onData (dart:io-patch/socket_patch.dart:2044)
    #47     _rootRunUnary (dart:async/zone.dart:1198)
    #48     _CustomZone.runUnary (dart:async/zone.dart:1100)
    #49     _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005)
    #50     _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357)
    #51     _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285)
    #52     _SyncStreamControllerDispatch._sendData (dart:async/stream_controller.dart:808)
    #53     _StreamController._add (dart:async/stream_controller.dart:682)
2021-04-20 17:51:17.161 11917-12113/? E/flutter: #54     _StreamController.add (dart:async/stream_controller.dart:624)
    #55     _RawSecureSocket._sendReadEvent (dart:io/secure_socket.dart:1002)
    #56     _rootRun (dart:async/zone.dart:1182)
    #57     _CustomZone.run (dart:async/zone.dart:1093)
    #58     _CustomZone.runGuarded (dart:async/zone.dart:997)
    #59     _CustomZone.bindCallbackGuarded.<anonymous closure> (dart:async/zone.dart:1037)
    #60     _rootRun (dart:async/zone.dart:1190)
    #61     _CustomZone.run (dart:async/zone.dart:1093)
    #62     _CustomZone.bindCallback.<anonymous closure> (dart:async/zone.dart:1021)
    #63     Timer._createTimer.<anonymous closure> (dart:async-patch/timer_patch.dart:18)
    #64     _Timer._runTimers (dart:isolate-patch/timer_impl.dart:397)
    #65     _Timer._handleMessage (dart:isolate-patch/timer_impl.dart:428)
    #66     _RawReceivePortImpl._handleMessage (dart:isolate-patch/isolate_patch.dart:168)

What package are you using? What version?
stream_flutter 0.2.10

What platform is it about?

  • Android
  • iOS
  • Web
  • Windows
  • MacOS
  • Linux

To Reproduce
Steps to reproduce the behavior:
0. Open app through a notification (Firebase display message) (this might be relevant, as perhaps the environment isn't fully the same on start-up or something)

  1. client.setUser(...)
  2. It doesn't always happen

Expected behavior
For Stream to create the Websocket successfully, or at least to keep trying.

Full Stacktrace

``` 2021-04-20 17:51:15.920 11917-12113/? I/flutter: ┌─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── 2021-04-20 17:51:15.920 11917-12113/? I/flutter: │ 17:51:15.920 (+0:02:09.088596) 2021-04-20 17:51:15.920 11917-12113/? I/flutter: ├┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄ 2021-04-20 17:51:15.920 11917-12113/? I/flutter: │ 💡 Authenticated with Stream Chat. Setting up now... 2021-04-20 17:51:15.920 11917-12113/? I/flutter: └─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── 2021-04-20 17:51:15.920 11917-12113/? I/flutter: ┌─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── 2021-04-20 17:51:15.920 11917-12113/? I/flutter: │ 17:51:15.920 (+0:02:09.088770) 2021-04-20 17:51:15.920 11917-12113/? I/flutter: ├┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄ 2021-04-20 17:51:15.920 11917-12113/? I/flutter: │ 🐛 Setting chat user wF6n9VTqeFbKVQGIaYaxloAGINH3 - Ruben 2021-04-20 17:51:15.920 11917-12113/? I/flutter: └─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── 2021-04-20 17:51:17.161 11917-12113/? E/flutter: [ERROR:flutter/lib/ui/ui_dart_state.cc(177)] Unhandled Exception: Null check operator used on a null value #0 ChangeNotifier.notifyListeners (package:flutter/src/foundation/change_notifier.dart:218) #1 ValueNotifier.value= (package:flutter/src/foundation/change_notifier.dart:292) #2 WebSocket._onData (package:stream_chat/src/api/websocket.dart:167) #3 WebSocket.connect. (package:stream_chat/src/api/websocket.dart:132) #4 _rootRunUnary (dart:async/zone.dart:1198) #5 _CustomZone.runUnary (dart:async/zone.dart:1100) #6 _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005) #7 _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357) #8 _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285) #9 _ForwardingStreamSubscription._add (dart:async/stream_pipe.dart:127) #10 _HandleErrorStream._handleData (dart:async/stream_pipe.dart:266) #11 _ForwardingStreamSubscription._handleData (dart:async/stream_pipe.dart:157) #12 _rootRunUnary (dart:async/zone.dart:1198) #13 _CustomZone.runUnary (dart:async/zone.dart:1100) #14 _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005) #15 _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357) #16 _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285) #17 _SyncStreamControllerDispatch._sendData (dart:async/stream_controller.dart:808) #18 _StreamController._add (dart:async/stream_controller.dart:682) #19 _rootRunUnary (dart:async/zone.dart:1198) #20 _CustomZone.runUnary (dart:async/zone.dart:1100) #21 _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005) #22 _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357) #23 _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285) #24 _SyncStreamControllerDispatch._sendData (dart:async/stream_controller.dart:808) #25 _StreamController._add (dart:async/stream_controller.dart:682) #26 _StreamController.add (dart:async/stream_controller.dart:624) #27 new _WebSocketImpl._fromSocket. (dart:_http/websocket_impl.dart:1145) #28 _rootRunUnary (dart:async/zone.dart:1198) #29 _CustomZone.runUnary (dart:async/zone.dart:1100) #30 _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005) #31 _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357) #32 _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285) #33 _SinkTransformerStreamSubscription._add (dart:async/stream_transformers.dart:69) #34 _EventSinkWrapper.add (dart:async/stream_transformers.dart:15) #35 _WebSocketProtocolTransformer._messageFrameEnd (dart:_http/websocket_impl.dart:338) #36 _WebSocketProtocolTransformer.add (dart:_http/websocket_impl.dart:232) #37 _SinkTransformerStreamSubscription._handleData (dart:async/stream_transformers.dart:121) #38 _rootRunUnary (dart:async/zone.dart:1198) #39 _CustomZone.runUnary (dart:async/zone.dart:1100) #40 _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005) #41 _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357) #42 _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285) #43 _SyncStreamControllerDispatch._sendData (dart:async/stream_controller.dart:808) #44 _StreamController._add (dart:async/stream_controller.dart:682) #45 _StreamController.add (dart:async/stream_controller.dart:624) #46 _Socket._onData (dart:io-patch/socket_patch.dart:2044) #47 _rootRunUnary (dart:async/zone.dart:1198) #48 _CustomZone.runUnary (dart:async/zone.dart:1100) #49 _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005) #50 _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357) #51 _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285) #52 _SyncStreamControllerDispatch._sendData (dart:async/stream_controller.dart:808) #53 _StreamController._add (dart:async/stream_controller.dart:682) 2021-04-20 17:51:17.161 11917-12113/? E/flutter: #54 _StreamController.add (dart:async/stream_controller.dart:624) #55 _RawSecureSocket._sendReadEvent (dart:io/secure_socket.dart:1002) #56 _rootRun (dart:async/zone.dart:1182) #57 _CustomZone.run (dart:async/zone.dart:1093) #58 _CustomZone.runGuarded (dart:async/zone.dart:997) #59 _CustomZone.bindCallbackGuarded. (dart:async/zone.dart:1037) #60 _rootRun (dart:async/zone.dart:1190) #61 _CustomZone.run (dart:async/zone.dart:1093) #62 _CustomZone.bindCallback. (dart:async/zone.dart:1021) #63 Timer._createTimer. (dart:async-patch/timer_patch.dart:18) #64 _Timer._runTimers (dart:isolate-patch/timer_impl.dart:397) #65 _Timer._handleMessage (dart:isolate-patch/timer_impl.dart:428) #66 _RawReceivePortImpl._handleMessage (dart:isolate-patch/isolate_patch.dart:168) 2021-04-20 17:56:14.701 11917-12113/? I/flutter: on resume {notification: {}, data: {google.original_priority: high, google.sent_time: 1618937629441, google.delivered_priority: high, sound: default, channel: {"id":"OaNxaeJC8PgNpxCG7n9oUKoFax32","type":"lessgo-team","cid":"lessgo-team:OaNxaeJC8PgNpxCG7n9oUKoFax32"}, screen: /channel, click_action: FLUTTER_NOTIFICATION_CLICK, google.message_id: 0:1618937629467992%0117a48c0117a48c, collapse_key: co.lessgo.lessgo, google.ttl: 2419200, from: 297352398976, channelId: lessgo-team:OaNxaeJC8PgNpxCG7n9oUKoFax32, status: done}} 2021-04-20 17:56:14.702 11917-12113/? I/flutter: false - false - false 2021-04-20 17:56:14.702 11917-12113/? I/flutter: Want to nav? true 2021-04-20 17:56:14.702 11917-12113/? I/flutter: false - false - false 2021-04-20 17:56:14.702 11917-12113/? I/flutter: Logged in and got a display message - routing now 2021-04-20 17:56:14.702 11917-12113/? I/flutter: ┌─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── 2021-04-20 17:56:14.702 11917-12113/? I/flutter: │ 17:56:14.702 (+0:07:07.870854) 2021-04-20 17:56:14.702 11917-12113/? I/flutter: ├┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄ 2021-04-20 17:56:14.702 11917-12113/? I/flutter: │ 💡 Navigating display msg -> /channel with {google.original_priority: high, google.sent_time: 1618937629441, google.delivered_priority: high, sound: default, channel: {"id":"OaNxaeJC8PgNpxCG7n9oUKoFax32","type":"lessgo-team","cid":"lessgo-team:OaNxaeJC8PgNpxCG7n9oUKoFax32"}, screen: /channel, click_action: FLUTTER_NOTIFICATION_CLICK, google.message_id: 0:1618937629467992%0117a48c0117a48c, collapse_key: co.lessgo.lessgo, google.ttl: 2419200, from: 297352398976, channelId: lessgo-team:OaNxaeJC8PgNpxCG7n9oUKoFax32, status: done} 2021-04-20 17:56:14.702 11917-12113/? I/flutter: └─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── 2021-04-20 17:56:14.703 11917-12113/? I/flutter: ┌─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── 2021-04-20 17:56:14.703 11917-12113/? I/flutter: │ 17:56:14.703 (+0:07:07.871539) 2021-04-20 17:56:14.703 11917-12113/? I/flutter: ├┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄ 2021-04-20 17:56:14.703 11917-12113/? I/flutter: │ 🐛 Creating route arguments for '/channel' 2021-04-20 17:56:14.703 11917-12113/? I/flutter: └─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── 2021-04-20 17:56:14.703 11917-12113/? I/flutter: /channel 2021-04-20 17:56:15.244 11917-12113/? I/flutter: (2021-04-20 17:56:15.244562) 🚨 📡 apiError: ApiError{body: {"code":4,"message":"QueryChannels failed with error: \"Watch or Presence requires an active websocket connection, please make sure to include your websocket connection_id\"","StatusCode":400,"duration":"0.00ms","more_info":"https://getstream.io/chat/docs/api_errors_response"}, jsonData: {code: 4, message: QueryChannels failed with error: "Watch or Presence requires an active websocket connection, please make sure to include your websocket connection_id", StatusCode: 400, duration: 0.00ms, more_info: https://getstream.io/chat/docs/api_errors_response}, status: 400, code: 4} 2021-04-20 17:56:15.245 11917-12113/? E/flutter: [ERROR:flutter/lib/ui/ui_dart_state.cc(177)] Unhandled Exception: ApiError{body: {"code":4,"message":"QueryChannels failed with error: \"Watch or Presence requires an active websocket connection, please make sure to include your websocket connection_id\"","StatusCode":400,"duration":"0.00ms","more_info":"https://getstream.io/chat/docs/api_errors_response"}, jsonData: {code: 4, message: QueryChannels failed with error: "Watch or Presence requires an active websocket connection, please make sure to include your websocket connection_id", StatusCode: 400, duration: 0.00ms, more_info: https://getstream.io/chat/docs/api_errors_response}, status: 400, code: 4} #0 Client.get (package:stream_chat/src/client.dart:666) #1 Client.queryChannels (package:stream_chat/src/client.dart:583) #2 Stream.first. (dart:async/stream.dart) ```

Additional context
If this can't be resolved because it's some odd fluke and it might happen from time to time, we still want to be able to deal with it. Would it be possible to document/explain which calls are expected to throw, and what we can catch? For example, if setUser is expected to throw, we most definitely want to catch it and put some retry logic around it, if indeed it's retryable.

@rubenvereecken rubenvereecken added the bug Something isn't working label Apr 22, 2021
@deven98
Copy link
Contributor

deven98 commented Apr 22, 2021

Hey @rubenvereecken,

Can you try upgrading your dependency to the latest version and let us know if the problem still persists?

Thanks.

@rubenvereecken
Copy link
Author

Alright we're on it, will report back after the upgrade, might take a while.

@rubenvereecken
Copy link
Author

rubenvereecken commented Apr 23, 2021

The issue persists in 1.3.2-beta, which apparently is the latest we could upgrade to without dependency issues (we're waiting on #339 for the rest).

Also @deven98

@rubenvereecken
Copy link
Author

Actually that was my bad, bad communication on our part. We're testing and I'll report back when we have something conclusive.

@rubenvereecken
Copy link
Author

There are still some WebSocketChannelException errors. Are we expected to catch those ourselves and have our own retry logic? I don't mind but just want to figure out the API.

That aside, is it normal that we should catch queryChannels errors as DioErrors, rather than you wrapping them inside a Stream error or something?

I/flutter (12540): /channel
I/flutter (12540): (2021-04-23 20:53:05.468526) ℹ️ 📡 connecting
I/flutter (12540): (2021-04-23 20:53:05.469454) ℹ️ 📡 handle new event: {type: connection.changed, cid: null, channel_id: null, channel_type: null, connection_id: null, created_at: null, me: null, user: null, message: null, channel: null, member: null, reaction: null, total_unread_count: null, unread_channels: null, online: false, parent_id: null, is_local: true}
I/flutter (12540): (2021-04-23 20:53:05.469666) ℹ️ 🔌 connecting to wss://chat-us-east-1.stream-io-api.com/connect?api_key=f2f7btr66dgr&authorization=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ1c2VyX2lkIjoiT0lhcFpsa0I4UWNYSW9KandRUTRaQms0YUtqMiJ9.KhSU_rkjejEz2PDacyx6UiEHSlgEKlnYHvw5pdQsmSA&stream-auth-type=jwt&X-Stream-Client=stream-chat-dart-client-android-1.5.0&json=%7B%22user_id%22%3A%22OIapZlkB8QcXIoJjwQQ4ZBk4aKj2%22%2C%22server_determines_connection_id%22%3Atrue%2C%22user_details%22%3A%7B%22id%22%3A%22OIapZlkB8QcXIoJjwQQ4ZBk4aKj2%22%2C%22roles%22%3A%5B%5D%2C%22invisible%22%3Afalse%2C%22unread_count%22%3A11%2C%22language%22%3A%22%22%2C%22publicId%22%3A%22anne%22%2C%22teamChatMember%22%3Afalse%2C%22firstName%22%3A%22Anne%22%2C%22image%22%3A%22https%3A%2F%2Fstorage.googleapis.com%2Fprofilepictures.dev.lessgo.co%2FOIapZlkB8QcXIoJjwQQ4ZBk4aKj2%2F1RU7dbu5_320x320.jpg%22%2C%22name%22%3A%22Anne+Lingard%22%7D%7D
I/flutter (12540): (2021-04-23 20:53:05.470505) ℹ️ 📡 handle new event: {type: connection.changed, cid: null, channel_id: null, channel_type: null, connection_id: null, created_at: null, me: null, user: null, message: null, channel: null, member: null, reaction: null, total_unread_count: null, unread_channels: null, online: false, parent_id: null, is_local: true}
D/EGL_emulation(12540): eglMakeCurrent: 0xdf64b1a0: ver 2 0 (tinfo 0xdf678d20)
W/FA      (12540): setCurrentScreen cannot be called with the same class and name
I/PlayCore(12540): UID: [10300]  PID: [12540] AppUpdateService : ServiceConnectionImpl.onServiceConnected(ComponentInfo{com.android.vending/com.google.android.finsky.installservice.DevTriggeredUpdateService})
I/PlayCore(12540): UID: [10300]  PID: [12540] AppUpdateService : linkToDeath
I/PlayCore(12540): UID: [10300]  PID: [12540] OnRequestInstallCallback : onRequestInfo
I/flutter (12540): Instance of 'ClientState'
I/PlayCore(12540): UID: [10300]  PID: [12540] AppUpdateService : Unbind from service.
I/PlayCore(12540): UID: [10300]  PID: [12540] OnRequestInstallCallback : onRequestInfo
I/PlayCore(12540): UID: [10300]  PID: [12540] OnRequestInstallCallback : onRequestInfo
W/JavaBinder(12540): BinderProxy is being destroyed but the application did not call unlinkToDeath to unlink all of its death recipients beforehand.  Releasing leaked death recipient: com.google.android.play.core.internal.ai
D/EGL_emulation(12540): eglMakeCurrent: 0xdf64c0a0: ver 2 0 (tinfo 0xbf4022a0)
D/eglCodecCommon(12540): setVertexArrayObject: set vao to 0 (0) 49 0
I/flutter (12540): (2021-04-23 20:53:07.822076) ℹ️ 📡
I/flutter (12540):           method: GET
I/flutter (12540):           url: https://chat-us-east-1.stream-io-api.com/channels?payload=%7B%22filter_conditions%22%3A%7B%22cid%22%3A%22meetup%3A60817445a0553b6da25b5a69%22%7D%2C%22sort%22%3Anull%2C%22state%22%3Atrue%2C%22watch%22%3Atrue%2C%22presence%22%3Afalse%2C%22limit%22%3A10%2C%22offset%22%3A0%7D&user_id=OIapZlkB8QcXIoJjwQQ4ZBk4aKj2&api_key=f2f7btr66dgr&connection_id=6079510c-0a03-212a-0000-000000462d61
I/flutter (12540):           headers: {content-type: application/json; charset=utf-8, Authorization: eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ1c2VyX2lkIjoiT0lhcFpsa0I4UWNYSW9KandRUTRaQms0YUtqMiJ9.KhSU_rkjejEz2PDacyx6UiEHSlgEKlnYHvw5pdQsmSA, stream-auth-type: jwt, X-Stream-Client: stream-chat-dart-client-android-1.5.0, Content-Encoding: gzip}
I/flutter (12540):           data: {connection_id: 6079510c-0a03-212a-0000-000000462d61}
I/flutter (12540):
I/flutter (12540):
E/flutter (12540): [ERROR:flutter/lib/ui/ui_dart_state.cc(177)] Unhandled Exception: DioError [DioErrorType.CONNECT_TIMEOUT]: Connecting timed out [6000ms]
�[38;5;244mE/flutter (12540): #0      StreamChatClient.get�[39;49m
E/flutter (12540): <asynchronous suspension>
�[38;5;244mE/flutter (12540): #1      StreamChatClient.queryChannelsOnline�[39;49m
�[38;5;244mE/flutter (12540): #2      StreamChatClient.connect.<anonymous closure>�[39;49m
�[38;5;244mE/flutter (12540): #3      StreamChatClient.connect.<anonymous closure>�[39;49m
�[38;5;244mE/flutter (12540): #4      _rootRunUnary (dart:async/zone.dart:1198:47)�[39;49m
�[38;5;244mE/flutter (12540): #5      _CustomZone.runUnary (dart:async/zone.dart:1100:19)�[39;49m
�[38;5;244mE/flutter (12540): #6      _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005:7)�[39;49m
�[38;5;244mE/flutter (12540): #7      _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357:11)�[39;49m
�[38;5;244mE/flutter (12540): #8      _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285:7)�[39;49m
�[38;5;244mE/flutter (12540): #9      _SyncBroadcastStreamController._sendData (dart:async/broadcast_stream_controller.dart:385:25)�[39;49m
�[38;5;244mE/flutter (12540): #10     _BroadcastStreamController.add (dart:async/broadcast_stream_controller.dart:250:5)�[39;49m
�[38;5;244mE/flutter (12540): #11     _StartWithStreamSink.add�[39;49m
�[38;5;244mE/flutter (12540): #12     forwardStream.<anonymous closure>.<anonymous closure>.<anonymous closure>�[39;49m
�[38;5;244mE/flutter (12540): #13     forwardStream.runCatching�[39;49m
�[38;5;244mE/flutter (12540): #14     forwardStream.<anonymous closure>.<anonymous closure>�[39;49m
�[38;5;244mE/flutter (12540): #15     _rootRunUnary (dart:async/zone.dart:1198:47)�[39;49m
�[38;5;244mE/flutter (12540): #16     _CustomZone.runUnary (dart:async/zone.dart:1100:19)�[39;49m
�[38;5;244mE/flutter (12540): #17     _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005:7)�[39;49m
�[38;5;244mE/flutter (12540): #18     _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357:11)�[39;49m
�[38;5;244mE/flutter (12540): #19     _DelayedData.perform (dart:async/stream_impl.dart:611:14)�[39;49m
�[38;5;244mE/flutter (12540): #20     _StreamImplEvents.handleNext (dart:async/stream_impl.dart:730:11)�[39;49m
�[38;5;244mE/flutter (12540): #21     _PendingEvents.schedule.<anonymous closure> (dart:async/stream_impl.dart:687:7)�[39;49m
�[38;5;244mE/flutter (12540): #22     _rootRun (dart:async/zone.dart:1182:47)�[39;49m
�[38;5;244mE/flutter (12540): #23     _CustomZone.run (dart:async/zone.dart:1093:19)�[39;49m
�[38;5;244mE/flutter (12540): #24     _CustomZone.runGuarded (dart:async/zone.dart:997:7)�[39;49m
�[38;5;244mE/flutter (12540): #25     _CustomZone.bindCallbackGuarded.<anonymous closure> (dart:async/zone.dart:1037:23)�[39;49m
�[38;5;244mE/flutter (12540): #26     _rootRun (dart:async/zone.dart:1190:13)�[39;49m
�[38;5;244mE/flutter (12540): #27     _CustomZone.run (dart:async/zone.dart:1093:19)�[39;49m
�[38;5;244mE/flutter (12540): #28     _CustomZone.runGuarded (dart:async/zone.dart:997:7)�[39;49m
�[38;5;244mE/flutter (12540): #29     _CustomZone.bindCallbackGuarded.<anonymous closure> (dart:async/zone.dart:1037:23)�[39;49m
�[38;5;244mE/flutter (12540): #30     _microtaskLoop (dart:async/schedule_microtask.dart:41:21)�[39;49m
�[38;5;244mE/flutter (12540): #31     _startMicrotaskLoop (dart:async/schedule_microtask.dart:50:5)�[39;49m
E/flutter (12540):
I/flutter (12540): DioError [DioErrorType.CONNECT_TIMEOUT]: Connecting timed out [6000ms]
�[38;5;244mI/flutter (12540): #0      StreamChatClient.get�[39;49m
I/flutter (12540): <asynchronous suspension>
�[38;5;244mI/flutter (12540): #1      StreamChatClient.queryChannelsOnline�[39;49m
�[38;5;244mI/flutter (12540): #2      StreamChatClient.queryChannels�[39;49m
I/flutter (12540): <asynchronous suspension>
�[38;5;244mI/flutter (12540): #3      ChannelsBlocState.queryChannels�[39;49m
�[38;5;244mI/flutter (12540): #4      _ChannelListCoreState.loadData�[39;49m
�[38;5;244mI/flutter (12540): #5      _ChannelListCoreState.initState.<anonymous closure>�[39;49m
�[38;5;244mI/flutter (12540): #6      _rootRunUnary (dart:async/zone.dart:1198:47)�[39;49m
�[38;5;244mI/flutter (12540): #7      _CustomZone.runUnary (dart:async/zone.dart:1100:19)�[39;49m
�[38;5;244mI/flutter (12540): #8      _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005:7)�[39;49m
�[38;5;244mI/flutter (12540): #9      _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357:11)�[39;49m
�[38;5;244mI/flutter (12540): #10     _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285:7)�[39;49m
I/flutter (12540): #11     _SyncBroadcastStreamController._s
E/flutter (12540): [ERROR:flutter/lib/ui/ui_dart_state.cc(177)] Unhandled Exception: SocketException: Reading from a closed socket
�[38;5;244mE/flutter (12540): #0      _RawSecureSocket.read (dart:io/secure_socket.dart:683:7)�[39;49m
�[38;5;244mE/flutter (12540): #1      _Socket._onData (dart:io-patch/socket_patch.dart:2043:28)�[39;49m
�[38;5;244mE/flutter (12540): #2      _rootRunUnary (dart:async/zone.dart:1198:47)�[39;49m
�[38;5;244mE/flutter (12540): #3      _CustomZone.runUnary (dart:async/zone.dart:1100:19)�[39;49m
�[38;5;244mE/flutter (12540): #4      _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005:7)�[39;49m
�[38;5;244mE/flutter (12540): #5      _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357:11)�[39;49m
�[38;5;244mE/flutter (12540): #6      _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285:7)�[39;49m
�[38;5;244mE/flutter (12540): #7      _SyncStreamControllerDispatch._sendData (dart:async/stream_controller.dart:808:19)�[39;49m
�[38;5;244mE/flutter (12540): #8      _StreamController._add (dart:async/stream_controller.dart:682:7)�[39;49m
�[38;5;244mE/flutter (12540): #9      _StreamController.add (dart:async/stream_controller.dart:624:5)�[39;49m
�[38;5;244mE/flutter (12540): #10     _RawSecureSocket._sendReadEvent (dart:io/secure_socket.dart:1002:19)�[39;49m
�[38;5;244mE/flutter (12540): #11     _rootRun (dart:async/zone.dart:1182:47)�[39;49m
�[38;5;244mE/flutter (12540): #12     _CustomZone.run (dart:async/zone.dart:1093:19)�[39;49m
�[38;5;244mE/flutter (12540): #13     _CustomZone.runGuarded (dart:async/zone.dart:997:7)�[39;49m
�[38;5;244mE/flutter (12540): #14     _CustomZone.bindCallbackGuarded.<anonymous closure> (dart:async/zone.dart:1037:23)�[39;49m
�[38;5;244mE/flutter (12540): #15     _rootRun (dart:async/zone.dart:1190:13)�[39;49m
�[38;5;244mE/flutter (12540): #16     _CustomZone.run (dart:async/zone.dart:1093:19)�[39;49m
�[38;5;244mE/flutter (12540): #17     _CustomZone.bindCallback.<anonymous closure> (dart:async/zone.dart:1021:23)�[39;49m
�[38;5;244mE/flutter (12540): #18     Timer._createTimer.<anonymous closure> (dart:async-patch/timer_patch.dart:18:15)�[39;49m
�[38;5;244mE/flutter (12540): #19     _Timer._runTimers (dart:isolate-patch/timer_impl.dart:397:19)�[39;49m
�[38;5;244mE/flutter (12540): #20     _Timer._handleMessage (dart:isolate-patch/timer_impl.dart:428:5)�[39;49m
�[38;5;244mE/flutter (12540): #21     _RawReceivePortImpl._handleMessage (dart:isolate-patch/isolate_patch.dart:168:12)�[39;49m
E/flutter (12540):
I/flutter (12540): DioError [DioErrorType.CONNECT_TIMEOUT]: Connecting timed out [6000ms]
I/flutter (12540): DioError [DioErrorType.CONNECT_TIMEOUT]: Connecting timed out [6000ms]
I/o.lessgo.lessg(12540): Background young concurrent copying GC freed 58465(2653KB) AllocSpace objects, 86(2228KB) LOS objects, 48% free, 5252KB/10188KB, paused 5.520ms total 12.531ms
D/SharedPreferencesImpl(12540): Time required to fsync /data/user/0/co.lessgo.lessgo/shared_prefs/SHAKE_PREFS_NAME.xml: [<1: 0, <2: 202, <4: 1347, <8: 91, <16: 404, <32: 3, <64: 1, <128: 0, <256: 0, <512: 0, <1024: 0, <2048: 0, <4096: 0, <8192: 0, <16384: 0, >=16384: 0]
I/flutter (12540): Instance of 'ClientState'
I/flutter (12540): Bad state: No element
I/flutter (12540): Instance of 'ClientState'
I/flutter (12540): Bad state: No element
I/flutter (12540): Instance of 'ClientState'
I/flutter (12540): Bad state: No element
I/flutter (12540): (2021-04-23 20:57:09.926141) 🚨 🔌 error connecting
I/flutter (12540): (2021-04-23 20:57:09.926307) 🚨 🔌 WebSocketChannelException: WebSocketChannelException: HandshakeException: Connection terminated during handshake
�[38;5;244mI/flutter (12540): (2021-04-23 20:57:09.926615) 🚨 🔌 #0      new IOWebSocketChannel._withoutSocket.<anonymous closure>�[39;49m
�[38;5;244mI/flutter (12540): #1      _invokeErrorHandler (dart:async/async_error.dart:16:24)�[39;49m
�[38;5;244mI/flutter (12540): #2      _HandleErrorStream._handleError (dart:async/stream_pipe.dart:282:9)�[39;49m
�[38;5;244mI/flutter (12540): #3      _ForwardingStreamSubscription._handleError (dart:async/stream_pipe.dart:161:13)�[39;49m
�[38;5;244mI/flutter (12540): #4      _rootRunBinary (dart:async/zone.dart:1214:47)�[39;49m
�[38;5;244mI/flutter (12540): #5      _CustomZone.runBinary (dart:async/zone.dart:1107:19)�[39;49m
�[38;5;244mI/flutter (12540): #6      _CustomZone.runBinaryGuarded (dart:async/zone.dart:1013:7)�[39;49m
�[38;5;244mI/flutter (12540): #7      _BufferingStreamSubscription._sendError.sendError (dart:async/stream_impl.dart:376:15)�[39;49m
�[38;5;244mI/flutter (12540): #8      _BufferingStreamSubscription._sendError (dart:async/stream_impl.dart:394:16)�[39;49m
�[38;5;244mI/flutter (12540): #9      _BufferingStreamSubscription._addError (dart:async/stream_impl.dart:294:7)�[39;49m
�[38;5;244mI/flutter (12540): #10     _SyncStreamControllerDispatch._sendError (dart:async/stream_controller.dart:812:19)�[39;49m
�[38;5;244mI/flutter (12540): #11     _StreamController._addError (dart:async/stream_controller.dart:690:7)�[39;49m
�[38;5;244mI/flutter (12540): #12     _rootRunBinary (dart:asy�[39;49m
I/flutter (12540): (2021-04-23 20:57:09.928087) ℹ️ 📡 handle new event: {type: connection.changed, cid: null, channel_id: null, channel_type: null, connection_id: null, created_at: null, me: null, user: null, message: null, channel: null, member: null, reaction: null, total_unread_count: null, unread_channels: null, online: false, parent_id: null, is_local: true}
I/flutter (12540): (2021-04-23 20:57:09.930192) 🚨 📡 error connecting ws
�[38;5;244mI/flutter (12540): #0      new IOWebSocketChannel._withoutSocket.<anonymous closure>�[39;49m
�[38;5;244mI/flutter (12540): #1      _invokeErrorHandler (dart:async/async_error.dart:16:24)�[39;49m
�[38;5;244mI/flutter (12540): #2      _HandleErrorStream._handleError (dart:async/stream_pipe.dart:282:9)�[39;49m
�[38;5;244mI/flutter (12540): #3      _ForwardingStreamSubscription._handleError (dart:async/stream_pipe.dart:161:13)�[39;49m
�[38;5;244mI/flutter (12540): #4      _rootRunBinary (dart:async/zone.dart:1214:47)�[39;49m
�[38;5;244mI/flutter (12540): #5      _CustomZone.runBinary (dart:async/zone.dart:1107:19)�[39;49m
�[38;5;244mI/flutter (12540): #6      _CustomZone.runBinaryGuarded (dart:async/zone.dart:1013:7)�[39;49m
�[38;5;244mI/flutter (12540): #7      _BufferingStreamSubscription._sendError.sendError (dart:async/stream_impl.dart:376:15)�[39;49m
�[38;5;244mI/flutter (12540): #8      _BufferingStreamSubscription._sendError (dart:async/stream_impl.dart:394:16)�[39;49m
�[38;5;244mI/flutter (12540): #9      _BufferingStreamSubscription._addError (dart:async/stream_impl.dart:294:7)�[39;49m
�[38;5;244mI/flutter (12540): #10     _SyncStreamControllerDispatch._sendError (dart:async/stream_controller.dart:812:19)�[39;49m
�[38;5;244mI/flutter (12540): #11     _StreamController._addError (dart:async/stream_controller.dart:690:7)�[39;49m
�[38;5;244mI/flutter (12540): #12     _rootRunBinary (dart:async/zone.dart:1214:47)�[39;49m
I/flutter (12540): #13     _CustomZo
I/flutter (12540): (2021-04-23 20:57:09.931506) ℹ️ 🔌 connection closed | closeCode: null | closedReason: null
I/flutter (12540): (2021-04-23 20:57:09.931652) ℹ️ 🔌 reconnect
I/flutter (12540): (2021-04-23 20:57:09.931740) ℹ️ 🔌 reconnecting..
I/flutter (12540): (2021-04-23 20:57:09.931813) ℹ️ 🔌 connecting to wss://chat-us-east-1.stream-io-api.com/connect?api_key=f2f7btr66dgr&authorization=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ1c2VyX2lkIjoiT0lhcFpsa0I4UWNYSW9KandRUTRaQms0YUtqMiJ9.KhSU_rkjejEz2PDacyx6UiEHSlgEKlnYHvw5pdQsmSA&stream-auth-type=jwt&X-Stream-Client=stream-chat-dart-client-android-1.5.0&json=%7B%22user_id%22%3A%22OIapZlkB8QcXIoJjwQQ4ZBk4aKj2%22%2C%22server_determines_connection_id%22%3Atrue%2C%22user_details%22%3A%7B%22id%22%3A%22OIapZlkB8QcXIoJjwQQ4ZBk4aKj2%22%2C%22roles%22%3A%5B%5D%2C%22invisible%22%3Afalse%2C%22unread_count%22%3A11%2C%22language%22%3A%22%22%2C%22publicId%22%3A%22anne%22%2C%22teamChatMember%22%3Afalse%2C%22firstName%22%3A%22Anne%22%2C%22image%22%3A%22https%3A%2F%2Fstorage.googleapis.com%2Fprofilepictures.dev.lessgo.co%2FOIapZlkB8QcXIoJjwQQ4ZBk4aKj2%2F1RU7dbu5_320x320.jpg%22%2C%22name%22%3A%22Anne+Lingard%22%7D%7D
I/flutter (12540): (2021-04-23 20:57:09.933676) ℹ️ 📡 handle new event: {type: connection.changed, cid: null, channel_id: null, channel_type: null, connection_id: null, created_at: null, me: null, user: null, message: null, channel: null, member: null, reaction: null, total_unread_count: null, unread_channels: null, online: false, parent_id: null, is_local: true}
I/flutter (12540): (2021-04-23 20:57:09.934914) 🚨 🔌 WebSocketChannelException: WebSocketChannelException: HandshakeException: Connection terminated during handshake
I/flutter (12540): (2021-04-23 20:57:09.936813) ℹ️ 📡 handle new event: {type: connection.changed, cid: null, channel_id: null, channel_type: null, connection_id: null, created_at: null, me: null, user: null, message: null, channel: null, member: null, reaction: null, total_unread_count: null, unread_channels: null, online: false, parent_id: null, is_local: true}

@imtoori
Copy link
Contributor

imtoori commented Apr 26, 2021

Reconnection should be automatic, we have a retry logic just for that. I'd ask you to wait for the nndb migration to be completed so you can use the very last version.

About DioErrors, we are planning to refactor how we handle this kind of errors and wrap them in a custom type

@rubenvereecken
Copy link
Author

Alright so we'll put our own user-initiated retry logic on DioErrors. The chat needs to be able to service 1000s of users so may need to put our retry on your WebSocket exceptions ourselves, or is there a rough ETA on the nddb migration yet?

@imtoori
Copy link
Contributor

imtoori commented Apr 26, 2021

can you give me a quick way to reproduce this bug? I'll try doing it and come back to you with more details
btw the migration is almost complete, we'll release a nnbd version this week probably

@rubenvereecken
Copy link
Author

Not really. It happens sometimes on client.setUser. Try it with a poor/no connection maybe?

@rayliverified
Copy link

I can verify that this issue happens and is persistent.
My colleague on iOS experienced an issue with consistent 1 minute loading times.

On a slow connections, I receive a DioError timeout (6000ms)

@rubenvereecken
Copy link
Author

Can we get WebSocketChannelExceptions handled by Stream, at least those caused on setUser? This is very much startup code and it's a real pain to have to write retry logic ourselves, especially because it's unlikely any API consumer will choose not to retry it. It also shouldn't be too hard to find the origin of these.

I'm fine with writing retry logic for other methods like queryChannels.

@imtoori
Copy link
Contributor

imtoori commented Apr 28, 2021

Can you try if changing the connect/receive timeout when instantiating the client does anything?

@rubenvereecken
Copy link
Author

@imtoori But.. That won't actually prevent errors. What you need is a catch-all with some infinite retry logic wrapped around it. Except if you don't want to retry if there's no connection at all (to save battery), that's up to you.

I saw somewhere you already have a back-off strategy implemented.

@imtoori
Copy link
Contributor

imtoori commented Apr 28, 2021

yeah we have that, I need to check how that works for the first time connect call
because I think we should still throw an error if the user can't connect due to some API call errors (wrong token or something like this)
I'm working on this btw, I'll have more info soon

@rubenvereecken
Copy link
Author

Brilliant.

Just to add, we catch quite a few DioErrors in our start-up, some we retry, others are worse (like you said bad tokens for example). A lot of them are of type error.type == DioErrorType.DEFAULT. Checking for specific exceptions that occurred in Dio's layer we do for example with

if (error is DioError && error.error is SocketException) {
  // ...
}

Some other notable but rare connection errors of type DEFAULT:

  • HttpException
  • HandshakeException

@imtoori
Copy link
Contributor

imtoori commented Apr 28, 2021

yeah in other API calls, for example in client.sendMessage, when there is an error we check if it's an error of type DioErrorType.RESPONSE before adding the message to the retry queue.

Maybe it's not clear, but DioErrors are not related to the websocket connection anyway, that's all another different logic

@imtoori
Copy link
Contributor

imtoori commented Apr 28, 2021

Also, this error seems to be due to some null safety issue, right?

@rubenvereecken
Copy link
Author

Also, this error seems to be due to some null safety issue, right?

I'm.. not sure. My colleague said he gathered some more evidence, he'll post it soon. He did say when the client isn't initialised something becomes null inside the Stream SDK.

Maybe it's not clear, but DioErrors are not related to the websocket connection anyway, that's all another different logic

You're absolutely right, I was thinking of API errors etc which would go through Dio.

@imtoori
Copy link
Contributor

imtoori commented Apr 28, 2021

I'm.. not sure. My colleague said he gathered some more evidence, he'll post it soon. He did say when the client isn't initialised something becomes null inside the Stream SDK.

thanks I'm sure this will help
but I'm still thinking this is due to null safety since this is an error I saw while migrating the sdk
btw, we should be able to release a beta version fully migrated very soon

@Siqlain-Hanif
Copy link

Siqlain-Hanif commented Apr 28, 2021

Current version we are using 1.3.2-beta

So we are trying to open up the chat from the notification which carries the cid.
We first resolve the channel based on the cid using queryChannels, what happens is the websocketconnection is in the
connecting state that makes the queryChannels not yield anything and fails the resolution of channel.
So every time we present the user to retry. Here is the problem some of the time on retyring it resolves the channel and sometimes it just give me the CONNECT_TIMEOUT errors.

CONNECT_TIMEOUT Error

W/JavaBinder( 3736): BinderProxy is being destroyed but the application did not call unlinkToDeath to unlink all of its death recipients beforehand. Releasing leaked death recipient: com.google.android.play.core.internal.ai
D/EGL_emulation( 3736): eglMakeCurrent: 0xdf5e5920: ver 2 0 (tinfo 0xdf69dc10)
D/eglCodecCommon( 3736): setVertexArrayObject: set vao to 0 (0) 17 0
E/flutter ( 3736): [ERROR:flutter/lib/ui/ui_dart_state.cc(177)] Unhandled Exception: DioError [DioErrorType.CONNECT_TIMEOUT]: Connecting timed out [15000ms]
�[38;5;244mE/flutter ( 3736): #0 StreamChatClient.get�[39;49m
E/flutter ( 3736):
�[38;5;244mE/flutter ( 3736): #1 StreamChatClient.queryChannelsOnline�[39;49m
�[38;5;244mE/flutter ( 3736): #2 StreamChatClient.connect.�[39;49m
�[38;5;244mE/flutter ( 3736): #3 StreamChatClient.connect.�[39;49m
�[38;5;244mE/flutter ( 3736): #4 _rootRunUnary (dart:async/zone.dart:1198:47)�[39;49m
�[38;5;244mE/flutter ( 3736): #5 _CustomZone.runUnary (dart:async/zone.dart:1100:19)�[39;49m
�[38;5;244mE/flutter ( 3736): #6 _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005:7)�[39;49m
�[38;5;244mE/flutter ( 3736): #7 _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357:11)�[39;49m
�[38;5;244mE/flutter ( 3736): #8 _BufferingStreamSubscription._add (dart:async/stream_impl.dart:285:7)�[39;49m
�[38;5;244mE/flutter ( 3736): #9 _SyncBroadcastStreamController._sendData (dart:async/broadcast_stream_controller.dart:385:25)�[39;49m
�[38;5;244mE/flutter ( 3736): #10 _BroadcastStreamController.add (dart:async/broadcast_stream_controller.dart:250:5)�[39;49m
�[38;5;244mE/flutter ( 3736): #11 _StartWithStreamSink.add�[39;49m
�[38;5;244mE/flutter ( 3736): #12 forwardStream...�[39;49m
�[38;5;244mE/flutter ( 3736): #13 forwardStream.runCatching�[39;49m
�[38;5;244mE/flutter ( 3736): #14 forwardStream..�[39;49m
�[38;5;244mE/flutter ( 3736): #15 _rootRunUnary (dart:async/zone.dart:1198:47)�[39;49m
�[38;5;244mE/flutter ( 3736): #16 _CustomZone.runUnary (dart:async/zone.dart:1100:19)�[39;49m
�[38;5;244mE/flutter ( 3736): #17 _CustomZone.runUnaryGuarded (dart:async/zone.dart:1005:7)�[39;49m
�[38;5;244mE/flutter ( 3736): #18 _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:357:11)�[39;49m
�[38;5;244mE/flutter ( 3736): #19 _DelayedData.perform (dart:async/stream_impl.dart:611:14)�[39;49m
�[38;5;244mE/flutter ( 3736): #20 _StreamImplEvents.handleNext (dart:async/stream_impl.dart:730:11)�[39;49m
�[38;5;244mE/flutter ( 3736): #21 _PendingEvents.schedule. (dart:async/stream_impl.dart:687:7)�[39;49m
�[38;5;244mE/flutter ( 3736): #22 _rootRun (dart:async/zone.dart:1182:47)�[39;49m
�[38;5;244mE/flutter ( 3736): #23 _CustomZone.run (dart:async/zone.dart:1093:19)�[39;49m
�[38;5;244mE/flutter ( 3736): #24 _CustomZone.runGuarded (dart:async/zone.dart:997:7)�[39;49m
�[38;5;244mE/flutter ( 3736): #25 _CustomZone.bindCallbackGuarded. (dart:async/zone.dart:1037:23)�[39;49m
�[38;5;244mE/flutter ( 3736): #26 _rootRun (dart:async/zone.dart:1190:13)�[39;49m
�[38;5;244mE/flutter ( 3736): #27 _CustomZone.run (dart:async/zone.dart:1093:19)�[39;49m
�[38;5;244mE/flutter ( 3736): #28 _CustomZone.runGuarded (dart:async/zone.dart:997:7)�[39;49m
�[38;5;244mE/flutter ( 3736): #29 _CustomZone.bindCallbackGuarded. (dart:async/zone.dart:1037:23)�[39;49m
�[38;5;244mE/flutter ( 3736): #30 _microtaskLoop (dart:async/schedule_microtask.dart:41:21)�[39;49m
�[38;5;244mE/flutter ( 3736): #31 _startMicrotaskLoop (dart:async/schedule_microtask.dart:50:5)�[39;49m
E/flutter ( 3736):
I/flutter ( 3736): Retry? true -> DioError [DioErrorType.CONNECT_TIMEOUT]: Connecting timed out [15000ms] (GET https://dev.lessgo.co/api/v1/meetups/6081715b0343124b50327256)
I/flutter ( 3736): Retry? true -> DioError [DioErrorType.CONNECT_TIMEOUT]: Connecting timed out [15000ms] (GET https://dev.lessgo.co/api/v1/meetups/608171630343124b5032725c)
I/flutter ( 3736): Retry? true -> DioError [DioErrorType.CONNECT_TIMEOUT]: Connecting timed out [15000ms] (GET https://dev.lessgo.co/api/v1/meetups/6081715b0343124b50327256)
I/flutter ( 3736): Retry? true -> DioError [DioErrorType.CONNECT_TIMEOUT]: Connecting timed out [15000ms] (GET https://dev.lessgo.co/api/v1/meetups/608171630343124b5032725c)
I/flutter ( 3736): Retry? true -> DioError [DioErrorType.CONNECT_TIMEOUT]: Connecting timed out [15000ms] (GET https://dev.lessgo.co/api/v1/meetups/6081715b0343124b50327256)

Followed by this

I/flutter ( 3736): (2021-04-28 17:36:26.565530) 🚨 🔌 error connecting
I/flutter ( 3736): (2021-04-28 17:36:26.566381) 🚨 🔌 WebSocketChannelException: WebSocketChannelException: HandshakeException: Connection terminated during handshake
I/flutter ( 3736): (2021-04-28 17:36:26.566699) 🚨 🔌 #0 new IOWebSocketChannel._withoutSocket.
package:web_socket_channel/io.dart:84
I/flutter ( 3736): #1 _invokeErrorHandler (dart:async/async_error.dart:16:24)
I/flutter ( 3736): #2 _HandleErrorStream._handleError (dart:async/stream_pipe.dart:282:9)
I/flutter ( 3736): #3 _ForwardingStreamSubscription._handleError (dart:async/stream_pipe.dart:161:13)
I/flutter ( 3736): #4 _rootRunBinary (dart:async/zone.dart:1214:47)
I/flutter ( 3736): #5 _CustomZone.runBinary (dart:async/zone.dart:1107:19)
I/flutter ( 3736): #6 _CustomZone.runBinaryGuarded (dart:async/zone.dart:1013:7)
I/flutter ( 3736): #7 _BufferingStreamSubscription._sendError.sendError (dart:async/stream_impl.dart:376:15)
I/flutter ( 3736): #8 _BufferingStreamSubscription._sendError (dart:async/stream_impl.dart:394:16)
I/flutter ( 3736): #9 _BufferingStreamSubscription._addError (dart:async/stream_impl.dart:294:7)
I/flutter ( 3736): #10 _SyncStreamControllerDispatch._sendError (dart:async/stream_controller.dart:812:19)
I/flutter ( 3736): #11 _StreamController._addError (dart:async/stream_controller.dart:690:7)
I/flutter ( 3736): #12 _rootRunBinary (dart:asy
I/flutter ( 3736): (2021-04-28 17:36:26.567406) 🚨 📡 error connecting ws
I/flutter ( 3736): #0 new IOWebSocketChannel._withoutSocket.
package:web_socket_channel/io.dart:84
I/flutter ( 3736): #1 _invokeErrorHandler (dart:async/async_error.dart:16:24)
I/flutter ( 3736): #2 _HandleErrorStream._handleError (dart:async/stream_pipe.dart:282:9)
I/flutter ( 3736): #3 _ForwardingStreamSubscription._handleError (dart:async/stream_pipe.dart:161:13)
I/flutter ( 3736): #4 _rootRunBinary (dart:async/zone.dart:1214:47)
I/flutter ( 3736): #5 _CustomZone.runBinary (dart:async/zone.dart:1107:19)
I/flutter ( 3736): #6 _CustomZone.runBinaryGuarded (dart:async/zone.dart:1013:7)
I/flutter ( 3736): #7 _BufferingStreamSubscription._sendError.sendError (dart:async/stream_impl.dart:376:15)
I/flutter ( 3736): #8 _BufferingStreamSubscription._sendError (dart:async/stream_impl.dart:394:16)
I/flutter ( 3736): #9 _BufferingStreamSubscription._addError (dart:async/stream_impl.dart:294:7)
I/flutter ( 3736): #10 _SyncStreamControllerDispatch._sendError (dart:async/stream_controller.dart:812:19)
I/flutter ( 3736): #11 _StreamController._addError (dart:async/stream_controller.dart:690:7)
I/flutter ( 3736): #12 _rootRunBinary (dart:async/zone.dart:1214:47)
I/flutter ( 3736): #13 _CustomZo
I/flutter ( 3736): (2021-04-28 17:36:26.571651) 🚨 🔌 WebSocketChannelException: WebSocketChannelException: HandshakeException: Connection terminated during handshake
D/SharedPreferencesImpl( 3736): Time required to fsync /data/user/0/co.lessgo.lessgo/shared_prefs/SHAKE_PREFS_NAME.xml: [<1: 0, <2: 92, <4: 713, <8: 50, <16: 166, <32: 3, <64: 0, <128: 0, <256: 0, <512: 0, <1024: 0, <2048: 0, <4096: 0, <8192: 0, <16384: 0, >=16384: 0]

Every other part of my application is working fine where I am resolving something from the server which means i had an active internet connection when that error occured.

Note:
Previously on version 0.2.10 it was an "awaited get" that resolves and then you yield so we get the valid response.

@rubenvereecken @imtoori

@imtoori
Copy link
Contributor

imtoori commented Apr 28, 2021

I can give you some advice that may help you while I try to understand how to help you better:

  • always await the client.connectUser calls before doing anything else
  • avoid using queryChannels if not needed. In this case, It would be better to instantiate the channel using something like this
  final splits = cid.split(':');
  final channel = client.channel(
    splits[0],
    id: splits[1],
  );

  await channel.query();

@Siqlain-Hanif
Copy link

  • connectUser call is awaited so no issue there.
  • The second one I will try this and let you know whether it fixes it or not

@Siqlain-Hanif
Copy link

The above snippet works real well for resolving the channel from notification.

@rayliverified
Copy link

rayliverified commented May 3, 2021

How is Stream able to claim <100ms message times when connecting the user and querying channels consistently fails (+6000ms)?
What is being done to resolve the issue and is it even fixable because it looks like the backend is taking a long time to respond.

This issue has delayed our rollout of chat and is giving users an unacceptable experience.

@imtoori
Copy link
Contributor

imtoori commented May 3, 2021

we just released a 2.0.0-nullsafety.0 version of the package that should solve this issue
I'm closing it, feel free to reopen it if the problem persists

@searchy2 I think your problem is not the same as this one.
Can you contact support so that we can chat sharing your app details so we can solve it as soon as possible?

@imtoori imtoori closed this as completed May 3, 2021
@rayliverified
Copy link

Can you look into the backend and run a trace for all the requests on our account that took over 6 seconds to connect and update us on what the issue is there?

@imtoori
Copy link
Contributor

imtoori commented May 4, 2021

In the latest version there is a small fix that improves the connection time client side
Can you contact support for this? Thanks

@rubenvereecken
Copy link
Author

Now I'm a bit worried too, @imtoori improving connection time can still cause time-outs.

I'd like to revisit my original question

If this can't be resolved because it's some odd fluke and it might happen from time to time, we still want to be able to deal with it. Would it be possible to document/explain which calls are expected to throw, and what we can catch? For example, if setUser is expected to throw, we most definitely want to catch it and put some retry logic around it, if indeed it's retryable.

In short: What throws, literally ever, what doesn't?

@imtoori
Copy link
Contributor

imtoori commented May 4, 2021

I want to stress the fact that the original issue:

┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄┄
2021-04-20 17:51:15.920 11917-12113/? I/flutter: │ 🐛 Setting chat user wF6n9VTqeFbKVQGIaYaxloAGINH3 - Ruben
2021-04-20 17:51:15.920 11917-12113/? I/flutter: └───────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
2021-04-20 17:51:17.161 11917-12113/? E/flutter: [ERROR:flutter/lib/ui/ui_dart_state.cc(177)] Unhandled Exception: Null check operator used on a null value
#0 ChangeNotifier.notifyListeners (package:flutter/src/foundation/change_notifier.dart:218)
.....

is related to null-safety, and it was not expected at all

Regarding what throws and what doesn't:
the connectUser call might throw in case of a backend error; that's when the retry mechanism does not trigger. If the connection is not good, and the error is related to the network, the websocket retries to connect.

Now, we're working on defining a custom error class and wrap everything with that so that it's cleaner and more reliable; I'll have more details next week.

About the connection timeout: that it's not a known issue, and it should not happen. I suggest contacting support for that to solve it more quickly, knowing the details of your stream application. That's the only way we can understand if that's a backend or a client issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

5 participants