shamblett / mqtt5_client

A server and browser based MQTT 5 client for dart
Other
49 stars 25 forks source link

How to control autoConnect time? #84

Closed OpenJarvisAI closed 5 months ago

OpenJarvisAI commented 6 months ago

Currently, the autoConnect happens toooo fast.

I set onAUtoConect

 void onAutoReconnect() async {
    await Future.delayed(const Duration(seconds: 2), () {
      _crtReconnect += 1;
      _broadcastConnectionState();
      connectionState.value = ConnState.connecting;
      kLog('[onAutoReconnect] Auto Reconnect...');
      if (_crtReconnect > maxReconnect) {
        kLog("[onAutoReconnect] max reconnect get, force connect");
        _cnxBehavior.add(ConnState.connected);
      }
    });
  }

A timesleep, but it didn't work. Why and how?

shamblett commented 6 months ago

onAutoReconnect is a synchronous callback from the client, you can't asynchronously await in it. You could try increasing connectTimeoutPeriod , this would then wait the amount of time you set before trying to connect again(assuming it doesn't connect on the first try of course).

Why do you want to slow down autoreconnect? Most people want to do this as quickly as possible.

OpenJarvisAI commented 6 months ago

@shamblett thansk for the suggestion, this is part of my log:

I/flutter (14437): [KLOG] Subscribed topic: messages/afe9ea25-8188-4ad7-a8ec-547870b2b5f7
I/flutter (14437): [KLOG] Subscribed topic: events/afe9ea25-8188-4ad7-a8ec-547870b2b5f7
I/flutter (14437): [KLOG] Subscribed topic: messages/981fe011-ca02-4eac-9249-de5fcc51db45
I/flutter (14437): [KLOG] Subscribed topic: events/981fe011-ca02-4eac-9249-de5fcc51db45
I/flutter (14437): [KLOG] Subscribed topic: messages/24d64a99-1bbf-4cd8-bd87-3c7f18d5f7bb
I/flutter (14437): [KLOG] Subscribed topic: events/24d64a99-1bbf-4cd8-bd87-3c7f18d5f7bb
I/flutter (14437): [KLOG] Subscribed topic: messages/2f324986-ed2f-4ba8-a914-8a5b22bb4412
I/flutter (14437): [KLOG] Subscribed topic: events/2f324986-ed2f-4ba8-a914-8a5b22bb4412
I/flutter (14437): [KLOG] [onAutoReconnect] Auto Reconnect...
I/flutter (14437): [KLOG] [onConnected] Connected, is this connected? Instance of 'MqttServerClient', state: MqttConnectionState.connected
I/flutter (14437): [KLOG] joined Rooms from local!
I/flutter (14437): [KLOG] Subscribed topic: archivesrooms/android_client_6g6jh_usrHQ3w4bIjN7
I/flutter (14437): [KLOG] Subscribed topic: archivesmessages/android_client_6g6jh_usrHQ3w4bIjN7
I/flutter (14437): [KLOG] Subscribed topic: archivesrooms/new/android_client_6g6jh_usrHQ3w4bIjN7
I/flutter (14437): [KLOG] Subscribed topic: personalmyid/android_client_6g6jh_usrHQ3w4bIjN7
I/flutter (14437): [KLOG] [onAutoReconnect] Auto Reconnect...
I/flutter (14437): [KLOG] [onConnected] Connected, is this connected? Instance of 'MqttServerClient', state: MqttConnectionState.connecting
I/flutter (14437): [KLOG] joined Rooms from local!
I/flutter (14437): [KLOG] Subscribed topic: archivesrooms/android_client_6g6jh_usrHQ3w4bIjN7
I/flutter (14437): [KLOG] Subscribed topic: archivesmessages/android_client_6g6jh_usrHQ3w4bIjN7

I am not stuck by this problem: It will connected and still autoReconnect will call. I don't want disable auto reconnect.

From the log, I didn't say any onDisconnected log, it just connected and then autoReconnect will call.

then, it will run forever repeatly and never connected, except I kill the flutter app and reenter.

This happens only when the network switch or I close network and reopen.

I still don't know why.

One of reason on my mind, is autoReconnect too fast, it didn't wait the ConnectionState change to connected and reconnect imediately, or it mgith has conflict with server, I am really not sure.

OnDisconnect didnt print anything here..

shamblett commented 6 months ago

onDisconnected isn't called if you are using auto reconnect, from the client API spec -

/// Client disconnect callback, called on unsolicited disconnect.
  /// This will not be called even if set if [autoReconnect} is set,instead
  /// [AutoReconnectCallback] will be called.
  DisconnectCallback? onDisconnected;

You are expecting the client to do more than it can, the client reacts to events from the underlying flutter/dart runtime, if the runtime does not generate those events the client can't react to them. If the runtime just reports failed to connect when the network is switched etc. then so be it, the client will just try and reconnect, if a socket error is reported however the client will react differently.

In my experience what the Dart VM or flutter runtime reports when network cables are pulled, networks switch etc. varies from platform to platform. Some users monitor for these events separately and control the client that way rather than expecting the client to always know whats going on. You can also use keepalive and the pong callback in some cases to better detect if your broker is alive or not.

OpenJarvisAI commented 6 months ago

@shamblett Then it seems reasonable.

Because am using a self-maintained connState varaible to maintain the connect state, and only when onDisConnected called would change this state into disconnect.

So, looks like my isConnected() were wrong previous, makes the client didn't connected, but I thought it was.

But it introduce another question, how to listen the state properly if with autoConnect?

In autoConnect, how to check the client is connected or not?

shamblett commented 6 months ago

From the API docs -

 /// Auto reconnected callback, if auto reconnect is selected this callback will
  /// be called after auto reconnect processing is completed to allow the user to
  /// perform any post auto reconnect actions.
  AutoReconnectCompleteCallback? onAutoReconnected;

When you get this callback the connection state will be connected, until then if auto reconnect is running you can assume you are not connected.

OpenJarvisAI commented 6 months ago

I have tried everything but it still not work properly.

My situation is:

when app goes to background, and return back (my apps won't exist, it just back to home screen so that apps re-open won't re run whole app). The thing is the app should be killed by system as Android won't keep apps in background forever, but the first page keeps same page when I return back to app from home.

So here is the thing: the MQTT connection I don't know it is lost or not, but the _client!.connectionStatus!.state == MqttConnectionState.connected; gives me false, so I reconnect it:

a. if I enable auto reconnect, it will has some chance connected and imediately disconnected and repeat this forever; b. if I disable auto reconnect, if have a logic manually reconnect it simple calling _client.connect with same clientId always, but it also will connected first, and then disconnencted, then it will falls to my onDisconnected callback, and at there I manually connect, then everything would be fine.

But for option b, it have a lot of chance, lost messages.......

Either way seems abnomarml in my opinion...

It should automatically connect and won't disconnect again ....

shamblett commented 6 months ago

You need to examine your broker logs to see why it is accepting your connection then disconnecting you, the client cant help.you any more with this.

I doubt its your client id as if the brokler thought there was something wrong here it wouldnt accept your connection in the first place.

Even in the case where you never connect you need the brolker logs to tell you if the broker could even see your connection attempts at the time.

OpenJarvisAI commented 6 months ago

@shamblett this is my opinion:

How do u think?

I previuos logged server logs, and it just keeping says: clientId connection already exist.... and repeat forever, same as client, the repeating won't happen except autoconnect close, so there must be a disagreement between server and client.

OpenJarvisAI commented 6 months ago
4-02-07T17:07:11.066+08:00 level=INFO msg="--> client connected [auth]" hook=my-auth-hook client=android_client_6g6jh_usrHQ3w4bIjN7
INFO[880882] >>>>>[v2] login, username: 15x1xxx23x0, client: android_client_6g6jh_usrHQ3w4bIjN7
INFO[880882] ------> publish IdArchives: archivesmyid/android_client_6g6jh_usrHQ3w4bIjN7
time=2024-02-07T17:07:11.072+08:00 level=INFO msg="--> received from inline client " hook=my-hook topic=archivesmyid/android_client_6g6jh_usrHQ3w4bIjN7
time=2024-02-07T17:07:11.072+08:00 level=INFO msg="--> published to inline client" hook=my-hook
time=2024-02-07T17:07:11.072+08:00 level=INFO msg="--> client disconnected" hook=my-hook client=android_client_6g6jh_usrHQ3w4bIjN7 expire=false error="read tcp 172.18.171.245:1883->113.89.10.97:44377: use of closed network connection"
time=2024-02-07T17:07:11.073+08:00 level=WARN msg="" listener=t1 error="read tcp 172.18.171.245:1883->113.89.10.97:44377: use of closed network connection"
time=2024-02-07T17:07:11.083+08:00 level=INFO msg="subscribed qos=[1]" hook=my-hook client=android_client_6g6jh_usrHQ3w4bIjN7 filters="[{ShareName:[] Filter:archivesrooms/android_client_6g6jh_usrHQ3w4bIjN7 Identifier:0 Identifiers:map[] RetainHandling:0 Qos:1 RetainAsPublished:true NoLocal:false FwdRetainedFlag:false}]"
time=2024-02-07T17:07:11.092+08:00 level=INFO msg="subscribed qos=[1]" hook=my-hook client=android_client_6g6jh_usrHQ3w4bIjN7 filters="[{ShareName:[] Filter:archivesmessages/android_client_6g6jh_usrHQ3w4bIjN7 Identifier:0 Identifiers:map[] RetainHandling:0 Qos:1 RetainAsPublished:true NoLocal:false FwdRetainedFlag:false}]"
time=2024-02-07T17:07:11.092+08:00 level=INFO msg="subscribed qos=[1]" hook=my-hook client=android_client_6g6jh_usrHQ3w4bIjN7 filters="[{ShareName:[] Filter:archivesrooms/new/android_client_6g6jh_usrHQ3w4bIjN7 Identifier:0 Identifiers:map[] RetainHandling:0 Qos:1 RetainAsPublished:true NoLocal:false FwdRetainedFlag:false}]"
time=2024-02-07T17:07:11.092+08:00 level=INFO msg="subscribed qos=[1]" hook=my-hook client=android_client_6g6jh_usrHQ3w4bIjN7 filters="[{ShareName:[] Filter:personalmyid/android_client_6g6jh_usrHQ3w4bIjN7 Identifier:0 Identifiers:map[] RetainHandling:0 Qos:1 RetainAsPublished:true NoLocal:false FwdRetainedFlag:false}]"
time=2024-02-07T17:07:11.101+08:00 level=INFO msg="--> client connected" hook=my-hook client=android_client_6g6jh_usrHQ3w4bIjN7
time=2024-02-07T17:07:11.101+08:00 level=INFO msg="--> client connected [auth]" hook=my-auth-hook client=android_client_6g6jh_usrHQ3w4bIjN7
INFO[880882] >>>>>[v2] login, username: 15116123160, client: android_client_6g6jh_usrHQ3w4bIjN7
INFO[880882] ------> publish IdArchives: archivesmyid/android_client_6g6jh_usrHQ3w4bIjN7
time=2024-02-07T17:07:11.107+08:00 level=INFO msg="--> received from inline client " hook=my-hook topic=archivesmyid/android_client_6g6jh_usrHQ3w4bIjN7
time=2024-02-07T17:07:11.107+08:00 level=INFO msg="--> published to inline client" hook=my-hook
time=2024-02-07T17:07:11.108+08:00 level=INFO msg="--> client disconnected" hook=my-hook client=android_client_6g6jh_usrHQ3w4bIjN7 expire=false error="read tcp 172.18.171.245:1883->113.89.10.97:44378: use of closed network connection"
time=2024-02-07T17:07:11.108+08:00 level=WARN msg="" listener=t1 error="read tcp 172.18.171.245:1883->113.89.10.97:44378: use of closed network connection"

I just take a deep dive into servers log, here is the clue.

Can u help me a little bit about this issue. the server clearly says:

It was disconnected due to use a close network connectionn , and this happens repeatly fast....

shamblett commented 6 months ago

Yes Ok, looks as though the network connection the client is using has been closed so the broker is not accepting the connection. The client is not getting an on error event or socket exception to tell it the socket is closed, so it keeps trying to connect. As I said above if the runtime doesn't tell the client what is going on then it won't know.

The only safe thing to do is monitor for network down/change at the platform level, i.e. use whatever indication your platform gives you for this and disconnect the client, wait for a network up indication and reconnect the client. Do not use autoreconnect or it will get stuck as you have seen.

As I've also said above you can use the keepalive mechanism and the pong call back to monitor the health of your broker, this will protect against the broker not responding, whether this is for a network event or not, then you can manually disconnect etc.

OpenJarvisAI commented 6 months ago

I think I now found the reason.... it is my fault maybe, wait to make sure it.