Misc: Unify error logging on network errors (#9523)

Making sure we get the relevant information in the logs, and that the UI feedback (if any), is meaningful and readable.

frontend/apps/cloudstorage/webdavapi.lua

@@ -92,14 +92,16 @@ function WebDavApi:listFolder(address, user, pass, folder_path)
         source   = ltn12.source.string(data),
         sink     = ltn12.sink.table(sink),
     }
-    local headers_request = socket.skip(1, http.request(request))
+    local code, headers, status = socket.skip(1, http.request(request))
     socketutil:reset_timeout()
-    if headers_request == nil then
+    if headers == nil then
+        logger.dbg("WebDavApi:listFolder: No response:", status or code)
         return nil
-    elseif headers_request < 200 or headers_request >= 300 then
+    elseif not code or code < 200 or code > 299 then
         -- got a response, but it wasn't a success (e.g. auth failure)
-        logger.dbg(headers_request)
-        logger.dbg(table.concat(sink))
+        logger.dbg("WebDavApi:listFolder: Request failed:", status or code)
+        logger.dbg("WebDavApi:listFolder: Response headers:", headers)
+        logger.dbg("WebDavApi:listFolder: Response body:", table.concat(sink))
         return nil
     end
 
@@ -165,7 +167,7 @@ end
 function WebDavApi:downloadFile(file_url, user, pass, local_path)
     socketutil:set_timeout(socketutil.FILE_BLOCK_TIMEOUT, socketutil.FILE_TOTAL_TIMEOUT)
     logger.dbg("WebDavApi: downloading file: ", file_url)
-    local code, _, status = socket.skip(1, http.request{
+    local code, headers, status = socket.skip(1, http.request{
         url      = file_url,
         method   = "GET",
         sink     = ltn12.sink.file(io.open(local_path, "w")),
@@ -175,6 +177,7 @@ function WebDavApi:downloadFile(file_url, user, pass, local_path)
     socketutil:reset_timeout()
     if code ~= 200 then
         logger.warn("WebDavApi: Download failure:", status or code or "network unreachable")
+        logger.dbg("WebDavApi: Response headers:", headers)
     end
     return code
 end

frontend/apps/reader/modules/readerdictionary.lua

@@ -1104,14 +1104,16 @@ function ReaderDictionary:downloadDictionary(dict, download_location, continue)
     end
 
     socketutil:set_timeout(socketutil.FILE_BLOCK_TIMEOUT, socketutil.FILE_TOTAL_TIMEOUT)
-    local c = socket.skip(1, http.request{
+    local code, headers, status = socket.skip(1, http.request{
         url     = dict.url,
         sink    = ltn12.sink.file(io.open(download_location, "w")),
     })
     socketutil:reset_timeout()
-    if c == 200 then
+    if code == 200 then
         logger.dbg("file downloaded to", download_location)
     else
+        logger.dbg("ReaderDictionary: Request failed:", status or code)
+        logger.dbg("ReaderDictionary: Response headers:", headers)
         UIManager:show(InfoMessage:new{
             text = _("Could not save file to:\n") .. BD.filepath(download_location),
             --timeout = 3,

frontend/ui/otamanager.lua

@@ -161,13 +161,14 @@ function OTAManager:checkUpdate()
     -- download zsync file from OTA server
     logger.dbg("downloading update file", ota_update_file)
     socketutil:set_timeout()
-    local code, _, status = socket.skip(1, http.request{
+    local code, headers, status = socket.skip(1, http.request{
         url     = ota_update_file,
         sink    = ltn12.sink.file(io.open(local_update_file, "w")),
     })
     socketutil:reset_timeout()
     if code ~= 200 then
         logger.warn("cannot find update file:", status or code or "network unreachable")
+        logger.dbg("Response headers:", headers)
         return
     end
     -- parse OTA package version

frontend/ui/translator.lua

@@ -386,11 +386,12 @@ function Translator:loadPage(text, target_lang, source_lang)
 
     -- raise error message when network is unavailable
     if headers == nil then
-        error("Network is unreachable")
+        error(status or code or "network unreachable")
     end
 
     if code ~= 200 then
-        logger.warn("translator HTTP status not okay:", status)
+        logger.warn("translator HTTP status not okay:", status or code or "network unreachable")
+        logger.dbg("Response headers:", headers)
         return
     end
 

frontend/ui/wikipedia.lua

@@ -133,11 +133,12 @@ local function getUrlContent(url, timeout, maxtime)
         return false, code
     end
     if headers == nil then
-        logger.warn("No HTTP headers:", code, status)
+        logger.warn("No HTTP headers:", status or code or "network unreachable")
         return false, "Network or remote server unavailable"
     end
-    if not code or string.sub(code, 1, 1) ~= "2" then -- all 200..299 HTTP codes are OK
-        logger.warn("HTTP status not okay:", code, status)
+    if not code or code < 200 or code > 299 then -- all 200..299 HTTP codes are OK
+        logger.warn("HTTP status not okay:", status or code or "network unreachable")
+        logger.dbg("Response headers:", headers)
         return false, "Remote server error or unavailable"
     end
     if headers and headers["content-length"] then

plugins/exporter.koplugin/target/readwise.lua

@@ -30,11 +30,12 @@ local function makeRequest(endpoint, method, request_body, token)
             ["Authorization"] = "Token " .. token
         },
     }
-    local code, _, status = socket.skip(1, http.request(request))
+    local code, headers, status = socket.skip(1, http.request(request))
     socketutil:reset_timeout()
 
     if code ~= 200 then
-        logger.warn("Readwise: HTTP response code <> 200. Response status: ", status)
+        logger.warn("Readwise: HTTP response code <> 200. Response status:", status or code or "network unreachable")
+        logger.dbg("Response headers:", headers)
         return nil, status
     end
 

plugins/newsdownloader.koplugin/epubdownloadbackend.lua

@@ -103,14 +103,14 @@ local function getUrlContent(url, timeout, maxtime, redirectCount)
        code == socketutil.SSL_HANDSHAKE_CODE or
        code == socketutil.SINK_TIMEOUT_CODE
     then
-        logger.warn("request interrupted:", code)
+        logger.warn("request interrupted:", status or code)
         return false, code
     end
     if headers == nil then
-        logger.warn("No HTTP headers:", code, status)
+        logger.warn("No HTTP headers:", status or code or "network unreachable")
         return false, "Network or remote server unavailable"
     end
-    if not code or string.sub(code, 1, 1) ~= "2" then -- all 200..299 HTTP codes are OK
+    if not code or code < 200 or code > 299 then -- all 200..299 HTTP codes are OK
         if code and code > 299 and code < 400  and headers and headers.location then -- handle 301, 302...
            local redirected_url = headers.location
            local parsed_redirect_location = socket_url.parse(redirected_url)
@@ -122,9 +122,9 @@ local function getUrlContent(url, timeout, maxtime, redirectCount)
            logger.dbg("getUrlContent: Redirecting to url: ", redirected_url)
            return getUrlContent(redirected_url, timeout, maxtime, redirectCount + 1)
         else
-           error("EpubDownloadBackend: Don't know how to handle HTTP response status: ", status)
+           error("EpubDownloadBackend: Don't know how to handle HTTP response status:", status or code)
         end
-        logger.warn("HTTP status not okay:", code, status)
+        logger.warn("HTTP status not okay:", status or code)
         return false, "Remote server error or unavailable"
     end
     if headers and headers["content-length"] then

plugins/newsdownloader.koplugin/internaldownloadbackend.lua

@@ -5,15 +5,15 @@ local socket = require("socket")
 local socketutil = require("socketutil")
 
 local InternalDownloadBackend = {}
-local max_redirects = 5; --prevent infinite redirects
+local max_redirects = 5 --prevent infinite redirects
 
 function InternalDownloadBackend:getResponseAsString(url, redirectCount)
     if not redirectCount then
         redirectCount = 0
     elseif redirectCount == max_redirects then
-        error("InternalDownloadBackend: reached max redirects: ", redirectCount)
+        error("InternalDownloadBackend: reached max redirects:", redirectCount)
     end
-    logger.dbg("InternalDownloadBackend: url :", url)
+    logger.dbg("InternalDownloadBackend: url:", url)
     local sink = {}
     socketutil:set_timeout(socketutil.LARGE_BLOCK_TIMEOUT, socketutil.LARGE_TOTAL_TIMEOUT)
     local request = {
@@ -24,23 +24,27 @@ function InternalDownloadBackend:getResponseAsString(url, redirectCount)
     socketutil:reset_timeout()
 
     if code ~= 200 then
-        logger.dbg("InternalDownloadBackend: HTTP response code <> 200. Response status: ", status)
-        if code and code > 299 and code < 400  and headers and headers["location"] then -- handle 301, 302...
-           local redirected_url = headers["location"]
-           logger.dbg("InternalDownloadBackend: Redirecting to url: ", redirected_url)
-           return self:getResponseAsString(redirected_url, redirectCount + 1)
+        logger.dbg("InternalDownloadBackend: HTTP response code <> 200. Response status:", status or code)
+        if code and code > 299 and code < 400 and headers and headers.location then -- handle 301, 302...
+            local redirected_url = headers.location
+            logger.dbg("InternalDownloadBackend: Redirecting to url:", redirected_url)
+            return self:getResponseAsString(redirected_url, redirectCount + 1)
         else
-           error("InternalDownloadBackend: Don't know how to handle HTTP response status: ", status)
+            logger.dbg("InternalDownloadBackend: Unhandled response status:", status or code)
+            logger.dbg("InternalDownloadBackend: Response headers:", headers)
+            error("InternalDownloadBackend: Don't know how to handle HTTP response status:", status or code)
         end
     end
     return table.concat(sink)
 end
 
 function InternalDownloadBackend:download(url, path)
-   local response = self:getResponseAsString(url)
-   local file = io.open(path, 'w')
-   file:write(response)
-   file:close()
+    local response = self:getResponseAsString(url)
+    local file = io.open(path, 'w')
+    if file then
+        file:write(response)
+        file:close()
+    end
 end
 
 return InternalDownloadBackend

plugins/newsdownloader.koplugin/luahttpdownloadbackend.lua

@@ -7,7 +7,7 @@ local LuaHttpDownloadBackend = {}
 function LuaHttpDownloadBackend:getResponseAsString(url)
    local _, stream = assert(http_request.new_from_uri(url):go())
    local body = assert(stream:get_body_as_string())
-   logger.dbg("Response body :", body)
+   logger.dbg("Response body:", body)
    return body
 end
 

plugins/opds.koplugin/opdsbrowser.lua

@@ -298,11 +298,11 @@ function OPDSBrowser:fetchFeed(item_url, username, password, method)
     }
     logger.dbg("Request:", request)
     -- Fire off the request and wait to see what we get back.
-    local code, headers = socket.skip(1, http.request(request))
+    local code, headers, status = socket.skip(1, http.request(request))
     socketutil:reset_timeout()
     -- Check the response and raise error message when network is unavailable.
     if headers == nil then
-        error(code)
+        error(status or code or "network unreachable")
     end
     -- Below are numerous if cases to handle different response codes.
     if code == 200 then
@@ -331,7 +331,7 @@ function OPDSBrowser:fetchFeed(item_url, username, password, method)
     elseif code == 301 then -- Page has permanently moved
         UIManager:show(InfoMessage:new{
             text = T(_("The catalog has been permanently moved. Please update catalog URL to '%1'."),
-                     BD.url(headers['Location'])),
+                     BD.url(headers.location)),
         })
     elseif code == 302
         and item_url:match("^https")
@@ -362,7 +362,7 @@ function OPDSBrowser:fetchFeed(item_url, username, password, method)
         -- This block handles all other requests and supplies the user with a generic
         -- error message and no more information than the code.
         UIManager:show(InfoMessage:new{
-            text = T(_("Cannot get catalog. Server response code %1."), code),
+            text = T(_("Cannot get catalog. Server response status: %1."), status or code),
         })
     end
 end
@@ -624,10 +624,10 @@ function OPDSBrowser:downloadFile(item, filename, remote_url)
             logger.dbg("Downloading file", local_path, "from", remote_url)
             local parsed = url.parse(remote_url)
 
-            local code, headers
+            local code, headers, status
             if parsed.scheme == "http" or parsed.scheme == "https" then
                 socketutil:set_timeout(socketutil.FILE_BLOCK_TIMEOUT, socketutil.FILE_TOTAL_TIMEOUT)
-                code, headers = socket.skip(1, http.request {
+                code, headers, status = socket.skip(1, http.request {
                     url         = remote_url,
                     headers     = {
                         ["Accept-Encoding"] = "identity",
@@ -640,7 +640,6 @@ function OPDSBrowser:downloadFile(item, filename, remote_url)
             else
                 UIManager:show(InfoMessage:new {
                     text = T(_("Invalid protocol:\n%1"), parsed.scheme),
-                    timeout = 3,
                 })
             end
 
@@ -657,9 +656,12 @@ function OPDSBrowser:downloadFile(item, filename, remote_url)
                 })
             else
                 util.removeFile(local_path)
+                logger.dbg("OPDSBrowser:downloadFile: Request failed:", status or code)
+                logger.dbg("OPDSBrowser:downloadFile: Response headers:", headers)
                 UIManager:show(InfoMessage:new {
-                    text = _("Could not save file to:\n") .. BD.filepath(local_path),
-                    timeout = 3,
+                    text = T(_("Could not save file to:\n%1\n%2"),
+                        BD.filepath(local_path),
+                        status or code or "network unreachable"),
                 })
             end
         end)
@@ -698,10 +700,10 @@ function OPDSBrowser:streamPages(item, remote_url, count)
             logger.dbg("Streaming page from", page_url)
             local parsed = url.parse(page_url)
 
-            local code
+            local code, headers, status
             if parsed.scheme == "http" or parsed.scheme == "https" then
                 socketutil:set_timeout(socketutil.FILE_BLOCK_TIMEOUT, socketutil.FILE_TOTAL_TIMEOUT)
-                code = socket.skip(1, http.request {
+                code, headers, status = socket.skip(1, http.request {
                     url         = page_url,
                     headers     = {
                         ["Accept-Encoding"] = "identity",
@@ -714,7 +716,6 @@ function OPDSBrowser:streamPages(item, remote_url, count)
             else
                 UIManager:show(InfoMessage:new {
                     text = T(_("Invalid protocol:\n%1"), parsed.scheme),
-                    timeout = 3,
                 })
             end
 
@@ -725,6 +726,8 @@ function OPDSBrowser:streamPages(item, remote_url, count)
                              or RenderImage:renderImageFile("resources/koreader.png", false)
                 return page_bb
             else
+                logger.dbg("OPDSBrowser:streamPages: Request failed:", status or code)
+                logger.dbg("OPDSBrowser:streamPages: Response headers:", headers)
                 local error_bb = RenderImage:renderImageFile("resources/koreader.png", false)
                 return error_bb
             end

plugins/wallabag.koplugin/main.lua

@@ -464,7 +464,7 @@ function Wallabag:getArticleList()
             -- we may have hit the last page, there are no more articles
             logger.dbg("Wallabag: couldn't get page #", page)
             break -- exit while loop
-        elseif err then
+        elseif err or articles_json == nil then
             -- another error has occured. Don't proceed with downloading
             -- or deleting articles
             logger.warn("Wallabag: download of page #", page, "failed with", err, code)
@@ -484,7 +484,7 @@ function Wallabag:getArticleList()
         new_article_list = self:filterIgnoredTags(new_article_list)
 
         -- Append the filtered list to the final article list
-        for i, article in ipairs(new_article_list) do
+        for _, article in ipairs(new_article_list) do
             if #article_list == self.articles_per_sync then
                 logger.dbg("Wallabag: hit the article target", self.articles_per_sync)
                 break
@@ -631,11 +631,11 @@ function Wallabag:callAPI(method, apiurl, headers, body, filepath, quiet)
     logger.dbg("Wallabag: URL     ", request.url)
     logger.dbg("Wallabag: method  ", method)
 
-    local code, resp_headers = socket.skip(1, http.request(request))
+    local code, resp_headers, status = socket.skip(1, http.request(request))
     socketutil:reset_timeout()
     -- raise error message when network is unavailable
     if resp_headers == nil then
-        logger.dbg("Wallabag: Server error: ", code)
+        logger.dbg("Wallabag: Server error:", status or code)
         return nil, "network_error"
     end
     if code == 200 then
@@ -665,12 +665,14 @@ function Wallabag:callAPI(method, apiurl, headers, body, filepath, quiet)
             local entry_mode = lfs.attributes(filepath, "mode")
             if entry_mode == "file" then
                 os.remove(filepath)
-                logger.dbg("Wallabag: Removed failed download: ", filepath)
+                logger.dbg("Wallabag: Removed failed download:", filepath)
             end
         elseif not quiet then
             UIManager:show(InfoMessage:new{
                 text = _("Communication with server failed."), })
         end
+        logger.dbg("Wallabag: Request failed:", status or code)
+        logger.dbg("Wallabag: Response headers:", resp_headers)
         return nil, "http_error", code
     end
 end
@@ -709,7 +711,7 @@ function Wallabag:synchronize()
     if self.access_token ~= "" then
         local articles = self:getArticleList()
         if articles then
-            logger.dbg("Wallabag: number of articles: ", #articles)
+            logger.dbg("Wallabag: number of articles:", #articles)
 
             info = InfoMessage:new{ text = _("Downloading articles…") }
             UIManager:show(info)