MQTTnet DisconnectInternalAsync keep waiting and doesn't end

Describe the bug

The inner task TrySendKeepAliveMessagesAsync Get Timeout Exception and then disconnect keep running that program can't do any other operations.

Which project is your bug related to?

Client

To Reproduce

Steps to reproduce the behavior:

Using this version of MQTTnet 3.0.2
Program is busy running

Expected behavior

Disconnect should finish it's own and tell the disconnect handler

Screenshots

the mqttnetLog shown like this, it nerver go to the finalize block 'disconneted'. I had wait ten minutes but no more logs , The program try client.SubscribeAsync but does not work :

2020-04-27 09:44:25.7520|Hrst.AIDetect.WebApiServer.MqttJobHandler|INFO|<mqttNetLog>[2020-04-27T01:44:25.7519515Z] [] [24] [MqttClient.MqttChannelAdapter] [Verbose]: RX (91 bytes) <<< Publish: [Topic=Work/abc123] [Payload.Length=76] [QoSLevel=AtMostOnce] [Dup=False] [Retain=False] [PacketIdentifier=]| 2020-04-27 09:44:25.7520|Hrst.AIDetect.WebApiServer.MqttJobHandler|INFO|Receive the topic:Work/abc123,{"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}}| 2020-04-27 09:44:33.4840|Hrst.AIDetect.WebApiServer.MqttJobHandler|INFO|<mqttNetLog>[2020-04-27T01:44:33.4839523Z] [] [24] [MqttClient.MqttChannelAdapter] [Verbose]: RX (91 bytes) <<< Publish: [Topic=Work/abc123] [Payload.Length=76] [QoSLevel=AtMostOnce] [Dup=False] [Retain=False] [PacketIdentifier=]| 2020-04-27 09:44:33.4840|Hrst.AIDetect.WebApiServer.MqttJobHandler|INFO|Receive the topic:Work/abc123,{"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}}| 2020-04-27 09:44:48.5917|Hrst.AIDetect.WebApiServer.MqttJobHandler|INFO|<mqttNetLog>[2020-04-27T01:44:48.5916000Z] [] [27] [MqttClient.MqttChannelAdapter] [Verbose]: TX (2 bytes) >>> PingReq| 2020-04-27 09:45:18.5923|Hrst.AIDetect.WebApiServer.MqttJobHandler|INFO|<mqttNetLog>[2020-04-27T01:45:18.5922783Z] [] [27] [MqttClient] [Warning]: Timeout while waiting for packet of type 'MqttPingRespPacket'.| 2020-04-27 09:45:18.5959|Hrst.AIDetect.WebApiServer.MqttJobHandler|INFO|<mqttNetLog>[2020-04-27T01:45:18.5931456Z] [] [27] [MqttClient] [Warning]: MQTT communication exception while sending/receiving keep alive packets. MQTTnet.Exceptions.MqttCommunicationTimedOutException: Exception of type 'MQTTnet.Exceptions.MqttCommunicationTimedOutException' was thrown. at MQTTnet.PacketDispatcher.MqttPacketAwaiter`1.WaitOneAsync(TimeSpan timeout) at MQTTnet.Client.MqttClient.SendAndReceiveAsync[TResponsePacket](MqttBasePacket requestPacket, CancellationToken cancellationToken) at MQTTnet.Client.MqttClient.TrySendKeepAliveMessagesAsync(CancellationToken cancellationToken)| 2020-04-27 09:45:18.5992|Hrst.AIDetect.WebApiServer.MqttJobHandler|INFO|<mqttNetLog>[2020-04-27T01:45:18.5991942Z] [] [27] [MqttClient] [Verbose]: Disconnecting [Timeout=00:00:30]|

Code example

the 3.0.2 mqttClient.cs private async Task DisconnectInternalAsync(Task sender, Exception exception, MqttClientAuthenticateResult authenticateResult) { var clientWasConnected = IsConnected;

        InitiateDisconnect();

        IsConnected = false;

        try
        {
            if (_adapter != null)
            {
                _logger.Verbose("Disconnecting [Timeout={0}]", Options.CommunicationTimeout);
                await _adapter.DisconnectAsync(Options.CommunicationTimeout, CancellationToken.None).ConfigureAwait(false);
            }

            await WaitForTaskAsync(_packetReceiverTask, sender).ConfigureAwait(false);
            await WaitForTaskAsync(_keepAlivePacketsSenderTask, sender).ConfigureAwait(false);

            _logger.Verbose("Disconnected from adapter.");
        }
        catch (Exception adapterException)
        {
            _logger.Warning(adapterException, "Error while disconnecting from adapter.");
        }
        finally
        {
            Dispose();
            _cleanDisconnectInitiated = false;

            _logger.Info("Disconnected.");

            var disconnectedHandler = DisconnectedHandler;
            if (disconnectedHandler != null)
            {
                await disconnectedHandler.HandleDisconnectedAsync(new MqttClientDisconnectedEventArgs(clientWasConnected, exception, authenticateResult)).ConfigureAwait(false);
            }
        }
    }

And my ClientOption is like this: private MqttClientOptions InitOption() { var tlsOptions = new MqttClientTlsOptions { UseTls = false, IgnoreCertificateChainErrors = true, IgnoreCertificateRevocationErrors = true, AllowUntrustedCertificates = true }; var options = new MqttClientOptions { ClientId = _serverUser.ClientId, ProtocolVersion = MQTTnet.Formatter.MqttProtocolVersion.V311, ChannelOptions = new MqttClientTcpOptions { Server = _filesUrl.MqttServerIp, Port = _filesUrl.MqttServerPort, TlsOptions = tlsOptions }, Credentials = new MqttClientCredentials { Username = _serverUser.Name, Password = _mqttPwd }, CommunicationTimeout = TimeSpan.FromSeconds(30), KeepAlivePeriod = TimeSpan.FromSeconds(60), CleanSession = true, }; return options; }

Apr 27 '20 03:04 bobbydog

Hi, please try with version 3.0.9. The version you are using is too old so that I cannot give any support for it.

Best regards Christian

Apr 27 '20 07:04 chkr1011

Hi, please try with version 3.0.9. The version you are using is too old so that I cannot give any support for it.

As my coreApp runtime is 2.2.0 , It's hard to upgrade the whole project to 3.0 which mqttNet 3.0.9 and its dependency demind. Would there be any workaround ? I find I extract the loop and rebuild the client, the new client can't get PingResp if from the same mqttFactory build.

Apr 27 '20 10:04 bobbydog

@JanEggers do you know how to still support asp 2.2? Isn't there some compiler statements for that purpose?

Apr 27 '20 10:04 chkr1011

@chkr1011 it should work, maybe there is another packaging issue. i will check it.

Apr 27 '20 10:04 JanEggers

Hi, I have update my development app runtime to core 3.0 and upgrade the mqttNet to 3.0.9 . now the disconnect handler go through. but in my docker (Ubuntu 16.04.6 LTS) the keepalive disconnect still happen and rebuild client does not work. By the way the same time programme run fine (no disconnect happend ) in my win10 machine, and the mqtt broker is mosca.js in another docker container the logs: 2020-04-29 09:39:30.7112|Receive the topic:Work/000000,{"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}}| 2020-04-29 09:39:30.8492|<mqttNetLog>[2020-04-29T01:39:30.8491471Z] [] [28] [MqttChannelAdapter] [Verbose]: RX (91 bytes) <<< Publish: [Topic=Work/000000] [Payload.Length=76] [QoSLevel=AtMostOnce] [Dup=False] [Retain=False] [PacketIdentifier=]| 2020-04-29 09:39:30.8492|Receive the topic:Work/000000,{"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}}| 2020-04-29 09:39:31.4108|<mqttNetLog>[2020-04-29T01:39:31.4107823Z] [] [13] [MqttChannelAdapter] [Verbose]: TX (2 bytes) >>> PingReq| 2020-04-29 09:39:31.4166|<mqttNetLog>[2020-04-29T01:39:31.4166584Z] [] [28] [MqttClient] [Verbose]: Disconnecting [Timeout=00:00:10]|

2020-04-29 09:39:31.4166|<mqttNetLog>[2020-04-29T01:39:31.4174270Z] [] [28] [MqttClient] [Verbose]: Disconnected from adapter.| 2020-04-29 09:39:31.7260|Mqtt DoMessagesWork has a loop| 2020-04-29 09:39:41.4137|<mqttNetLog>[2020-04-29T01:39:41.4136835Z] [] [26] [MqttClient] [Warning]: Timeout while waiting for packet of type 'MqttPingRespPacket'.| 2020-04-29 09:39:41.4177|<mqttNetLog>[2020-04-29T01:39:41.4146426Z] [] [26] [MqttClient] [Warning]: Communication error while sending/receiving keep alive packets. MQTTnet.Exceptions.MqttCommunicationTimedOutException: Exception of type 'MQTTnet.Exceptions.MqttCommunicationTimedOutException' was thrown. at MQTTnet.PacketDispatcher.MqttPacketAwaiter`1.WaitOneAsync(TimeSpan timeout) at MQTTnet.Client.MqttClient.SendAndReceiveAsync[TResponsePacket](MqttBasePacket requestPacket, CancellationToken cancellationToken) at MQTTnet.Client.MqttClient.TrySendKeepAliveMessagesAsync(CancellationToken cancellationToken)| 2020-04-29 09:39:41.4177|<mqttNetLog>[2020-04-29T01:39:41.4178417Z] [] [26] [MqttClient] [Verbose]: Stopped sending keep alive packets.| 2020-04-29 09:39:41.4177|<mqttNetLog>[2020-04-29T01:39:41.4185668Z] [] [26] [MqttClient] [Info]: Disconnected.| 2020-04-29 09:39:41.4177|<mqttNetLog>[2020-04-29T01:39:41.4187934Z] [] [26] [MqttClient] [Verbose]: Stopped receiving packets.| 2020-04-29 09:39:41.4177|[AI-102ZC-ZXGLPT-V100_CLI_88] was disconnected | 2020-04-29 09:39:41.4215|<mqttNetLog>[2020-04-29T01:39:41.4215225Z] [] [28] [MqttClient] [Verbose]: Trying to connect with server '192.168.3.24:11883' (Timeout=00:00:10).| 2020-04-29 09:39:41.4215|<mqttNetLog>[2020-04-29T01:39:41.4219656Z] [] [13] [MqttClient] [Verbose]: Connection with server established.| 2020-04-29 09:39:41.4215|<mqttNetLog>[2020-04-29T01:39:41.4221919Z] [] [20] [MqttClient] [Verbose]: Start receiving packets.| 2020-04-29 09:39:41.4215|<mqttNetLog>[2020-04-29T01:39:41.4222596Z] [] [13] [MqttChannelAdapter] [Verbose]: TX (498 bytes) >>> Connect: [ClientId=AI-102ZC-ZXGLPT-V100_CLI_88] [Username=server88] [Password=****] [KeepAlivePeriod=20] [CleanSession=True]| 2020-04-29 09:39:41.4215|<mqttNetLog>[2020-04-29T01:39:41.4229370Z] [] [28] [MqttChannelAdapter] [Verbose]: RX (4 bytes) <<< ConnAck: [ReturnCode=ConnectionAccepted] [ReasonCode=] [IsSessionPresent=False]| 2020-04-29 09:39:41.4215|<mqttNetLog>[2020-04-29T01:39:41.4230846Z] [] [13] [MqttClient] [Verbose]: Authenticated MQTT connection with server established.| 2020-04-29 09:39:41.4232|<mqttNetLog>[2020-04-29T01:39:41.4231993Z] [] [13] [MqttClient] [Info]: Connected.| 2020-04-29 09:39:41.4232|<mqttNetLog>[2020-04-29T01:39:41.4232101Z] [] [28] [MqttClient] [Verbose]: Start sending keep alive packets.| 2020-04-29 09:39:41.4232|[AI-102ZC-ZXGLPT-V100_CLI_88] connected | 2020-04-29 09:39:41.4232|MqttClient reconnect:True,0|

2020-04-29 09:39:56.4249|<mqttNetLog>[2020-04-29T01:39:56.4248279Z] [] [28] [MqttChannelAdapter] [Verbose]: TX (2 bytes) >>> PingReq| 2020-04-29 09:39:56.4249|<mqttNetLog>[2020-04-29T01:39:56.4254503Z] [] [28] [MqttChannelAdapter] [Verbose]: RX (2 bytes) <<< PingResp| 2020-04-29 09:40:11.4285|<mqttNetLog>[2020-04-29T01:40:11.4284773Z] [] [20] [MqttChannelAdapter] [Verbose]: TX (2 bytes) >>> PingReq| 2020-04-29 09:40:11.4285|<mqttNetLog>[2020-04-29T01:40:11.4291570Z] [] [20] [MqttChannelAdapter] [Verbose]: RX (2 bytes) <<< PingResp| 2020-04-29 09:40:26.4289|<mqttNetLog>[2020-04-29T01:40:26.4288598Z] [] [20] [MqttChannelAdapter] [Verbose]: TX (2 bytes) >>> PingReq| 2020-04-29 09:40:26.4289|<mqttNetLog>[2020-04-29T01:40:26.4295076Z] [] [20] [MqttChannelAdapter] [Verbose]: RX (2 bytes) <<< PingResp| 2020-04-29 09:40:56.4306|<mqttNetLog>[2020-04-29T01:40:56.4304955Z] [] [28] [MqttClient] [Verbose]: Disconnecting [Timeout=00:00:10]|

2020-04-29 09:40:56.4315|<mqttNetLog>[2020-04-29T01:40:56.4315023Z] [] [28] [MqttClient] [Verbose]: Disconnected from adapter.| 2020-04-29 09:40:56.4315|<mqttNetLog>[2020-04-29T01:40:56.4305320Z] [] [20] [MqttClient] [Warning]: Error when sending packet of type 'MqttPingRespPacket'. System.Threading.Tasks.TaskCanceledException: A task was canceled. at MQTTnet.Adapter.MqttChannelAdapter.SendPacketAsync(MqttBasePacket packet, TimeSpan timeout, CancellationToken cancellationToken) at MQTTnet.Client.MqttClient.SendAndReceiveAsync[TResponsePacket](MqttBasePacket requestPacket, CancellationToken cancellationToken)|

Apr 29 '20 01:04 bobbydog

@chkr1011 can you have a look? seems strange to me. the disconnect seems to happen right after the pingrequest is send. when the keepalive times out the client is already disconnected.

and maybe whe should add a reason code to the disconnect log, because right now its not obvious why the disconnects happen. could be tcp ip error, server closed connection, missing keepalive response, disconnect packet, ....

@bobbydog do you have logs of the broker? does it accept the pingreq? does it end the connection?

Apr 29 '20 10:04 JanEggers

@chkr1011 can you have a look? seems strange to me. the disconnect seems to happen right after the pingrequest is send. when the keepalive times out the client is already disconnected.

and maybe whe should add a reason code to the disconnect log, because right now its not obvious why the disconnects happen. could be tcp ip error, server closed connection, missing keepalive response, disconnect packet, ....

@bobbydog do you have logs of the broker? does it accept the pingreq? does it end the connection?

the broker didn't log pingreq . the broker logs show it had end the connection. the program can run for an hour without any exception, so that it accept the pingreq ? this is the broker logs: ... 4/29/2020, 9:39:30 AM topic:Work/abc123,message: {"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}} published from AITest_DEBUG_0007 4/29/2020, 9:39:30 AM topic:Work/000000,message: {"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}} published from AITest_DEBUG_0003 4/29/2020, 9:39:31 AM topic:Work/123abc,message: {"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}} published from AITest_DEBUG_0002 4/29/2020, 9:39:31 AM unsubcribed: AI-102ZC-ZXGLPT-V100_CLI_88 keepalive/ 4/29/2020, 9:39:31 AM unsubcribed: AI-102ZC-ZXGLPT-V100_CLI_88 Work/000000 4/29/2020, 9:39:31 AM client disConnected: AI-102ZC-ZXGLPT-V100_CLI_88 4/29/2020, 9:39:31 AM topic:$SYS/yaOz~iz/new/unsubscribes,message: {"clientId":"AI-102ZC-ZXGLPT-V100_CLI_88","topic":"keepalive/"} published from
4/29/2020, 9:39:31 AM topic:$SYS/yaOz~iz/new/unsubscribes,message: {"clientId":"AI-102ZC-ZXGLPT-V100_CLI_88","topic":"Work/000000"} published from 4/29/2020, 9:39:31 AM topic:$SYS/yaOz~iz/disconnect/clients,message: AI-102ZC-ZXGLPT-V100_CLI_88 published from 4/29/2020, 9:39:41 AM topic:Work/000000,message: {"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}} published from AITest_DEBUG_0005 4/29/2020, 9:39:41 AM topic:Work/abc123,message: {"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}} published from AITest_DEBUG_0007 4/29/2020, 9:39:41 AM client connected: AI-102ZC-ZXGLPT-V100_CLI_88 4/29/2020, 9:39:41 AM topic:$SYS/yaOz~iz/new/clients,message: AI-102ZC-ZXGLPT-V100_CLI_88 published from 4/29/2020, 9:39:41 AM topic:Work/abc123,message: {"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}} published from AITest_DEBUG_0001 4/29/2020, 9:39:42 AM topic:Work/000000,message: {"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}} published from AITest_DEBUG_0005 4/29/2020, 9:39:42 AM topic:Work/abc123,message: {"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}} published from AITest_DEBUG_0007 4/29/2020, 9:39:42 AM topic:Work/000000,message: {"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}} published from AITest_DEBUG_0008 ... ... 4/29/2020, 9:40:55 AM topic:Work/000000,message: {"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}} published from AITest_DEBUG_0008 4/29/2020, 9:40:55 AM topic:Work/123abc,message: {"devid":"abc123","unit":"","type":0,"option":7,"data":{"soc":80,"temp":45}} published from AITest_DEBUG_0002

Apr 30 '20 00:04 bobbydog

@bobbydog So the problem only occurs on your Linux machine? The same binary works perfectly when running on Windows 10?

May 01 '20 08:05 chkr1011

@bobbydog So the problem only occurs on your Linux machine? The same binary works perfectly when running on Windows 10?

I have just tested twice in both enviroments at the same time and the same topic workload that the docker linux went down. It appeared to be, but I am not quite sure. the error would easily occur when receive mqtt messages decrease from 10 to 2 per second

May 02 '20 03:05 bobbydog

I have update the mqttnet to 3.0.10rc. Now disconnect can exit and reconnect successsful. But when the disconnect happend which at the same time the PublishAsync method call , the PublishAsync can't get through and running all the time even canceltoken does not help. My program receive the message (Work/abc123), then republish the content to annother topic (device/abc123), When the publishAsync done , it will log "Msg send successful:true/false". but when in mqtt disconnecting , the publishAsync method did not end and program did not log the result(in time 2020-05-12 12:51:43.3605). And after reconnect , when receive message , can't republish message as the while loop never go to the next step. the program section is:

    /// <summary>发送消息</summary>
    /// <param name="msg"></param>
    /// <returns></returns>
    public static async Task<bool> PublishMessage(WebSocketContent msg)
    {
        bool isSuccess=false;
        try
        {
            CancellationTokenSource cts = new CancellationTokenSource();
            _logger.LogInformation("MqttClient send topic:{0} {1}", msg.Topic, msg.Content);
            var msgBuilder = new MqttApplicationMessageBuilder()
                    .WithPayload(msg.Content)
                    .WithTopic(msg.Topic)
                    .WithAtMostOnceQoS();
            cts.CancelAfter(TimeSpan.FromSeconds(_communicateTimeout));
            var result = await _mqttClient.PublishAsync(msgBuilder.Build(), cts.Token);
            if (result.ReasonCode != MqttClientPublishReasonCode.Success)
            {
                isSuccess = false;
                _logger.LogError("消息推送失败:{0},{1}", msg.Topic, result.ToString());
            }
            else
            {
                _failCount = 0;
                isSuccess = true;
            }
        }
        catch (AggregateException ex)
        {
            ex.Handle(eachException =>
            {
                _failCount++;
                isSuccess = false;
                _logger.LogError(eachException, "消息推送失败");
                return true;
            });
        }
        return isSuccess;
    }

    public async Task DoMessagesPublishWork(CancellationToken stoppingToken)
    {
        while (true)
        {
            if (stoppingToken.IsCancellationRequested) break;
            try
            {
                List<WebSocketContent> newMsgs = MqttDataCollection.FetchSendMessageList();
                foreach (var msg in newMsgs)
                {
                        bool isSuccess = await CanTimeoutTask(StaticPubMqttClient.PublishMessage(msg), 15);
                        if (!isSuccess)
                        {
                            msg.Times++;
                            if (msg.Times < 3) MqttDataCollection.PushMessage(msg);
                        }
                        _logger.LogInformation(" Msg send successful: {0}", isSuccess);
                }
                await Task.Delay(600);
            }
            catch (AggregateException ex)
            {
                ex.Handle(eachException =>
                {
                    _logger.LogError(eachException, "DoMessagesPublishWork error");
                    return true;
                });

            }
        }
        _logger.LogInformation("DoMessagesPublishWork end");
    }

    /// <summary> 防止发送/订阅任务一直阻塞</summary>
    private async Task<bool> CanTimeoutTask(Task<bool> task, int timeout)
    {
        var task2 = Task.Delay(TimeSpan.FromSeconds(timeout));
        var firstTask = await Task.WhenAny(task, task2);
        if (firstTask == task2)
        {
            return false;
        }
        else
        {
            return await task;
        }
    }

the log is 2020-05-12 12:51:42.7326|[mqttNetLog][52] [MqttChannelAdapter] [Verbose]: RX (91 bytes) <<< Publish: [Topic=Work/abc123] [Payload.Length=76] [QoSLevel=AtMostOnce] [Dup=False] [Retain=False] [PacketIdentifier=]| 2020-05-12 12:51:42.7326|INFO|Receive the topic:Work/abc123,AI-102ZC-ZXGLPT-V100| 2020-05-12 12:51:42.7582|INFO|MqttClient send topic:device/abc123 {"act":"state","data":{"soc":"81%","temp":"52℃"}}| 2020-05-12 12:51:42.7582|INFO|[mqttNetLog][56] [MqttChannelAdapter] [Verbose]: TX (68 bytes) >>> Publish: [Topic=device/abc123] [Payload.Length=51] [QoSLevel=AtMostOnce] [Dup=False] [Retain=False] [PacketIdentifier=]| 2020-05-12 12:51:42.7582|INFO| Msg send successful: True| 2020-05-12 12:51:43.1716|INFO|DoMessagesRecvWork 1| 2020-05-12 12:51:43.3287|INFO|[mqttNetLog][52] [MqttChannelAdapter] [Verbose]: TX (2 bytes) >>> Disconnect: [ReasonCode=]| 2020-05-12 12:51:43.3287|INFO|[mqttNetLog][52] [MqttClient] [Verbose]: Stopped sending keep alive packets.| 2020-05-12 12:51:43.3287|INFO|[mqttNetLog] [52] [MqttClient] [Verbose]: Disconnecting [Timeout=00:00:10]| 2020-05-12 12:51:43.3287|INFO|[mqttNetLog][56] [MqttClient] [Verbose]: Stopped receiving packets.| 2020-05-12 12:51:43.3605|INFO|MqttClient send topic:device/abc123 {"act":"state","data":{"soc":"27%","temp":"36℃"}}| 2020-05-12 12:52:03.3306|INFO|[mqttNetLog][52] [MqttClient] [Verbose]: Disconnected from adapter.| 2020-05-12 12:52:03.3313|INFO|[mqttNetLog] [52] [MqttClient] [Info]: Disconnected.| 2020-05-12 12:52:03.3313|INFO|[AI-102ZC-ZXGLPT-V100] disconnected :0| 2020-05-12 12:52:03.3313|INFO|[mqttNetLog] [52] [MqttClient] [Verbose]: Trying to connect with server '192.168.3.24:11883' (Timeout=00:00:10).| 2020-05-12 12:52:03.3313|INFO|[mqttNetLog] [46] [MqttClient] [Verbose]: Connection with server established.| 2020-05-12 12:52:03.3313|INFO|[mqttNetLog][59] [MqttClient] [Verbose]: Start receiving packets.| 2020-05-12 12:52:03.3313|INFO|[mqttNetLog][46] [MqttChannelAdapter] [Verbose]: TX (477 bytes) >>> Connect: [ClientId=AI-102ZC-ZXGLPT-V100] [Username=server0] [Password=****] [KeepAlivePeriod=15] [CleanSession=True]| 2020-05-12 12:52:03.3364|INFO|[mqttNetLog][46] [MqttChannelAdapter] [Verbose]: RX (4 bytes) <<< ConnAck: [ReturnCode=ConnectionAccepted] [ReasonCode=] [IsSessionPresent=False]| 2020-05-12 12:52:03.3364|INFO|[mqttNetLog] [MqttClient] [Verbose]: Authenticated MQTT connection with server established.| 2020-05-12 12:52:03.3364|INFO|[mqttNetLog] [59] [MqttClient] [Info]: Connected.| 2020-05-12 12:52:03.3364|INFO|[AI-102ZC-ZXGLPT-V100] connected :1| 2020-05-12 12:52:03.3364|INFO|[mqttNetLog] [46] [MqttClient] [Verbose]: Start sending keep alive packets.| 2020-05-12 12:52:03.3364|INFO|[mqttNetLog] [59] [MqttChannelAdapter] [Verbose]: TX (17 bytes) >>> Subscribe: [PacketIdentifier=1] [TopicFilters=keepalive/@AtMostOnce]| 2020-05-12 12:52:03.3364|INFO|[mqttNetLog] [46] [MqttChannelAdapter] [Verbose]: RX (5 bytes) <<< SubAck: [PacketIdentifier=1] [ReturnCodes=SuccessMaximumQoS0] [ReasonCode=]| 2020-05-12 12:52:03.3364|INFO|[mqttNetLog] [50] [MqttChannelAdapter] [Verbose]: TX (18 bytes) >>> Subscribe: [PacketIdentifier=2] [TopicFilters=Work/abc123@AtMostOnce]| 2020-05-12 12:52:03.3364|INFO|[mqttNetLog] [56] [MqttChannelAdapter] [Verbose]: RX (5 bytes) <<< SubAck: [PacketIdentifier=2] [ReturnCodes=SuccessMaximumQoS0] [ReasonCode=]| 2020-05-12 12:52:03.3364|INFO|[mqttNetLog] [50] [MqttChannelAdapter] [Verbose]: TX (18 bytes) >>> Subscribe: [PacketIdentifier=3] [TopicFilters=Work/000000@AtMostOnce]| 2020-05-12 12:52:03.3364|INFO|[mqttNetLog] [50] [MqttChannelAdapter] [Verbose]: RX (5 bytes) <<< SubAck: [PacketIdentifier=3] [ReturnCodes=SuccessMaximumQoS0] [ReasonCode=]| 2020-05-12 12:52:03.3364|INFO|[AI-102ZC-ZXGLPT-V100] mqtt 已连接 True | 2020-05-12 12:52:03.6527|INFO|[mqttNetLog] [52] [MqttChannelAdapter] [Verbose]: RX (91 bytes) <<< Publish: [Topic=Work/abc123] [Payload.Length=76] [QoSLevel=AtMostOnce] [Dup=False] [Retain=False] [PacketIdentifier=]| 2020-05-12 12:52:03.6527|INFO|Receive the topic:Work/abc123,AI-102ZC-ZXGLPT-V100| 2020-05-12 12:52:03.7626|INFO|[mqttNetLog] [56] [MqttChannelAdapter] [Verbose]: RX (91 bytes) <<< Publish: [Topic=Work/abc123] [Payload.Length=76] [QoSLevel=AtMostOnce] [Dup=False] [Retain=False] [PacketIdentifier=]| 2020-05-12 12:52:03.7626|INFO|Receive the topic:Work/abc123,AI-102ZC-ZXGLPT-V100| 2020-05-12 12:52:04.2503|INFO|DoMessagesRecvWork 2|

May 12 '20 07:05 bobbydog

Hi,

is it fixed in 3.0.11?

Jun 03 '20 07:06 SymbioticKilla

Hi,

is it fixed in 3.0.11? In 3.0.10 the DisconnectInternalAsync can success ending. but this disconnect will still suddently happen through the network env is as good as usual in the newest 3.0.11

Jun 09 '20 04:06 bobbydog

Is this already fixed now @bobbydog @SymbioticKilla ? If yes, please let me know.

Jun 11 '20 14:06 SeppPenner

Is this already fixed now @bobbydog @SymbioticKilla ? If yes, please let me know.

@SeppPenner
The question "DisconnectInternalAsync keep waiting and doesn't end" has fixed from v3.0.10 . But the mqttclient suddently to be disconnected every 60~80minutes which the network env is as good as usual and server is normal running , this situation still occurs in v3.0.12

2020-08-22 17:40:25.1833|<mqttNetLog>[2020-08-22T09:40:25.1839160Z] [] [89] [MqttClient] [Verbose]: Disconnecting [Timeout=00:00:10]| 2020-08-22 17:40:25.1833|<mqttNetLog>[2020-08-22T09:40:25.1832944Z] [] [89] [MqttClient] [Verbose]: Stopped sending keep alive packets.| 2020-08-22 17:40:25.1833|<mqttNetLog>[2020-08-22T09:40:25.1839160Z] [] [89] [MqttClient] [Verbose]: Disconnecting [Timeout=00:00:10]| 2020-08-22 17:40:25.1833|<mqttNetLog>[2020-08-22T09:40:25.1848120Z] [] [112] [MqttClient] [Verbose]: Stopped receiving packets.| 2020-08-22 17:40:45.1856|<mqttNetLog>[2020-08-22T09:40:45.1858698Z] [] [89] [MqttClient] [Verbose]: Disconnected from adapter.| 2020-08-22 17:40:45.1856|<mqttNetLog>[2020-08-22T09:40:45.1860379Z] [] [89] [MqttClient] [Info]: Disconnected.|

Aug 21 '20 01:08 bobbydog

I have just updated to 3.0.14, the mqttclient still suddently to be disconnected every one hour in my ubuntu docker (base from .net core 2.2 image). The log show below seems like the MqttClient._backgroundCancellationTokenSource has a dispose() operation that the keepalve and receive task has to stop and return , but I use the mqttClient.ConnectAsync(IMqttClientOptions) method and have nothing to do with the cancellationtoken.

Mar 02 '21 03:03 bobbydog

Please try with 3.0.15. A few things have changed in that area.

Mar 02 '21 09:03 chkr1011

Please try with 3.0.15. A few things have changed in that area.

Hi @chkr1011 , I have tried with 3.0.15, but I'm sorry to tell that this situation still happend

Mar 05 '21 03:03 bobbydog

What about 3.0.16? There were some improvements accroding to release notes in this area?

Jun 30 '21 12:06 SymbioticKilla

@bobbydog Please try with the latest version 4 and reopen this ticket if the error persists.

Sep 25 '22 08:09 chkr1011

MQTTnet MQTTnet copied to clipboard

DisconnectInternalAsync keep waiting and doesn't end

Describe the bug

Which project is your bug related to?

To Reproduce

Expected behavior

Screenshots

Code example

MQTTnet
MQTTnet copied to clipboard