Fix that curl generates a SIGPIPE that causes application to exit due…

… to upstream device killing idle TCP connection (#2906) * Add releaseTimestamp to track when a curlEngine was last used to determine if this engine should be reused or not * Add forced HTTP/1.1 downgrade based on bad curl versions usually found in Ubuntu distributions * Add note regarding 'Could not connect to server on handle' * Make stale curl idle value a config option and update associated documentation
abraunegg · Oct 20, 2024 · 2e93c1f · 2e93c1f
1 parent 967327c
commit 2e93c1f
Show file tree

Hide file tree

Showing 8 changed files with 132 additions and 13 deletions.
diff --git a/docs/application-config-options.md b/docs/application-config-options.md
@@ -29,6 +29,7 @@ Before reading this document, please ensure you are running application version
   - [ip_protocol_version](#ip_protocol_version)
   - [local_first](#local_first)
   - [log_dir](#log_dir)
+  - [max_curl_idle](#max_curl_idle)
   - [monitor_fullscan_frequency](#monitor_fullscan_frequency)
   - [monitor_interval](#monitor_interval)
   - [monitor_log_frequency](#monitor_log_frequency)
@@ -382,6 +383,20 @@ _**Config Example:**_ `log_dir = "~/logs/"`
 
 _**CLI Option Use:**_ `--log-dir "~/logs/"`
 
+### max_curl_idle
+_**Description:**_ This configuration option controls the number of seconds that elapse after a cURL engine was last used before it is considered stale and destroyed. Evidence suggests that some upstream network devices ignore the cURL keep-alive setting and forcibly close the active TCP connection when idle.
+
+_**Value Type:**_ Integer
+
+_**Default Value:**_ 120
+
+_**Config Example:**_ `monitor_fullscan_frequency = "120"`
+
+_**CLI Option Use:**_ *None - this is a config file option only*
+
+> [!IMPORTANT]
+> It is strongly recommended not to modify this setting without conducting thorough network testing. Changing this option may lead to unexpected behaviour or connectivity issues, especially if upstream network devices handle idle connections in non-standard ways.
+
 ### monitor_fullscan_frequency
 _**Description:**_ This configuration option controls the number of 'monitor_interval' iterations between when a full scan of your data is performed to ensure data integrity and consistency.
 

diff --git a/docs/usage.md b/docs/usage.md
@@ -153,8 +153,11 @@ If you explicitly want to use HTTP/1.1, you can do so by using the `--force-http
 > [!IMPORTANT]
 > It has been evidenced that curl has an internal DNS resolution bug that at random times will skip using IPv4 for DNS resolution and only uses IPv6 DNS resolution when the host system is configured to use IPv4 and IPv6 addressing.
 > 
-> As a result of this curl resolution bug, if your system does not have an IPv6 DNS resolver, and/or does not have a valid IPv6 network path to Microsoft OneDrive, you may encounter this error: `A libcurl timeout has been triggered - data transfer too slow, no DNS resolution response, no server response`
+> As a result of this curl resolution bug, if your system does not have an IPv6 DNS resolver, and/or does not have a valid IPv6 network path to Microsoft OneDrive, you may encounter these errors: 
 > 
+> * `A libcurl timeout has been triggered - data transfer too slow, no DNS resolution response, no server response`
+> * `Could not connect to server on handle ABC12DEF3456`
+>
 > The only options to resolve this are the following:
 > 1. Implement and/or ensure that IPv6 DNS resolution is possible on your system; allow IPv6 network connectivity between your system and Microsoft OneDrive
 > 2. Configure the client to only use IPv4 DNS resolution via setting the configuration option `ip_protocol_version = "1"`

diff --git a/src/config.d b/src/config.d
@@ -272,6 +272,8 @@ class ApplicationConfig {
 		longValues["data_timeout"] = defaultDataTimeout;
 		// What IP protocol version should be used when communicating with OneDrive
 		longValues["ip_protocol_version"] = defaultIpProtocol; // 0 = IPv4 + IPv6, 1 = IPv4 Only, 2 = IPv6 Only
+		// What is the default age that a curl engine should be left idle for, before being being destroyed
+		longValues["max_curl_idle"] = 120;
 
 		// Number of concurrent threads
 		longValues["threads"] = defaultConcurrentThreads; // Default is 8, user can increase to max of 16 or decrease
@@ -1335,6 +1337,7 @@ class ApplicationConfig {
 		// Display application version
 		addLogEntry("Application version                          = " ~ applicationVersion);
 		addLogEntry("Compiled with                                = " ~ compilerDetails());
+		addLogEntry("Curl version                                 = " ~ getCurlVersionString());
 
 		// Display all of the pertinent configuration options
 		addLogEntry("User Application Config path                 = " ~ configDirName);
@@ -1418,6 +1421,7 @@ class ApplicationConfig {
 		addLogEntry("Config option 'data_timeout'                 = " ~ to!string(getValueLong("data_timeout")));
 		addLogEntry("Config option 'ip_protocol_version'          = " ~ to!string(getValueLong("ip_protocol_version")));
 		addLogEntry("Config option 'threads'                      = " ~ to!string(getValueLong("threads")));
+		addLogEntry("Config option 'max_curl_idle'                = " ~ to!string(getValueLong("max_curl_idle")));
 
 		// GUI notifications
 		version(Notifications) {

diff --git a/src/curlEngine.d b/src/curlEngine.d
@@ -7,6 +7,7 @@ import etc.c.curl;
 import std.datetime;
 import std.conv;
 import std.file;
+import std.format;
 import std.json;
 import std.stdio;
 import std.range;
@@ -184,11 +185,14 @@ class CurlEngine {
 	bool keepAlive;
 	ulong dnsTimeout;
 	string internalThreadId;
+	SysTime releaseTimestamp;
+	ulong maxIdleTime;
 
     this() {
         http = HTTP();   // Directly initializes HTTP using its default constructor
         response = null; // Initialize as null
 		internalThreadId = generateAlphanumericString(); // Give this CurlEngine instance a unique ID
+		if (debugLogging) {addLogEntry("Created new CurlEngine instance id: " ~ to!string(internalThreadId), ["debug"]);}
     }
 
 	// The destructor should only clean up resources owned directly by this CurlEngine instance
@@ -212,10 +216,14 @@ class CurlEngine {
 
 	// We are releasing a curl instance back to the pool
 	void releaseEngine() {
+		// Set timestamp of release
+		releaseTimestamp = Clock.currTime(UTC());
 		// Log that we are releasing this engine back to the pool
 		if (debugLogging) {
 			addLogEntry("CurlEngine releaseEngine() called on instance id: " ~ to!string(internalThreadId), ["debug"]);
 			addLogEntry("CurlEngine curlEnginePool size before release: " ~ to!string(curlEnginePool.length), ["debug"]);
+			string engineReleaseMessage = format("Release Timestamp for CurlEngine %s: %s", to!string(internalThreadId), to!string(releaseTimestamp));
+			addLogEntry(engineReleaseMessage, ["debug"]);
 		}
 
 		// cleanup this curl instance before putting it back in the pool
@@ -231,13 +239,14 @@ class CurlEngine {
     }
 
 	// Initialise this curl instance
-	void initialise(ulong dnsTimeout, ulong connectTimeout, ulong dataTimeout, ulong operationTimeout, int maxRedirects, bool httpsDebug, string userAgent, bool httpProtocol, ulong userRateLimit, ulong protocolVersion, bool keepAlive=true) {
+	void initialise(ulong dnsTimeout, ulong connectTimeout, ulong dataTimeout, ulong operationTimeout, int maxRedirects, bool httpsDebug, string userAgent, bool httpProtocol, ulong userRateLimit, ulong protocolVersion, ulong maxIdleTime, bool keepAlive=true) {
 		//   Setting this to false ensures that when we close the curl instance, any open sockets are closed - which we need to do when running 
 		//   multiple threads and API instances at the same time otherwise we run out of local files | sockets pretty quickly
 		this.keepAlive = keepAlive;
 		this.dnsTimeout = dnsTimeout;
 
 		// Curl Timeout Handling
+		this.maxIdleTime = maxIdleTime;
 
 		// libcurl dns_cache_timeout timeout
 		// https://curl.se/libcurl/c/CURLOPT_DNS_CACHE_TIMEOUT.html
@@ -512,12 +521,39 @@ CurlEngine getCurlInstance() {
 				if (debugLogging) {addLogEntry("CurlEngine was in a stopped state (not usable) - constructing a new CurlEngine instance", ["debug"]);}
 				return new CurlEngine;  // Constructs a new CurlEngine with a fresh HTTP instance
 			} else {
-				// return an existing curl engine
+				// When was this engine last used?
+				auto elapsedTime = Clock.currTime(UTC()) - curlEngine.releaseTimestamp;
 				if (debugLogging) {
-					addLogEntry("CurlEngine was in a valid state - returning existing CurlEngine instance", ["debug"]);
-					addLogEntry("CurlEngine instance ID: " ~ curlEngine.internalThreadId, ["debug"]);
+					string engineIdleMessage = format("CurlEngine %s time since last use: %s", to!string(curlEngine.internalThreadId), to!string(elapsedTime));
+					addLogEntry(engineIdleMessage, ["debug"]);
+				}
+
+				// If greater than 120 seconds (default), the treat this as a stale engine, preventing:
+				// 	* Too old connection (xxx seconds idle), disconnect it
+				// 	* Connection 0 seems to be dead!
+				// 	* Closing connection 0
+
+				if (elapsedTime > dur!"seconds"(curlEngine.maxIdleTime)) {
+					// Too long idle engine, clean it up and create a new one
+					if (debugLogging) {
+						string curlTooOldMessage = format("CurlEngine idle for > %d seconds .... destroying and returning a new curl engine instance", curlEngine.maxIdleTime);
+						addLogEntry(curlTooOldMessage, ["debug"]);
+					}
+
+					curlEngine.cleanup(true); // Cleanup instance by resetting values and flushing cookie cache
+					curlEngine.shutdownCurlHTTPInstance();  // Assume proper cleanup of any resources used by HTTP
+					if (debugLogging) {addLogEntry("Returning NEW curlEngine instance", ["debug"]);}
+					return new CurlEngine;  // Constructs a new CurlEngine with a fresh HTTP instance
+				} else {
+					// return an existing curl engine
+					if (debugLogging) {
+						addLogEntry("CurlEngine was in a valid state - returning existing CurlEngine instance", ["debug"]);
+						addLogEntry("Using CurlEngine instance ID: " ~ curlEngine.internalThreadId, ["debug"]);
+					}
+
+					// return the existing engine
+					return curlEngine;
 				}
-				return curlEngine;
 			}
 		}
 	}
@@ -546,7 +582,7 @@ void releaseAllCurlInstances() {
 				// Perform Garbage Collection on this destroyed curl engine
 				GC.collect();
 				// Log release
-				if (debugLogging) {addLogEntry("CurlEngine released", ["debug"]);}
+				if (debugLogging) {addLogEntry("CurlEngine destroyed", ["debug"]);}
 			}
 
 			// Clear the array after all instances have been handled

diff --git a/src/main.d b/src/main.d
@@ -188,12 +188,34 @@ int main(string[] cliArgs) {
 	// Update the current runtime application configuration (default or 'config' fileread-in options) from any passed in command line arguments
 	appConfig.updateFromArgs(cliArgs);
 
+	// If 'force_http_11' = false, we need to check the curl version being used
+	if (!appConfig.getValueBool("force_http_11")) {
+		// get the curl version
+		string curlVersion = getCurlVersionNumeric();
+
+		// Is the version of curl or libcurl being used by the platform a known bad curl version for HTTP/2 support
+		if (isBadCurlVersion(curlVersion)) {
+			// add warning message
+			string curlWarningMessage = format("WARNING: Your curl/libcurl version (%s) has known HTTP/2 bugs that impact the use of this application.", curlVersion);
+			addLogEntry();
+			addLogEntry(curlWarningMessage);
+			addLogEntry("         Please report this to your distribution and request that they provide a newer version for your platform or upgrade this yourself.");
+			addLogEntry("         Downgrading all application operations to use HTTP/1.1 to ensure maximum operational stability.");
+			addLogEntry("         Please read https://github.com/abraunegg/onedrive/blob/master/docs/usage.md#compatibility-with-curl for more information.");
+			addLogEntry();
+			appConfig.setValueBool("force_http_11" , true);
+		}
+	}
+
 	// If --disable-notifications has not been used, check if everything exists to enable notifications
 	if (!appConfig.getValueBool("disable_notifications")) {
 		// If notifications was compiled in, we need to ensure that these variables are actually available before we enable GUI Notifications
 		flagEnvironmentVariablesAvailable(appConfig.validateGUINotificationEnvironmentVariables());
-		// Attempt to enable GUI Notifications
-		validateDBUSServerAvailability();
+		// If we are not using --display-config attempt to enable GUI notifications
+		if (!appConfig.getValueBool("display_config")) {
+			// Attempt to enable GUI Notifications
+			validateDBUSServerAvailability();
+		}
 	}
 
 	// In a debug scenario, to assist with understanding the run-time configuration, ensure this flag is set

diff --git a/src/onedrive.d b/src/onedrive.d
@@ -140,7 +140,7 @@ class OneDriveApi {
 		this.keepAlive = keepAlive;
 		if (curlEngine is null) {
 			curlEngine = getCurlInstance();
-			curlEngine.initialise(appConfig.getValueLong("dns_timeout"), appConfig.getValueLong("connect_timeout"), appConfig.getValueLong("data_timeout"), appConfig.getValueLong("operation_timeout"), appConfig.defaultMaxRedirects, appConfig.getValueBool("debug_https"), appConfig.getValueString("user_agent"), appConfig.getValueBool("force_http_11"), appConfig.getValueLong("rate_limit"), appConfig.getValueLong("ip_protocol_version"), keepAlive);
+			curlEngine.initialise(appConfig.getValueLong("dns_timeout"), appConfig.getValueLong("connect_timeout"), appConfig.getValueLong("data_timeout"), appConfig.getValueLong("operation_timeout"), appConfig.defaultMaxRedirects, appConfig.getValueBool("debug_https"), appConfig.getValueString("user_agent"), appConfig.getValueBool("force_http_11"), appConfig.getValueLong("rate_limit"), appConfig.getValueLong("ip_protocol_version"), appConfig.getValueLong("max_curl_idle"), keepAlive);
 		}
 
 		// Authorised value to return
@@ -1177,7 +1177,7 @@ class OneDriveApi {
 				// re-try log entry & clock time
 				retryTime = Clock.currTime();
 				retryTime.fracSecs = Duration.zero;
-				addLogEntry("Retrying the respective Microsoft Graph API call for Internal Thread ID " ~ to!string(curlEngine.internalThreadId) ~ " (Timestamp: " ~ to!string(retryTime) ~ ") ...");
+				addLogEntry("Retrying the respective Microsoft Graph API call for Internal Thread ID: " ~ to!string(curlEngine.internalThreadId) ~ " (Timestamp: " ~ to!string(retryTime) ~ ") ...");
 			}
 
 			try {

diff --git a/src/sync.d b/src/sync.d
@@ -8548,7 +8548,6 @@ class SyncEngine {
 
 		// Check the session data for expirationDateTime
 		if ("expirationDateTime" in sessionFileData) {
-			addLogEntry("expirationDateTime: " ~ sessionFileData["expirationDateTime"].str);
 			SysTime expiration;
 			string expirationTimestamp;
 			expirationTimestamp = strip(sessionFileData["expirationDateTime"].str);

diff --git a/src/util.d b/src/util.d
@@ -34,6 +34,7 @@ import core.sys.posix.pwd;
 import core.sys.posix.unistd;
 import core.stdc.string;
 import core.sys.posix.signal;
+import etc.c.curl;
 
 // What other modules that we have created do we need to import?
 import log;
@@ -1359,4 +1360,43 @@ string compilerDetails() {
 	else enum compiler = "Unknown compiler";
 	string compilerString = compiler ~ " " ~ to!string(__VERSION__);
 	return compilerString;
-}
+}
+
+// Return the curl version details
+string getCurlVersionString() {
+	// Get curl version
+	auto versionInfo = curl_version();
+	return to!string(versionInfo);
+}
+
+// Function to return the decoded curl version as a string
+string getCurlVersionNumeric() {
+    // Get curl version info using curl_version_info
+    auto curlVersionDetails = curl_version_info(CURLVERSION_NOW);
+
+    // Extract the major, minor, and patch numbers from version_num
+    uint versionNum = curlVersionDetails.version_num;
+
+    // The version number is in the format 0xXXYYZZ
+    uint major = (versionNum >> 16) & 0xFF; // Extract XX (major version)
+    uint minor = (versionNum >> 8) & 0xFF;  // Extract YY (minor version)
+    uint patch = versionNum & 0xFF;         // Extract ZZ (patch version)
+
+    // Return the version in the format "major.minor.patch"
+    return major.to!string ~ "." ~ minor.to!string ~ "." ~ patch.to!string;
+}
+
+// Test the curl version against known curl versions with HTTP/2 issues
+bool isBadCurlVersion(string curlVersion) {
+    // List of known curl versions with HTTP/2 issues
+    string[] supportedVersions = [
+        "7.68.0",
+        "7.74.0",
+        "7.81.0",
+        "7.88.1",
+        "8.10.0"
+    ];
+
+    // Check if the current version matches one of the supported versions
+    return canFind(supportedVersions, curlVersion);
+}