diff options
6 files changed, 429 insertions, 21 deletions
diff --git a/.coverage-baseline b/.coverage-baseline index 5e1b8b0..bcafd92 100644 --- a/.coverage-baseline +++ b/.coverage-baseline @@ -1 +1 @@ -2.69 +5.28 diff --git a/app/src/androidTest/java/org/terst/feedreader/readability/ReaderExtractorRetryTest.kt b/app/src/androidTest/java/org/terst/feedreader/readability/ReaderExtractorRetryTest.kt new file mode 100644 index 0000000..ef2d578 --- /dev/null +++ b/app/src/androidTest/java/org/terst/feedreader/readability/ReaderExtractorRetryTest.kt @@ -0,0 +1,127 @@ +package org.terst.feedreader.readability + +import androidx.test.ext.junit.runners.AndroidJUnit4 +import androidx.test.platform.app.InstrumentationRegistry +import kotlinx.coroutines.runBlocking +import okhttp3.mockwebserver.Dispatcher +import okhttp3.mockwebserver.MockResponse +import okhttp3.mockwebserver.MockWebServer +import okhttp3.mockwebserver.RecordedRequest +import java.util.concurrent.TimeUnit +import org.junit.After +import org.junit.Assert.assertTrue +import org.junit.Before +import org.junit.Test +import org.junit.runner.RunWith + +/** + * Extraction used to fail intermittently on perfectly ordinary articles. + * + * onPageFinished fires before the page has finished loading — observed at + * progress=25 — and injecting the extraction script at that point is a race: + * sometimes the DOM is ready enough, and sometimes evaluateJavascript hands + * back a bare "null" because the document is still being replaced. Measured at + * 2 failures in 6 attempts against the same URL, which is what produced a bug + * report reading only "extraction failed" for one article while others worked. + * + * The fix retries an unusable result rather than treating it as final. + * + * HONEST LIMITATION: this test does not reproduce that race. A page served from + * a local MockWebServer finishes loading before onPageFinished fires + * (progress=100 every time), and adding deliberately slow subresources does not + * help — WebView simply waits for them. The race needs a real remote page. + * Verified manually instead: against the reported URL the extractor scored 4/6 + * before the fix and 10/10 after. + * + * What this test IS worth keeping for: it asserts that repeated back-to-back + * extractions in one process all succeed, which guards the WebView + * create/destroy churn the retry loop now leans on, and would catch a + * regression that broke extraction outright. + */ +@RunWith(AndroidJUnit4::class) +class ReaderExtractorRetryTest { + + private lateinit var server: MockWebServer + + @Before + fun startServer() { + server = MockWebServer() + // A page served instantly from localhost finishes loading before + // onPageFinished fires (observed progress=100), which does NOT + // reproduce the bug. A real article is still pulling subresources at + // that point — the observed failure had progress=25. So the fixture + // references subresources the server deliberately dawdles over, which + // is what puts the document in the half-loaded state the extraction + // script used to be injected into. + server.dispatcher = object : Dispatcher() { + override fun dispatch(request: RecordedRequest): MockResponse { + val path = request.path.orEmpty() + return when { + path.startsWith("/slow") -> + MockResponse() + .setResponseCode(200) + .setHeader("Content-Type", "application/javascript") + .setBody("/* slow */") + .setBodyDelay(3, TimeUnit.SECONDS) + else -> + MockResponse().setResponseCode(200) + .setHeader("Content-Type", "text/html") + .setBody(article) + } + } + } + server.start() + } + + @After + fun stopServer() { + server.shutdown() + } + + // Enough real prose that Readability is in no doubt there is an article + // here; the failures under test are about timing, not content. + private val article = buildString { + append("<html><head><title>A perfectly ordinary article</title>") + // Subresources the server is slow to answer, so the page is still + // loading when onPageFinished fires. + append("<script src=\"/slow-a.js\"></script>") + append("<script src=\"/slow-b.js\"></script>") + append("</head><body><article>") + append("<h1>A perfectly ordinary article</h1>") + repeat(12) { + append( + "<p>This paragraph exists so that Readability has a comfortably large " + + "body of text to score, well above any minimum content threshold, so " + + "that a failure to extract can only be a timing problem rather than a " + + "judgement about whether this page contains an article at all.</p>" + ) + } + append("</article></body></html>") + } + + @Test + fun repeatedExtractionOfTheSamePageAlwaysSucceeds() { + val context = InstrumentationRegistry.getInstrumentation().targetContext + val attempts = 8 + val failures = mutableListOf<String>() + + repeat(attempts) { i -> + val url = server.url("/article-$i").toString() + when (val r = runBlocking { ReaderExtractor.extractResult(context, url) }) { + is ExtractionResult.Success -> + assertTrue( + "attempt ${i + 1} returned empty content", + !r.article.content.isNullOrBlank() + ) + is ExtractionResult.Failure -> + failures += "attempt ${i + 1}: ${r.reason.diagnostic()}" + } + } + + assertTrue( + "extraction is not reliable — ${failures.size}/$attempts failed:\n" + + failures.joinToString("\n"), + failures.isEmpty() + ) + } +} diff --git a/app/src/main/java/org/terst/feedreader/readability/ExtractionFailure.kt b/app/src/main/java/org/terst/feedreader/readability/ExtractionFailure.kt new file mode 100644 index 0000000..532b109 --- /dev/null +++ b/app/src/main/java/org/terst/feedreader/readability/ExtractionFailure.kt @@ -0,0 +1,64 @@ +package org.terst.feedreader.readability + +/** + * Why an extraction did not produce article content. + * + * Extraction used to fail silently: ReaderScreen did `extracted?.content?.let { }`, + * so a null result — whatever caused it — left the reader showing the raw feed + * content with nothing logged and nothing shown. The only way a failure ever + * surfaced was the user noticing and filing a bug report by hand, which could + * not say why either. + */ +sealed interface ExtractionFailure { + + /** The page load reported a transport-level error. */ + data class LoadError(val code: Int, val description: String?) : ExtractionFailure + + /** The server answered, but with an error status. */ + data class HttpError(val statusCode: Int, val reason: String?) : ExtractionFailure + + /** The page never finished loading within the budget. */ + data class TimedOut(val millis: Long) : ExtractionFailure + + /** Readability itself threw, or returned something unusable. */ + data class ReadabilityError(val message: String) : ExtractionFailure + + /** Readability ran but found no article body worth showing. */ + data object NoContent : ExtractionFailure + + /** The JS result could not be decoded. */ + data class BadResult(val raw: String) : ExtractionFailure +} + +private const val MILLIS_PER_SECOND = 1_000 + +/** + * How much of the raw JS payload a diagnostic keeps. The result can be tens of + * kilobytes; a bug report needs enough to recognise the shape of it, not all. + */ +private const val RAW_DIAGNOSTIC_CHARS = 200 + +/** A short, user-facing explanation. Shown in a snackbar and in bug reports. */ +fun ExtractionFailure.userMessage(): String = when (this) { + is ExtractionFailure.LoadError -> + "Couldn't load the page" + (description?.takeIf { it.isNotBlank() }?.let { " ($it)" } ?: "") + is ExtractionFailure.HttpError -> "Server returned HTTP $statusCode" + is ExtractionFailure.TimedOut -> "Page took longer than ${millis / MILLIS_PER_SECOND}s to load" + is ExtractionFailure.ReadabilityError -> "Couldn't parse the article ($message)" + ExtractionFailure.NoContent -> "No article text found on the page" + is ExtractionFailure.BadResult -> "Unexpected result from the page" +} + +/** + * A longer form for the bug report, carrying the detail the short message drops. + * Bug reports are the only channel for a failure the user has already lost, so + * this keeps the raw specifics rather than the tidy summary. + */ +fun ExtractionFailure.diagnostic(): String = when (this) { + is ExtractionFailure.LoadError -> "LoadError code=$code description=${description ?: "none"}" + is ExtractionFailure.HttpError -> "HttpError status=$statusCode reason=${reason ?: "none"}" + is ExtractionFailure.TimedOut -> "TimedOut after ${millis}ms" + is ExtractionFailure.ReadabilityError -> "ReadabilityError $message" + ExtractionFailure.NoContent -> "NoContent (Readability returned no usable body)" + is ExtractionFailure.BadResult -> "BadResult raw=${raw.take(RAW_DIAGNOSTIC_CHARS)}" +} diff --git a/app/src/main/java/org/terst/feedreader/readability/ReaderExtractor.kt b/app/src/main/java/org/terst/feedreader/readability/ReaderExtractor.kt index 03a7d7c..5061444 100644 --- a/app/src/main/java/org/terst/feedreader/readability/ReaderExtractor.kt +++ b/app/src/main/java/org/terst/feedreader/readability/ReaderExtractor.kt @@ -4,6 +4,9 @@ import android.annotation.SuppressLint import android.content.Context import android.os.Handler import android.os.Looper +import android.webkit.WebResourceError +import android.webkit.WebResourceRequest +import android.webkit.WebResourceResponse import android.webkit.WebView import android.webkit.WebViewClient import kotlinx.coroutines.Dispatchers @@ -24,6 +27,18 @@ data class ExtractedArticle( ) /** + * The outcome of an extraction: either usable content, or a reason it failed. + * + * extract() used to return a bare ExtractedArticle?, so every distinct failure + * — a dead host, an HTTP 403, a timeout, a Readability throw — arrived at the + * caller as the same null, and the caller dropped it. + */ +sealed interface ExtractionResult { + data class Success(val article: ExtractedArticle) : ExtractionResult + data class Failure(val reason: ExtractionFailure) : ExtractionResult +} + +/** * Runs Mozilla's Readability.js (vendored in assets/Readability.js, pinned * to release 0.6.0) against a page loaded in a hidden WebView, for feed * articles whose feedContentHtml is missing or too short to be the real @@ -38,6 +53,19 @@ object ReaderExtractor { // parsing failure, just not enough runway. 25s costs little (a spinner stays up slightly // longer on a truly dead page) against a real reduction in spurious extraction failures. private const val TIMEOUT_MS = 25_000L + + // onPageFinished fires while the page is still loading -- observed firing at + // progress=25 on a perfectly ordinary article. Injecting the script then is a + // race: sometimes the DOM is far enough along for Readability to work, and + // sometimes evaluateJavascript returns a bare "null" because the document is + // still being replaced underneath it. Measured at roughly 2 failures in 6 on + // the same URL, which is exactly what a user sees as "extraction randomly + // fails on some articles". + // + // So an unusable result is not final: retry a few times before giving up. + // The outer TIMEOUT_MS remains the real backstop. + private const val MAX_EVAL_ATTEMPTS = 6 + private const val EVAL_RETRY_DELAY_MS = 500L private val json = Json { ignoreUnknownKeys = true } // The vendored asset (~90KB) is identical every time regardless of which Context reads @@ -52,15 +80,31 @@ object ReaderExtractor { cachedReadabilityJs ?: context.assets.open("Readability.js").bufferedReader().use { it.readText() } .also { cachedReadabilityJs = it } - suspend fun extract(context: Context, url: String): ExtractedArticle? = - withTimeoutOrNull(TIMEOUT_MS) { + /** + * Extracts article content, or explains why it could not. + * + * A null from the inner call means the timeout fired, which is a distinct + * and common failure (a page whose load never completes) and deserves to + * say so rather than look like every other failure. + */ + suspend fun extractResult(context: Context, url: String): ExtractionResult { + val outcome = withTimeoutOrNull(TIMEOUT_MS) { withContext(Dispatchers.Main) { extractOnMainThread(context, url) } + } ?: return ExtractionResult.Failure(ExtractionFailure.TimedOut(TIMEOUT_MS)) + return outcome + } + + /** Back-compatible shim: content when it worked, null when it did not. */ + suspend fun extract(context: Context, url: String): ExtractedArticle? = + when (val r = extractResult(context, url)) { + is ExtractionResult.Success -> r.article + is ExtractionResult.Failure -> null } @SuppressLint("SetJavaScriptEnabled") - private suspend fun extractOnMainThread(context: Context, url: String): ExtractedArticle? = + private suspend fun extractOnMainThread(context: Context, url: String): ExtractionResult = suspendCancellableCoroutine { continuation -> val webView = WebView(context) webView.settings.javaScriptEnabled = true @@ -81,7 +125,7 @@ object ReaderExtractor { // This flag makes teardown happen exactly once no matter which path wins. var finished = false - fun finish(result: ExtractedArticle?) { + fun finish(result: ExtractionResult) { if (finished) return finished = true if (continuation.isActive) continuation.resume(result) @@ -89,6 +133,8 @@ object ReaderExtractor { webView.destroy() } + fun fail(reason: ExtractionFailure) = finish(ExtractionResult.Failure(reason)) + webView.webViewClient = object : WebViewClient() { override fun onPageFinished(view: WebView, finishedUrl: String) { val readabilityJs = loadReadabilityJs(context) @@ -383,6 +429,20 @@ object ReaderExtractor { })(); """.trimIndent() + evaluate(view, script, attempt = 1) + } + + /** + * Runs the extraction script, retrying while the result looks like + * the page simply was not ready yet. + * + * A Readability error is final -- retrying will not change what the + * parser thinks of the markup. A null result or empty content is + * not: both are what an injection against a half-loaded document + * produces, and the next attempt usually succeeds. + */ + private fun evaluate(view: WebView, script: String, attempt: Int) { + if (finished) return view.evaluateJavascript(script) { rawResult -> // evaluateJavascript's callback value is itself JSON-encoded (our // JSON.stringify(...) string comes back wrapped in an extra layer @@ -391,17 +451,58 @@ object ReaderExtractor { val article = unwrapped?.let { runCatching { json.decodeFromString<ExtractedArticle>(it) }.getOrNull() } - finish(article) + val usable = article != null && + article.error.isNullOrBlank() && + !article.content.isNullOrBlank() + + when { + usable -> finish(ExtractionResult.Success(article!!)) + + // Readability ran and objected: that verdict will not change. + article != null && !article.error.isNullOrBlank() -> + fail(ExtractionFailure.ReadabilityError(article.error)) + + attempt < MAX_EVAL_ATTEMPTS -> + view.postDelayed({ evaluate(view, script, attempt + 1) }, EVAL_RETRY_DELAY_MS) + + article == null -> + fail(ExtractionFailure.BadResult(rawResult ?: "null")) + + else -> fail(ExtractionFailure.NoContent) + } } } + // The four-argument onReceivedError this used to override is only + // called below API 23. minSdk is 26, so it never fired on any + // supported device: a failed load invoked nothing, hung for the + // full TIMEOUT_MS, and then surfaced as an indistinguishable + // null. These are the callbacks Android actually uses. + // + // isForMainFrame matters: a page routinely fails to load some + // tracker or font, and aborting extraction because an analytics + // script 404'd would break articles that render perfectly well. override fun onReceivedError( view: WebView, - errorCode: Int, - description: String?, - failingUrl: String? + request: WebResourceRequest, + error: WebResourceError + ) { + if (!request.isForMainFrame) return + fail(ExtractionFailure.LoadError(error.errorCode, error.description?.toString())) + } + + override fun onReceivedHttpError( + view: WebView, + request: WebResourceRequest, + errorResponse: WebResourceResponse ) { - finish(ExtractedArticle(error = description ?: "Failed to load $failingUrl")) + if (!request.isForMainFrame) return + fail( + ExtractionFailure.HttpError( + errorResponse.statusCode, + errorResponse.reasonPhrase + ) + ) } } diff --git a/app/src/main/java/org/terst/feedreader/ui/ReaderScreen.kt b/app/src/main/java/org/terst/feedreader/ui/ReaderScreen.kt index 165d421..c701a26 100644 --- a/app/src/main/java/org/terst/feedreader/ui/ReaderScreen.kt +++ b/app/src/main/java/org/terst/feedreader/ui/ReaderScreen.kt @@ -5,6 +5,7 @@ import android.content.ClipboardManager import android.content.Context import android.content.Intent import android.net.Uri +import android.util.Log import androidx.compose.foundation.layout.Box import androidx.compose.foundation.layout.Column import androidx.compose.foundation.layout.Row @@ -56,6 +57,9 @@ import androidx.compose.ui.unit.dp import androidx.compose.ui.viewinterop.AndroidView import kotlinx.coroutines.flow.first import kotlinx.coroutines.launch +import org.terst.feedreader.readability.ExtractionResult +import org.terst.feedreader.readability.diagnostic +import org.terst.feedreader.readability.userMessage import org.terst.feedreader.data.AppDatabase import org.terst.feedreader.data.ArticleEntity import org.terst.feedreader.data.DEFAULT_READER_FONT_SIZE_PX @@ -194,6 +198,10 @@ private fun ReaderContent( var readerContent by remember(articleId) { mutableStateOf<String?>(null) } var isReaderMode by remember(articleId) { mutableStateOf(false) } var isExtracting by remember(articleId) { mutableStateOf(false) } + // Non-null when the last extraction attempt failed. Keyed on articleId like + // the rest of the per-article state so a stale error cannot carry over to + // the next article. + var extractionError by remember(articleId) { mutableStateOf<String?>(null) } var isSaving by remember(articleId) { mutableStateOf(false) } var moreMenuExpanded by remember(articleId) { mutableStateOf(false) } var showBugReportDialog by remember(articleId) { mutableStateOf(false) } @@ -222,11 +230,24 @@ private fun ReaderContent( isReaderMode = true if (readerContent == null) { isExtracting = true - val extracted = ReaderExtractor.extract(context, loaded.link) + val result = ReaderExtractor.extractResult(context, loaded.link) isExtracting = false - extracted?.content?.let { - readerContent = it - db.articleDao().setExtractedContent(articleId, it) + when (result) { + is ExtractionResult.Success -> { + val content = result.article.content + if (content != null) { + readerContent = content + db.articleDao().setExtractedContent(articleId, content) + } + } + is ExtractionResult.Failure -> { + // Previously this branch did not exist: a failure was + // dropped, leaving the raw feed content on screen with + // no indication anything had gone wrong. + Log.w("ReaderExtractor", "extract failed for ${loaded.link}: ${result.reason.diagnostic()}") + extractionError = result.reason.userMessage() + snackbarHostState.showSnackbar(result.reason.userMessage()) + } } } } @@ -245,12 +266,20 @@ private fun ReaderContent( if (newEnabled) { if (readerContent == null) { isExtracting = true - val extracted = ReaderExtractor.extract(context, a.link) + val result = ReaderExtractor.extractResult(context, a.link) isExtracting = false - val content = extracted?.content - if (content != null) { - readerContent = content - db.articleDao().setExtractedContent(articleId, content) + when (result) { + is ExtractionResult.Success -> { + val content = result.article.content + if (content != null) { + readerContent = content + db.articleDao().setExtractedContent(articleId, content) + } + } + is ExtractionResult.Failure -> { + Log.w("ReaderExtractor", "extract failed for ${a.link}: ${result.reason.diagnostic()}") + extractionError = result.reason.userMessage() + } } } isReaderMode = true @@ -397,7 +426,12 @@ private fun ReaderContent( val a = currentArticle ?: return@DropdownMenuItem scope.launch { isExtracting = true - val extracted = ReaderExtractor.extract(context, a.link) + val reResult = ReaderExtractor.extractResult(context, a.link) + val extracted = (reResult as? ExtractionResult.Success)?.article + if (reResult is ExtractionResult.Failure) { + Log.w("ReaderExtractor", "re-extract failed for ${a.link}: ${reResult.reason.diagnostic()}") + extractionError = reResult.reason.userMessage() + } isExtracting = false val content = extracted?.content if (content != null) { @@ -406,7 +440,7 @@ private fun ReaderContent( db.articleDao().setExtractedContent(a.id, content) snackbarHostState.showSnackbar("Re-extracted") } else { - snackbarHostState.showSnackbar("Re-extraction failed") + snackbarHostState.showSnackbar(extractionError ?: "Re-extraction failed") } } } diff --git a/app/src/test/java/org/terst/feedreader/readability/ExtractionFailureTest.kt b/app/src/test/java/org/terst/feedreader/readability/ExtractionFailureTest.kt new file mode 100644 index 0000000..6f691fd --- /dev/null +++ b/app/src/test/java/org/terst/feedreader/readability/ExtractionFailureTest.kt @@ -0,0 +1,82 @@ +package org.terst.feedreader.readability + +import org.junit.Assert.assertEquals +import org.junit.Assert.assertTrue +import org.junit.Test + +/** + * Extraction failures used to be discarded entirely — ReaderScreen did + * `extracted?.content?.let { }`, so any failure left the reader silently showing + * the raw feed content. The bug report that prompted this could say only + * "extraction failed", because the app itself never knew why. + * + * These pin the two things a failure has to produce: something short enough to + * put in front of the user, and something specific enough to debug from. + */ +class ExtractionFailureTest { + + @Test + fun `load error names the underlying description`() { + val f = ExtractionFailure.LoadError(-2, "net::ERR_NAME_NOT_RESOLVED") + assertEquals("Couldn't load the page (net::ERR_NAME_NOT_RESOLVED)", f.userMessage()) + assertTrue(f.diagnostic().contains("code=-2")) + assertTrue(f.diagnostic().contains("ERR_NAME_NOT_RESOLVED")) + } + + @Test + fun `load error without a description still reads properly`() { + assertEquals("Couldn't load the page", ExtractionFailure.LoadError(-1, null).userMessage()) + assertEquals("Couldn't load the page", ExtractionFailure.LoadError(-1, " ").userMessage()) + } + + @Test + fun `http error names the status`() { + val f = ExtractionFailure.HttpError(403, "Forbidden") + assertEquals("Server returned HTTP 403", f.userMessage()) + assertTrue(f.diagnostic().contains("status=403")) + } + + @Test + fun `timeout is reported in seconds`() { + assertEquals("Page took longer than 25s to load", ExtractionFailure.TimedOut(25_000).userMessage()) + assertTrue(ExtractionFailure.TimedOut(25_000).diagnostic().contains("25000ms")) + } + + @Test + fun `readability error carries the thrown message`() { + val f = ExtractionFailure.ReadabilityError("TypeError: x is null") + assertTrue(f.userMessage().contains("TypeError")) + assertTrue(f.diagnostic().contains("TypeError")) + } + + @Test + fun `no content is distinct from an error`() { + assertEquals("No article text found on the page", ExtractionFailure.NoContent.userMessage()) + } + + // The raw JS result can be enormous; a diagnostic that pastes all of it is + // unusable in a bug report. + @Test + fun `bad result truncates the raw payload`() { + val f = ExtractionFailure.BadResult("x".repeat(5_000)) + assertTrue("diagnostic should be bounded", f.diagnostic().length < 400) + } + + // Every case must produce a non-empty message; a blank one would put the + // user back where they started. + @Test + fun `every failure produces both messages`() { + val all = listOf( + ExtractionFailure.LoadError(-6, "ERR_CONNECTION_REFUSED"), + ExtractionFailure.HttpError(500, null), + ExtractionFailure.TimedOut(25_000), + ExtractionFailure.ReadabilityError("boom"), + ExtractionFailure.NoContent, + ExtractionFailure.BadResult("{}"), + ) + for (f in all) { + assertTrue("$f has a blank user message", f.userMessage().isNotBlank()) + assertTrue("$f has a blank diagnostic", f.diagnostic().isNotBlank()) + } + } +} |