From 83a2965d6b7b40575e7c0b060540ff6cd084b1ba Mon Sep 17 00:00:00 2001 From: NiLuJe Date: Sat, 17 Sep 2022 00:08:00 +0200 Subject: [PATCH] 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 | 15 ++++++---- .../apps/reader/modules/readerdictionary.lua | 6 ++-- frontend/ui/otamanager.lua | 3 +- frontend/ui/translator.lua | 5 ++-- frontend/ui/wikipedia.lua | 7 +++-- plugins/exporter.koplugin/target/readwise.lua | 5 ++-- .../epubdownloadbackend.lua | 10 +++---- .../internaldownloadbackend.lua | 30 +++++++++++-------- .../luahttpdownloadbackend.lua | 2 +- plugins/opds.koplugin/opdsbrowser.lua | 27 +++++++++-------- plugins/wallabag.koplugin/main.lua | 14 +++++---- 11 files changed, 71 insertions(+), 53 deletions(-) diff --git a/frontend/apps/cloudstorage/webdavapi.lua b/frontend/apps/cloudstorage/webdavapi.lua index 917022f6b..92381afbc 100644 --- a/frontend/apps/cloudstorage/webdavapi.lua +++ b/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 diff --git a/frontend/apps/reader/modules/readerdictionary.lua b/frontend/apps/reader/modules/readerdictionary.lua index fb1ee2f02..a092be6eb 100644 --- a/frontend/apps/reader/modules/readerdictionary.lua +++ b/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, diff --git a/frontend/ui/otamanager.lua b/frontend/ui/otamanager.lua index ad344ba19..33e273d37 100644 --- a/frontend/ui/otamanager.lua +++ b/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 diff --git a/frontend/ui/translator.lua b/frontend/ui/translator.lua index 9b63ab676..b9ef74fa9 100644 --- a/frontend/ui/translator.lua +++ b/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 diff --git a/frontend/ui/wikipedia.lua b/frontend/ui/wikipedia.lua index 445c2ddcd..4077de287 100644 --- a/frontend/ui/wikipedia.lua +++ b/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 diff --git a/plugins/exporter.koplugin/target/readwise.lua b/plugins/exporter.koplugin/target/readwise.lua index 6b3f16144..77c7992a3 100644 --- a/plugins/exporter.koplugin/target/readwise.lua +++ b/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 diff --git a/plugins/newsdownloader.koplugin/epubdownloadbackend.lua b/plugins/newsdownloader.koplugin/epubdownloadbackend.lua index adfd93924..ec35d950e 100644 --- a/plugins/newsdownloader.koplugin/epubdownloadbackend.lua +++ b/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 diff --git a/plugins/newsdownloader.koplugin/internaldownloadbackend.lua b/plugins/newsdownloader.koplugin/internaldownloadbackend.lua index 68499b1e1..7c9486f21 100644 --- a/plugins/newsdownloader.koplugin/internaldownloadbackend.lua +++ b/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 diff --git a/plugins/newsdownloader.koplugin/luahttpdownloadbackend.lua b/plugins/newsdownloader.koplugin/luahttpdownloadbackend.lua index 9fe864ef1..801ecd493 100644 --- a/plugins/newsdownloader.koplugin/luahttpdownloadbackend.lua +++ b/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 diff --git a/plugins/opds.koplugin/opdsbrowser.lua b/plugins/opds.koplugin/opdsbrowser.lua index 4e7725c71..5a3a77546 100644 --- a/plugins/opds.koplugin/opdsbrowser.lua +++ b/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 diff --git a/plugins/wallabag.koplugin/main.lua b/plugins/wallabag.koplugin/main.lua index 9033c1905..5e743d768 100644 --- a/plugins/wallabag.koplugin/main.lua +++ b/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)