[core] improve write retry handling

* Add a proper delay before retrying a write operation and increase retry count to 4
* Add retries when clearing boot records or when zeroing a drive
* Also improve log output from USB device reset

ChangeLog.txt

@@ -1,3 +1,11 @@
+o Version 3.1 (2018.06.??)
+    Fix ISO content not being extracted with GRUB based ISOs (Manjaro, Kaspersky, etc.)
+    Fix text being truncated on some dialogs (mostly for Russian and Thai)
+    Add detection & warning about the 'Controlled Folder Access' Windows 10 feature
+    Improve retry attempts for transient errors
+    Update GRUB 2.0 and Grub4DOS to latest
+    Update libcdio to latest
+
 o Version 3.0 (2018.05.29)
     UI redesign to follow the flow of user operations (with thanks to Fahad Al-Riyami for the concept)
     Drop XP and Vista platform support

src/dev.c

@@ -141,8 +141,10 @@ BOOL ResetDevice(int index)
 		return FALSE;
 	}
 
-	if (DriveHub.String[index] == NULL)
+	if (DriveHub.String[index] == NULL) {
+		uprintf("The device you are trying to reset does not appear to be a USB device...");
 		return FALSE;
+	}
 
 	LastReset = GetTickCount64();
 
@@ -162,6 +164,7 @@ BOOL ResetDevice(int index)
 		uprintf("  Failed to cycle port: %s", WindowsErrorString());
 		goto out;
 	}
+	uprintf("Please wait for the device to re-appear...");
 	r = TRUE;
 
 out:

src/format.c

@@ -815,7 +815,7 @@ out:
 static BOOL ClearMBRGPT(HANDLE hPhysicalDrive, LONGLONG DiskSize, DWORD SectorSize, BOOL add1MB)
 {
 	BOOL r = FALSE;
-	uint64_t i, last_sector = DiskSize/SectorSize, num_sectors_to_clear;
+	uint64_t i, j, last_sector = DiskSize/SectorSize, num_sectors_to_clear;
 	unsigned char* pBuf = (unsigned char*) calloc(SectorSize, 1);
 
 	PrintInfoDebug(0, MSG_224);
@@ -839,13 +839,29 @@ static BOOL ClearMBRGPT(HANDLE hPhysicalDrive, LONGLONG DiskSize, DWORD SectorSi
 
 	uprintf("Erasing %d sectors", num_sectors_to_clear);
 	for (i=0; i<num_sectors_to_clear; i++) {
-		if ((IS_ERROR(FormatStatus)) || (write_sectors(hPhysicalDrive, SectorSize, i, 1, pBuf) != SectorSize)) {
+		for (j = 1; j <= WRITE_RETRIES; j++) {
+			if (IS_ERROR(FormatStatus))
 				goto out;
+			if (write_sectors(hPhysicalDrive, SectorSize, i, 1, pBuf) != SectorSize) {
+				if (j < WRITE_RETRIES) {
+					uprintf("Retrying in %d seconds...", WRITE_TIMEOUT / 1000);
+					Sleep(WRITE_TIMEOUT);
+				} else
+					goto out;
+			}
 		}
 	}
 	for (i = last_sector - MAX_SECTORS_TO_CLEAR; i < last_sector; i++) {
-		if ((IS_ERROR(FormatStatus)) || (write_sectors(hPhysicalDrive, SectorSize, i, 1, pBuf) != SectorSize)) {
+		for (j = 1; j <= WRITE_RETRIES; j++) {
+			if (IS_ERROR(FormatStatus))
 				goto out;
+			if (write_sectors(hPhysicalDrive, SectorSize, i, 1, pBuf) != SectorSize) {
+				if (j < WRITE_RETRIES) {
+					uprintf("Retrying in %d seconds...", WRITE_TIMEOUT / 1000);
+					Sleep(WRITE_TIMEOUT);
+				} else
+					goto out;
+			}
 		}
 	}
 	r = TRUE;
@@ -1583,7 +1599,7 @@ static BOOL WriteDrive(HANDLE hPhysicalDrive, HANDLE hSourceImage)
 				s = ReadFile(hSourceImage, buffer, BufSize, &rSize, NULL);
 				if (!s) {
 					FormatStatus = ERROR_SEVERITY_ERROR | FAC(FACILITY_STORAGE) | ERROR_READ_FAULT;
-					uprintf("read error: %s", WindowsErrorString());
+					uprintf("Read error: %s", WindowsErrorString());
 					goto out;
 				}
 				if (rSize == 0)
@@ -1597,20 +1613,21 @@ static BOOL WriteDrive(HANDLE hPhysicalDrive, HANDLE hSourceImage)
 			// WriteFile fails unless the size is a multiple of sector size
 			if (rSize % SelectedDrive.SectorSize != 0)
 				rSize = ((rSize + SelectedDrive.SectorSize - 1) / SelectedDrive.SectorSize) * SelectedDrive.SectorSize;
-			for (i = 0; i < WRITE_RETRIES; i++) {
+			for (i = 1; i <= WRITE_RETRIES; i++) {
 				CHECK_FOR_USER_CANCEL;
 				s = WriteFile(hPhysicalDrive, buffer, rSize, &wSize, NULL);
 				if ((s) && (wSize == rSize))
 					break;
 				if (s)
-					uprintf("write error: Wrote %d bytes, expected %d bytes", wSize, rSize);
+					uprintf("Write error: Wrote %d bytes, expected %d bytes", wSize, rSize);
 				else
-					uprintf("write error at sector %" PRIi64 ": %s", wb / SelectedDrive.SectorSize, WindowsErrorString());
+					uprintf("Write error at sector %" PRIi64 ": %s", wb / SelectedDrive.SectorSize, WindowsErrorString());
-				if (i < WRITE_RETRIES - 1) {
+				if (i < WRITE_RETRIES) {
 					li.QuadPart = wb;
-					uprintf("  RETRYING...\n");
+					uprintf("Retrying in %d seconds...", WRITE_TIMEOUT / 1000);
+					Sleep(WRITE_TIMEOUT);
 					if (!SetFilePointerEx(hPhysicalDrive, li, NULL, FILE_BEGIN)) {
-						uprintf("write error: could not reset position - %s", WindowsErrorString());
+						uprintf("Write error: Could not reset position - %s", WindowsErrorString());
 						goto out;
 					}
 				} else {
@@ -1619,7 +1636,8 @@ static BOOL WriteDrive(HANDLE hPhysicalDrive, HANDLE hSourceImage)
 				}
 				Sleep(200);
 			}
-			if (i >= WRITE_RETRIES) goto out;
+			if (i > WRITE_RETRIES)
+				goto out;
 		}
 	}
 	RefreshDriveLayout(hPhysicalDrive);
@@ -2105,7 +2123,7 @@ DWORD WINAPI SaveImageThread(void* param)
 			NULL, OPEN_EXISTING, FILE_FLAG_SEQUENTIAL_SCAN, NULL);
 		break;
 	default:
-		uprintf("invalid image type");
+		uprintf("Invalid image type");
 	}
 	if (hPhysicalDrive == INVALID_HANDLE_VALUE) {
 		FormatStatus = ERROR_SEVERITY_ERROR|FAC(FACILITY_STORAGE)|ERROR_OPEN_FAILED;
@@ -2149,7 +2167,7 @@ DWORD WINAPI SaveImageThread(void* param)
 			(DWORD)MIN(img_save->BufSize, img_save->DeviceSize - wb), &rSize, NULL);
 		if (!s) {
 			FormatStatus = ERROR_SEVERITY_ERROR|FAC(FACILITY_STORAGE)|ERROR_READ_FAULT;
-			uprintf("read error: %s", WindowsErrorString());
+			uprintf("Read error: %s", WindowsErrorString());
 			goto out;
 		}
 		if (rSize == 0)
@@ -2160,20 +2178,21 @@ DWORD WINAPI SaveImageThread(void* param)
 			PrintInfo(0, MSG_261, format_percent);
 			UpdateProgress(OP_FORMAT, format_percent);
 		}
-		for (i=0; i<WRITE_RETRIES; i++) {
+		for (i = 1; i <= WRITE_RETRIES; i++) {
 			CHECK_FOR_USER_CANCEL;
 			s = WriteFile(hDestImage, buffer, rSize, &wSize, NULL);
 			if ((s) && (wSize == rSize))
 				break;
 			if (s)
-				uprintf("write error: Wrote %d bytes, expected %d bytes\n", wSize, rSize);
+				uprintf("Write error: Wrote %d bytes, expected %d bytes", wSize, rSize);
 			else
-				uprintf("write error: %s", WindowsErrorString());
+				uprintf("Write error: %s", WindowsErrorString());
-			if (i < WRITE_RETRIES-1) {
+			if (i < WRITE_RETRIES) {
 				li.QuadPart = wb;
-				uprintf("  RETRYING...\n");
+				uprintf("Retrying in %d seconds...", WRITE_TIMEOUT / 1000);
+				Sleep(WRITE_TIMEOUT);
 				if (!SetFilePointerEx(hDestImage, li, NULL, FILE_BEGIN)) {
-					uprintf("write error: could not reset position - %s", WindowsErrorString());
+					uprintf("Write error: Could not reset position - %s", WindowsErrorString());
 					goto out;
 				}
 			} else {
@@ -2182,7 +2201,8 @@ DWORD WINAPI SaveImageThread(void* param)
 			}
 			Sleep(200);
 		}
-		if (i >= WRITE_RETRIES) goto out;
+		if (i > WRITE_RETRIES)
+			goto out;
 	}
 	if (wb != img_save->DeviceSize) {
 		uprintf("Error: wrote %s, expected %s", SizeToHumanReadable(wb, FALSE, FALSE),

src/rufus.h

@@ -62,7 +62,8 @@
 #define MAX_SECTORS_TO_CLEAR        128			// nb sectors to zap when clearing the MBR/GPT (must be >34)
 #define MBR_UEFI_MARKER             0x49464555	// 'U', 'E', 'F', 'I', as a 32 bit little endian longword
 #define STATUS_MSG_TIMEOUT          3500		// How long should cheat mode messages appear for on the status bar
-#define WRITE_RETRIES               3
+#define WRITE_RETRIES               4
+#define WRITE_TIMEOUT               5000		// How long we should wait between write retries
 #define MARQUEE_TIMER_REFRESH       10			// Time between progress bar marquee refreshes, in ms
 #define FS_DEFAULT                  FS_FAT32
 #define SINGLE_CLUSTERSIZE_DEFAULT  0x00000100

src/rufus.rc

@@ -33,7 +33,7 @@ LANGUAGE LANG_NEUTRAL, SUBLANG_NEUTRAL
 IDD_DIALOG DIALOGEX 12, 12, 232, 326
 STYLE DS_SETFONT | DS_MODALFRAME | DS_CENTER | WS_MINIMIZEBOX | WS_POPUP | WS_CAPTION | WS_SYSMENU
 EXSTYLE WS_EX_ACCEPTFILES
-CAPTION "Rufus 3.1.1316"
+CAPTION "Rufus 3.1.1317"
 FONT 9, "Segoe UI Symbol", 400, 0, 0x0
 BEGIN
     LTEXT           "Drive Properties",IDS_DRIVE_PROPERTIES_TXT,8,6,53,12,NOT WS_GROUP
@@ -389,8 +389,8 @@ END
 //
 
 VS_VERSION_INFO VERSIONINFO
- FILEVERSION 3,1,1316,0
+ FILEVERSION 3,1,1317,0
- PRODUCTVERSION 3,1,1316,0
+ PRODUCTVERSION 3,1,1317,0
  FILEFLAGSMASK 0x3fL
 #ifdef _DEBUG
  FILEFLAGS 0x1L
@@ -407,13 +407,13 @@ BEGIN
         BEGIN
             VALUE "CompanyName", "Akeo Consulting (http://akeo.ie)"
             VALUE "FileDescription", "Rufus"
-            VALUE "FileVersion", "3.1.1316"
+            VALUE "FileVersion", "3.1.1317"
             VALUE "InternalName", "Rufus"
             VALUE "LegalCopyright", "© 2011-2018 Pete Batard (GPL v3)"
             VALUE "LegalTrademarks", "http://www.gnu.org/copyleft/gpl.html"
             VALUE "OriginalFilename", "rufus.exe"
             VALUE "ProductName", "Rufus"
-            VALUE "ProductVersion", "3.1.1316"
+            VALUE "ProductVersion", "3.1.1317"
         END
     END
     BLOCK "VarFileInfo"

src/stdio.c

@@ -339,19 +339,18 @@ BOOL WriteFileWithRetry(HANDLE hFile, LPCVOID lpBuffer, DWORD nNumberOfBytesToWr
 	DWORD nTry;
 	BOOL readFilePointer;
 	LARGE_INTEGER liFilePointer, liZero = { { 0,0 } };
-	static char* retry_msg = " - retrying...";
 
 	// Need to get the current file pointer in case we need to retry
 	readFilePointer = SetFilePointerEx(hFile, liZero, &liFilePointer, FILE_CURRENT);
 	if (!readFilePointer)
-		uprintf("  Warning - Could not read file pointer: %s", WindowsErrorString());
+		uprintf("Warning: Could not read file pointer: %s", WindowsErrorString());
 
 	if (nNumRetries == 0)
 		nNumRetries = 1;
 	for (nTry = 1; nTry <= nNumRetries; nTry++) {
 		// Need to rewind our file position on retry - if we can't even do that, just give up
 		if ((nTry > 1) && (!SetFilePointerEx(hFile, liFilePointer, NULL, FILE_BEGIN))) {
-			uprintf("  Could not set file pointer - aborting");
+			uprintf("Could not set file pointer - Aborting");
 			break;
 		}
 		if (WriteFile(hFile, lpBuffer, nNumberOfBytesToWrite, lpNumberOfBytesWritten, NULL)) {
@@ -362,15 +361,17 @@ BOOL WriteFileWithRetry(HANDLE hFile, LPCVOID lpBuffer, DWORD nNumberOfBytesToWr
 				uprintf("Warning: Possible short write");
 				return TRUE;
 			}
-			uprintf("  Wrote %d bytes but requested %d%s", *lpNumberOfBytesWritten,
+			uprintf("Wrote %d bytes but requested %d", *lpNumberOfBytesWritten, nNumberOfBytesToWrite);
-				nNumberOfBytesToWrite, nTry < nNumRetries ? retry_msg : "");
 		} else {
-			uprintf("  Write error [0x%08X]%s", GetLastError(), nTry < nNumRetries ? retry_msg : "");
+			uprintf("Write error [0x%08X]", GetLastError());
 		}
 		// If we can't reposition for the next run, just abort
 		if (!readFilePointer)
 			break;
-		Sleep(200);
+		if (nTry < nNumRetries) {
+			uprintf("Retrying in %d seconds...", WRITE_TIMEOUT / 1000);
+			Sleep(WRITE_TIMEOUT);
+		}
 	}
 	if (SCODE_CODE(GetLastError()) == ERROR_SUCCESS)
 		SetLastError(ERROR_SEVERITY_ERROR|FAC(FACILITY_STORAGE)|ERROR_WRITE_FAULT);