Fronius: Improve connection handling and fix dead connection failing with operation canceled

fronius/froniussolarconnection.cpp

@@ -32,6 +32,7 @@
 #include "extern-plugininfo.h"
 
 #include <QUrlQuery>
+#include <QTimer>
 
 FroniusSolarConnection::FroniusSolarConnection(NetworkAccessManager *networkManager, const QHostAddress &address, QObject *parent) :
     QObject(parent),
@@ -87,8 +88,9 @@ FroniusNetworkReply *FroniusSolarConnection::getVersion()
     requestUrl.setHost(m_address.toString());
     requestUrl.setPath("/solar_api/GetAPIVersion.cgi");
 
-    FroniusNetworkReply *reply = new FroniusNetworkReply(QNetworkRequest(requestUrl), this);
+    FroniusNetworkReply *reply = new FroniusNetworkReply(buildRequest(requestUrl), this);
     m_requestQueue.enqueue(reply);
+    qCDebug(dcFronius()).nospace() << "Connection: Enqueued request (queue: " << m_requestQueue.size() << "): " << requestUrl.toString();
     sendNextRequest();
     return reply;
 }
@@ -104,10 +106,12 @@ FroniusNetworkReply *FroniusSolarConnection::getActiveDevices()
     query.addQueryItem("DeviceClass", "System");
     requestUrl.setQuery(query);
 
-    FroniusNetworkReply *reply = new FroniusNetworkReply(QNetworkRequest(requestUrl), this);
+    FroniusNetworkReply *reply = new FroniusNetworkReply(buildRequest(requestUrl), this);
     m_requestQueue.enqueue(reply);
+    qCDebug(dcFronius()).nospace() << "Connection: Enqueued request (queue: " << m_requestQueue.size() << "): " << requestUrl.toString();
 
     // Note: we use this request for detecting if the logger is available or not.
+    // Some other requests are only available if the device actually is loaded
     connect(reply, &FroniusNetworkReply::finished, this, [=](){
         if (reply->networkReply()->error() == QNetworkReply::NoError) {
             // Reply was successfully, we can communicate
@@ -121,8 +125,8 @@ FroniusNetworkReply *FroniusSolarConnection::getActiveDevices()
                 m_requestQueue.clear();
             }
         } else {
-            // Ther have been errors, seems like we not available any more
+            // There have been multiple errors in a row, seems like we not available any more
-            if (m_available) {
+            if (m_available && m_errorCount >= m_errorCountLimit) {
                 qCDebug(dcFronius()) << "Connection: the connection is not available any more:" << reply->networkReply()->errorString();
                 m_available = false;
                 emit availableChanged(m_available);
@@ -141,8 +145,9 @@ FroniusNetworkReply *FroniusSolarConnection::getPowerFlowRealtimeData()
     requestUrl.setHost(m_address.toString());
     requestUrl.setPath("/solar_api/v1/GetPowerFlowRealtimeData.fcgi");
 
-    FroniusNetworkReply *reply = new FroniusNetworkReply(QNetworkRequest(requestUrl), this);
+    FroniusNetworkReply *reply = new FroniusNetworkReply(buildRequest(requestUrl), this);
     m_requestQueue.enqueue(reply);
+    qCDebug(dcFronius()).nospace() << "Connection: Enqueued request (queue: " << m_requestQueue.size() << "): " << requestUrl.toString();
     sendNextRequest();
     return reply;
 }
@@ -160,8 +165,9 @@ FroniusNetworkReply *FroniusSolarConnection::getInverterRealtimeData(int inverte
     query.addQueryItem("DataCollection", "CommonInverterData");
     requestUrl.setQuery(query);
 
-    FroniusNetworkReply *reply = new FroniusNetworkReply(QNetworkRequest(requestUrl), this);
+    FroniusNetworkReply *reply = new FroniusNetworkReply(buildRequest(requestUrl), this);
     m_requestQueue.enqueue(reply);
+    qCDebug(dcFronius()).nospace() << "Connection: Enqueued request (queue: " << m_requestQueue.size() << "): " << requestUrl.toString();
     sendNextRequest();
     return reply;
 }
@@ -178,8 +184,9 @@ FroniusNetworkReply *FroniusSolarConnection::getMeterRealtimeData(int meterId)
     query.addQueryItem("DeviceId", QString::number(meterId));
     requestUrl.setQuery(query);
 
-    FroniusNetworkReply *reply = new FroniusNetworkReply(QNetworkRequest(requestUrl), this);
+    FroniusNetworkReply *reply = new FroniusNetworkReply(buildRequest(requestUrl), this);
     m_requestQueue.enqueue(reply);
+    qCDebug(dcFronius()).nospace() << "Connection: Enqueued request (queue: " << m_requestQueue.size() << "): " << requestUrl.toString();
     sendNextRequest();
     return reply;
 }
@@ -196,12 +203,22 @@ FroniusNetworkReply *FroniusSolarConnection::getStorageRealtimeData(int meterId)
     query.addQueryItem("DeviceId", QString::number(meterId));
     requestUrl.setQuery(query);
 
-    FroniusNetworkReply *reply = new FroniusNetworkReply(QNetworkRequest(requestUrl), this);
+    FroniusNetworkReply *reply = new FroniusNetworkReply(buildRequest(requestUrl), this);
     m_requestQueue.enqueue(reply);
+    qCDebug(dcFronius()).nospace() << "Connection: Enqueued request (queue: " << m_requestQueue.size() << "): " << requestUrl.toString();
     sendNextRequest();
     return reply;
 }
 
+QNetworkRequest FroniusSolarConnection::buildRequest(const QUrl &url)
+{
+    QNetworkRequest request;
+    request.setUrl(url);
+    // Note: some inverter stop accepting requests, this might help
+    request.setAttribute(QNetworkRequest::HttpPipeliningAllowedAttribute, false);
+    return request;
+}
+
 void FroniusSolarConnection::sendNextRequest()
 {
     if (m_currentReply)
@@ -212,18 +229,49 @@ void FroniusSolarConnection::sendNextRequest()
 
     m_currentReply = m_requestQueue.dequeue();
 
-    qCDebug(dcFronius()) << "Connection: Sending request" << m_currentReply->request().url().toString();
+    if (m_useCustomNetworkManager) {
-    m_currentReply->setNetworkReply(m_networkManager->get(m_currentReply->request()));
+        qCDebug(dcFronius()) << "Connection: --> Sending request using custom network manager (queue: " << m_requestQueue.size() << "): " << m_currentReply->request().url().toString();
+        if (!m_customNetworkManager) {
+            m_customNetworkManager = new QNetworkAccessManager(this);
+        }
+
+        m_currentReply->setNetworkReply(m_customNetworkManager->get(m_currentReply->request()));
+    } else {
+        qCDebug(dcFronius()).nospace() << "Connection: --> Sending request (queue: " << m_requestQueue.size() << "): " << m_currentReply->request().url().toString();
+        m_currentReply->setNetworkReply(m_networkManager->get(m_currentReply->request()));
+    }
+
 
     connect(m_currentReply, &FroniusNetworkReply::finished, this, [=](){
-        if (m_currentReply->networkReply()->error() != QNetworkReply::NoError) {
-            qCWarning(dcFronius()) << "Connection: Request finished with error:" << m_currentReply->networkReply()->error() << "for url" << m_currentReply->request().url().toString();
-        }
 
         // Note: the network reply will be deleted in the destructor
         m_currentReply->deleteLater();
 
+        if (m_currentReply->networkReply()->error() != QNetworkReply::NoError) {
+            m_errorCount++;
+            qCWarning(dcFronius()).nospace() << "Connection: <--  Request finished with error (count: " << m_errorCount << ") " << m_currentReply->networkReply()->error() << " for url " << m_currentReply->request().url().toString();
+            if (m_currentReply->networkReply()->error() == QNetworkReply::OperationCanceledError) {
+                m_errorOperationCanceledCount++;
+                if (!m_useCustomNetworkManager && m_errorOperationCanceledCount >= m_errorOperationCanceledCountLimit) {
+                    qCWarning(dcFronius()) << "Received" << m_errorOperationCanceledCountLimit << "in a row, skipping to internal network access manager. This is a workaround in order to free all requests after each reply.";
+                    m_useCustomNetworkManager = true;
+                }
+            }
+        } else {
+            qCDebug(dcFronius()) << "Connection: <-- Request finished successfully for" << m_currentReply->request().url().toString();
+            m_errorCount = 0;
+            m_errorOperationCanceledCount = 0;
+        }
+
         m_currentReply = nullptr;
-        sendNextRequest();
+
+        // Note: this is a workaround for some fronius devices, we recreate the networkaccessmanager after each request
+        if (m_useCustomNetworkManager && m_customNetworkManager) {
+            m_customNetworkManager->deleteLater();
+            m_customNetworkManager = nullptr;
+        }
+
+        // Wait some time until we send the next request
+        QTimer::singleShot(500, this, &FroniusSolarConnection::sendNextRequest);
     });
 }

fronius/froniussolarconnection.h

@@ -34,6 +34,7 @@
 #include <QObject>
 #include <QQueue>
 #include <QHostAddress>
+#include <QNetworkAccessManager>
 
 #include <network/networkaccessmanager.h>
 
@@ -69,10 +70,27 @@ private:
 
     bool m_available = false;
 
+    // Fallback solution for dead nam requests, this happens on some platforms
+    // Note: we enable for now the custom network access manager
+    // Some fronius inverters keep the connection alive and get stuck somehow.
+    // In order to workaround this issue, we have to recreate the nam after each request.
+    // Stuff like disableing pipelining, queueing requests did not fix the issue, only
+    // destroying and re-creating the nam helped here. Current guess: the persistant TCP connection
+    // keeps some resources blocked. The issue is actually on the fronius webserver side, and just on some
+    // rare hardware so far.
+    QNetworkAccessManager *m_customNetworkManager = nullptr;
+    bool m_useCustomNetworkManager = true; // Force for now
+    uint m_errorOperationCanceledCount = 0;
+    uint m_errorOperationCanceledCountLimit = 3;
+    uint m_errorCount = 0;
+    uint m_errorCountLimit = 5;
+
     // Request queue to prevent overloading the device with requests
     FroniusNetworkReply *m_currentReply = nullptr;
     QQueue<FroniusNetworkReply *> m_requestQueue;
 
+    QNetworkRequest buildRequest(const QUrl &url);
+
     void sendNextRequest();
 
 };

fronius/integrationpluginfronius.cpp

@@ -296,12 +296,12 @@ void IntegrationPluginFronius::executeAction(ThingActionInfo *info)
 void IntegrationPluginFronius::refreshConnection(FroniusSolarConnection *connection)
 {
     if (connection->busy()) {
-        qCDebug(dcFronius()) << "Connection busy. Skipping refresh cycle for host" << connection->address().toString();
+        qCDebug(dcFronius()) << "The connection is busy. Skipping refresh cycle for host" << connection->address().toString();
         return;
     }
 
     if (connection->address().isNull()) {
-        qCDebug(dcFronius()) << "Connection has no IP configured yet. Skipping refresh cycle until known";
+        qCDebug(dcFronius()) << "The connection has no IP configured yet. Skipping refresh cycle until known";
         return;
     }
 
@@ -358,9 +358,8 @@ void IntegrationPluginFronius::refreshConnection(FroniusSolarConnection *connect
                 // Get the meter realtime data for details
                 FroniusNetworkReply *realtimeDataReply = connection->getMeterRealtimeData(meterId.toInt());
                 connect(realtimeDataReply, &FroniusNetworkReply::finished, this, [=]() {
-                    if (realtimeDataReply->networkReply()->error() != QNetworkReply::NoError) {
+                    if (realtimeDataReply->networkReply()->error() != QNetworkReply::NoError)
                         return;
-                    }
 
                     QByteArray data = realtimeDataReply->networkReply()->readAll();
 
@@ -414,9 +413,8 @@ void IntegrationPluginFronius::refreshConnection(FroniusSolarConnection *connect
                 // Get the meter realtime data for details
                 FroniusNetworkReply *realtimeDataReply = connection->getStorageRealtimeData(storageId.toInt());
                 connect(realtimeDataReply, &FroniusNetworkReply::finished, this, [=]() {
-                    if (realtimeDataReply->networkReply()->error() != QNetworkReply::NoError) {
+                    if (realtimeDataReply->networkReply()->error() != QNetworkReply::NoError)
                         return;
-                    }
 
                     QByteArray data = realtimeDataReply->networkReply()->readAll();
 
@@ -488,9 +486,8 @@ void IntegrationPluginFronius::updatePowerFlow(FroniusSolarConnection *connectio
     // to make sure the sum is correct. Battery seems to be feeded DC to DC before the AC power convertion
     FroniusNetworkReply *powerFlowReply = connection->getPowerFlowRealtimeData();
     connect(powerFlowReply, &FroniusNetworkReply::finished, this, [=]() {
-        if (powerFlowReply->networkReply()->error() != QNetworkReply::NoError) {
+        if (powerFlowReply->networkReply()->error() != QNetworkReply::NoError)
             return;
-        }
 
         QByteArray data = powerFlowReply->networkReply()->readAll();
 
@@ -547,8 +544,6 @@ void IntegrationPluginFronius::updatePowerFlow(FroniusSolarConnection *connectio
             qCDebug(dcFronius()) << "Using power flow grid power for the weak S0 meter" << gridPower << "House consumption" << dataMap.value("Site").toMap().value("P_Load").toDouble();
             meterThing->setStateValue(meterCurrentPowerStateTypeId, gridPower);
         }
-
-
     });
 }
 
@@ -563,11 +558,20 @@ void IntegrationPluginFronius::updateInverters(FroniusSolarConnection *connectio
         FroniusNetworkReply *realtimeDataReply = connection->getInverterRealtimeData(inverterId);
         connect(realtimeDataReply, &FroniusNetworkReply::finished, this, [=]() {
             if (realtimeDataReply->networkReply()->error() != QNetworkReply::NoError) {
-                // Thing does not seem to be reachable
+                m_thingRequestErrorCounter[inverterThing] = m_thingRequestErrorCounter.value(inverterThing, 0) + 1;
-                markInverterAsDisconnected(inverterThing);
+                if (m_thingRequestErrorCounter.value(inverterThing) >= m_thingRequestErrorCountLimit) {
+                    if (inverterThing->stateValue("connected").toBool()) {
+                        qCWarning(dcFronius()) << "The inverter" << inverterThing << "received" << m_thingRequestErrorCountLimit << "errors. Mark thing as offline";
+                    }
+                    // Thing does not seem to be reachable
+                    markInverterAsDisconnected(inverterThing);
+                }
                 return;
             }
 
+            // Reset the error counter on a successfull refresh
+            m_thingRequestErrorCounter[inverterThing] = 0;
+
             QByteArray data = realtimeDataReply->networkReply()->readAll();
 
             QJsonParseError error;
@@ -627,11 +631,20 @@ void IntegrationPluginFronius::updateMeters(FroniusSolarConnection *connection)
         FroniusNetworkReply *realtimeDataReply = connection->getMeterRealtimeData(meterId);
         connect(realtimeDataReply, &FroniusNetworkReply::finished, this, [=]() {
             if (realtimeDataReply->networkReply()->error() != QNetworkReply::NoError) {
-                // Thing does not seem to be reachable
+                m_thingRequestErrorCounter[meterThing] = m_thingRequestErrorCounter.value(meterThing, 0) + 1;
-                markMeterAsDisconnected(meterThing);
+                if (m_thingRequestErrorCounter.value(meterThing) >= m_thingRequestErrorCountLimit) {
+                    if (meterThing->stateValue("connected").toBool()) {
+                        qCWarning(dcFronius()) << "The meter" << meterThing << "received" << m_thingRequestErrorCountLimit << "errors. Mark thing as offline";
+                    }
+                    // Thing does not seem to be reachable
+                    markMeterAsDisconnected(meterThing);
+                }
                 return;
             }
 
+            // Reset the error counter on a successfull refresh
+            m_thingRequestErrorCounter[meterThing] = 0;
+
             QByteArray data = realtimeDataReply->networkReply()->readAll();
 
             QJsonParseError error;
@@ -665,7 +678,6 @@ void IntegrationPluginFronius::updateMeters(FroniusSolarConnection *connection)
                 m_weakMeterConnections[connection] = false;
             }
 
-
             // Power
             if (dataMap.contains("PowerReal_P_Sum")) {
                 meterThing->setStateValue(meterCurrentPowerStateTypeId, dataMap.value("PowerReal_P_Sum").toDouble());
@@ -735,6 +747,21 @@ void IntegrationPluginFronius::updateStorages(FroniusSolarConnection *connection
         // Get the storage realtime data
         FroniusNetworkReply *realtimeDataReply = connection->getStorageRealtimeData(storageId);
         connect(realtimeDataReply, &FroniusNetworkReply::finished, this, [=]() {
+            if (realtimeDataReply->networkReply()->error() != QNetworkReply::NoError) {
+                m_thingRequestErrorCounter[storageThing] = m_thingRequestErrorCounter.value(storageThing, 0) + 1;
+                if (m_thingRequestErrorCounter.value(storageThing) >= m_thingRequestErrorCountLimit) {
+                    if (storageThing->stateValue("connected").toBool()) {
+                        qCWarning(dcFronius()) << "The storage" << storageThing << "received" << m_thingRequestErrorCountLimit << "errors. Mark thing as offline";
+                    }
+                    // Thing does not seem to be reachable
+                    markStorageAsDisconnected(storageThing);
+                }
+                return;
+            }
+
+            // Reset the error counter on a successfull refresh
+            m_thingRequestErrorCounter[storageThing] = 0;
+
             if (realtimeDataReply->networkReply()->error() != QNetworkReply::NoError) {
                 // Thing does not seem to be reachable
                 markStorageAsDisconnected(storageThing);

fronius/integrationpluginfronius.h

@@ -61,6 +61,9 @@ private:
     QHash<Thing *, NetworkDeviceMonitor *> m_monitors;
     QHash<FroniusSolarConnection *, bool> m_weakMeterConnections;
 
+    QHash<Thing *, uint> m_thingRequestErrorCounter;
+    uint m_thingRequestErrorCountLimit = 3;
+
     void refreshConnection(FroniusSolarConnection *connection);
 
     void updatePowerFlow(FroniusSolarConnection *connection);