diff --git a/lib/Controller/Implementation/RecipeImplementation.php b/lib/Controller/Implementation/RecipeImplementation.php index 8db965160..2f9cdea09 100644 --- a/lib/Controller/Implementation/RecipeImplementation.php +++ b/lib/Controller/Implementation/RecipeImplementation.php @@ -7,6 +7,7 @@ namespace OCA\Cookbook\Controller\Implementation; use Exception; +use OCA\Cookbook\Exception\ImportException; use OCA\Cookbook\Exception\InvalidDownloadURLException; use OCA\Cookbook\Exception\InvalidJSONFileException; use OCA\Cookbook\Exception\NoRecipeNameGivenException; @@ -15,6 +16,7 @@ use OCA\Cookbook\Helper\Filter\Output\RecipeJSONOutputFilter; use OCA\Cookbook\Helper\Filter\Output\RecipeStubFilter; use OCA\Cookbook\Helper\RestParameterParser; +use OCA\Cookbook\Helper\UrlRedactionHelper; use OCA\Cookbook\Service\DbCacheService; use OCA\Cookbook\Service\RecipeService; use OCP\AppFramework\Http; @@ -352,7 +354,15 @@ public function import() { ]; return new JSONResponse($json, Http::STATUS_CONFLICT); + } catch (ImportException $e) { + $this->logger->warning('Import failed at step "{step}": {reason}', [ + 'url' => UrlRedactionHelper::redact($data['url']), 'step' => $e->getStep(), 'reason' => $e->getMessage(), 'exception' => $e, + ]); + return new JSONResponse($e->getMessage(), 400); } catch (\Exception $e) { + $this->logger->error('Unexpected error during import: {reason}', [ + 'url' => UrlRedactionHelper::redact($data['url']), 'reason' => $e->getMessage(), 'exception' => $e, + ]); return new JSONResponse($e->getMessage(), 400); } diff --git a/lib/Exception/ImportException.php b/lib/Exception/ImportException.php index 1d7a4a9c3..e084d4a54 100644 --- a/lib/Exception/ImportException.php +++ b/lib/Exception/ImportException.php @@ -7,7 +7,14 @@ namespace OCA\Cookbook\Exception; class ImportException extends \Exception { - public function __construct($message = '', $code = 0, $previous = null) { + private string $step; + + public function __construct($message = '', $code = 0, $previous = null, string $step = '') { parent::__construct($message, $code, $previous); + $this->step = $step; + } + + public function getStep(): string { + return $this->step; } } diff --git a/lib/Helper/HTMLParser/AbstractHtmlParser.php b/lib/Helper/HTMLParser/AbstractHtmlParser.php index 9043154a2..406a4b3bd 100644 --- a/lib/Helper/HTMLParser/AbstractHtmlParser.php +++ b/lib/Helper/HTMLParser/AbstractHtmlParser.php @@ -8,6 +8,7 @@ use OCA\Cookbook\Exception\HtmlParsingException; use OCP\IL10N; +use Psr\Log\LoggerInterface; abstract class AbstractHtmlParser { /** @@ -15,8 +16,11 @@ abstract class AbstractHtmlParser { */ protected $l; - public function __construct(IL10N $l10n) { + protected LoggerInterface $logger; + + public function __construct(IL10N $l10n, LoggerInterface $logger) { $this->l = $l10n; + $this->logger = $logger; } /** diff --git a/lib/Helper/HTMLParser/HttpJsonLdParser.php b/lib/Helper/HTMLParser/HttpJsonLdParser.php index 27de6567c..5fb211bb2 100644 --- a/lib/Helper/HTMLParser/HttpJsonLdParser.php +++ b/lib/Helper/HTMLParser/HttpJsonLdParser.php @@ -7,8 +7,10 @@ namespace OCA\Cookbook\Helper\HTMLParser; use OCA\Cookbook\Exception\HtmlParsingException; +use OCA\Cookbook\Helper\UrlRedactionHelper; use OCA\Cookbook\Service\JsonService; use OCP\IL10N; +use Psr\Log\LoggerInterface; /** * This class is an AbstractHtmlParser which tries to extract a JSON+LD script from the HTML page. @@ -20,8 +22,8 @@ class HttpJsonLdParser extends AbstractHtmlParser { */ private $jsonService; - public function __construct(IL10N $l10n, JsonService $jsonService) { - parent::__construct($l10n); + public function __construct(IL10N $l10n, LoggerInterface $logger, JsonService $jsonService) { + parent::__construct($l10n, $logger); $this->jsonService = $jsonService; } @@ -32,6 +34,10 @@ public function parse(\DOMDocument $document, ?string $url): array { $json_ld_elements = $xpath->query("//*[@type='application/ld+json']"); + $this->logger->debug('JSON-LD parser found {count} ld+json elements for {url}', [ + 'count' => $json_ld_elements->length, 'url' => UrlRedactionHelper::redact($url), + ]); + foreach ($json_ld_elements as $json_ld_element) { if (!$json_ld_element || !$json_ld_element->nodeValue) { continue; @@ -40,7 +46,9 @@ public function parse(\DOMDocument $document, ?string $url): array { try { return $this->parseJsonLdElement($json_ld_element); } catch (HtmlParsingException $ex) { - // Parsing failed for this element. Let's see if there are more... + $this->logger->debug('JSON-LD element did not contain a valid recipe: {reason}', [ + 'reason' => $ex->getMessage(), + ]); } } @@ -62,6 +70,7 @@ private function parseJsonLdElement(\DOMNode $node): array { $json = json_decode($string, true); if ($json === null) { + $this->logger->debug('JSON-LD decode failed: {error}', ['error' => json_last_error_msg()]); throw new HtmlParsingException($this->l->t('JSON cannot be decoded.')); } diff --git a/lib/Helper/HTMLParser/HttpMicrodataParser.php b/lib/Helper/HTMLParser/HttpMicrodataParser.php index e2d981f4f..4fdaa1033 100644 --- a/lib/Helper/HTMLParser/HttpMicrodataParser.php +++ b/lib/Helper/HTMLParser/HttpMicrodataParser.php @@ -12,7 +12,9 @@ use DOMNodeList; use DOMXPath; use OCA\Cookbook\Exception\HtmlParsingException; +use OCA\Cookbook\Helper\UrlRedactionHelper; use OCP\IL10N; +use Psr\Log\LoggerInterface; /** * This class is an AbstractHtmlParser which tries to extract micro data from the HTML page. @@ -32,8 +34,8 @@ class HttpMicrodataParser extends AbstractHtmlParser { */ private $recipe; - public function __construct(IL10N $l10n) { - parent::__construct($l10n); + public function __construct(IL10N $l10n, LoggerInterface $logger) { + parent::__construct($l10n, $logger); } #[\Override] @@ -49,9 +51,14 @@ public function parse(DOMDocument $document, ?string $url): array { $recipes = $this->xpath->query($xpathSelector); if (count($recipes) === 0) { + $this->logger->info('Microdata parser found no Recipe itemscope elements for {url}', ['url' => UrlRedactionHelper::redact($url)]); throw new HtmlParsingException($this->l->t('No recipe was found.')); } + $this->logger->debug('Microdata parser found {count} Recipe itemscope elements for {url}', [ + 'count' => count($recipes), 'url' => UrlRedactionHelper::redact($url), + ]); + $this->recipe = [ '@type' => 'Recipe', '@context' => 'http://schema.org' diff --git a/lib/Helper/HtmlToDomParser.php b/lib/Helper/HtmlToDomParser.php index 8a25fca1d..089db7152 100644 --- a/lib/Helper/HtmlToDomParser.php +++ b/lib/Helper/HtmlToDomParser.php @@ -87,13 +87,13 @@ public function loadHtmlString(DOMDocument $dom, string $url, string $html): DOM try { $this->checkXMLErrors($errors, $url); } catch (Exception $ex) { - throw new ImportException($this->l->t('Parsing of HTML failed.'), null, $ex); + throw new ImportException($this->l->t('Parsing of HTML failed.'), null, $ex, step: 'parse_html'); } libxml_clear_errors(); if (!$parsedSuccessfully) { - throw new ImportException($this->l->t('Parsing of HTML failed.')); + throw new ImportException($this->l->t('Parsing of HTML failed.'), step: 'parse_html'); } } finally { libxml_use_internal_errors($libxml_previous_state); diff --git a/lib/Helper/UrlRedactionHelper.php b/lib/Helper/UrlRedactionHelper.php new file mode 100644 index 000000000..f236a187c --- /dev/null +++ b/lib/Helper/UrlRedactionHelper.php @@ -0,0 +1,25 @@ +logger->info('Starting recipe download from {url}', ['url' => UrlRedactionHelper::redact($url)]); + $html = $this->fetchHtmlPage($url); - // Filter the HTML code + $this->logger->debug('Downloaded {url}: HTTP {status}, content-type {ct}, size {size} bytes', [ + 'url' => UrlRedactionHelper::redact($url), + 'status' => $this->downloadHelper->getStatus(), + 'ct' => $this->downloadHelper->getContentType() ?? 'unknown', + 'size' => strlen($html), + ]); + /** @var AbstractHtmlFilter $filter */ foreach ($this->htmlFilters as $filter) { $filter->apply($html); @@ -121,7 +130,7 @@ private function fetchHtmlPage(string $url): string { $host = parse_url($url); if (!$host) { - throw new ImportException($this->l->t('Could not parse URL')); + throw new ImportException($this->l->t('Could not parse URL'), step: 'download'); } $opt = [ @@ -150,13 +159,13 @@ private function fetchHtmlPage(string $url): string { try { $this->downloadHelper->downloadFile($url, $opt, $headers); } catch (NoDownloadWasCarriedOutException $ex) { - throw new ImportException($this->l->t('Exception while downloading recipe from %s.: %s', [$url, $ex->getMessage()]), 0, $ex); + throw new ImportException($this->l->t('Exception while downloading recipe from %s.: %s', [$url, $ex->getMessage()]), 0, $ex, step: 'download'); } $status = $this->downloadHelper->getStatus(); if ($status < 200 || $status >= 300) { - throw new ImportException($this->l->t('Download from %s failed as HTTP status code %d is not in expected range.', [$url, $status])); + throw new ImportException($this->l->t('Download from %s failed as HTTP status code %d is not in expected range.', [$url, $status]), step: 'download'); } $html = $this->downloadHelper->getContent(); diff --git a/lib/Service/RecipeExtractionService.php b/lib/Service/RecipeExtractionService.php index f9150343c..914167233 100644 --- a/lib/Service/RecipeExtractionService.php +++ b/lib/Service/RecipeExtractionService.php @@ -9,7 +9,9 @@ use OCA\Cookbook\Exception\HtmlParsingException; use OCA\Cookbook\Helper\HTMLParser\HttpJsonLdParser; use OCA\Cookbook\Helper\HTMLParser\HttpMicrodataParser; +use OCA\Cookbook\Helper\UrlRedactionHelper; use OCP\IL10N; +use Psr\Log\LoggerInterface; class RecipeExtractionService { /** @@ -22,10 +24,13 @@ class RecipeExtractionService { */ private $l; + private LoggerInterface $logger; + public function __construct(HttpJsonLdParser $jsonParser, HttpMicrodataParser $microdataParser, - IL10N $l10n) { + IL10N $l10n, LoggerInterface $logger) { $this->parsers = [$jsonParser, $microdataParser]; $this->l = $l10n; + $this->logger = $logger; } /** @@ -37,14 +42,24 @@ public function __construct(HttpJsonLdParser $jsonParser, HttpMicrodataParser $m * @return array The data as returned from the parser */ public function parse(\DOMDocument $document, ?string $url): array { + $failures = []; + foreach ($this->parsers as $parser) { try { return $parser->parse($document, $url); } catch (HtmlParsingException $ex) { - // Silently ignore failure as there might be other parsers better suited + $parserName = (new \ReflectionClass($parser))->getShortName(); + $failures[] = "$parserName: {$ex->getMessage()}"; + $this->logger->info('Parser {parser} failed for URL {url}: {reason}', [ + 'parser' => $parserName, 'url' => UrlRedactionHelper::redact($url), 'reason' => $ex->getMessage(), + ]); } } + $detail = implode('; ', $failures); + $this->logger->warning('All parsers failed for URL {url}. Details: {detail}', [ + 'url' => UrlRedactionHelper::redact($url), 'detail' => $detail, + ]); throw new HtmlParsingException($this->l->t('No parser found for the given import.')); } } diff --git a/lib/Service/RecipeService.php b/lib/Service/RecipeService.php index 4410ac96c..b571f853c 100755 --- a/lib/Service/RecipeService.php +++ b/lib/Service/RecipeService.php @@ -18,6 +18,7 @@ use OCA\Cookbook\Helper\Filter\JSON\JSONFilter; use OCA\Cookbook\Helper\ImageService\ImageConversionHelper; use OCA\Cookbook\Helper\ImageService\ImageSize; +use OCA\Cookbook\Helper\UrlRedactionHelper; use OCA\Cookbook\Helper\UserConfigHelper; use OCA\Cookbook\Helper\UserFolderHelper; use OCP\AppFramework\Db\DoesNotExistException; @@ -350,15 +351,19 @@ public function downloadRecipe(string $url): File { $json = $this->recipeExtractionService->parse($this->htmlDownloadService->getDom(), $url); $importedHtml = $this->htmlDownloadService->getDom()->saveHTML(); } catch (HtmlParsingException $ex) { - throw new ImportException($ex->getMessage(), null, $ex); + throw new ImportException($ex->getMessage(), null, $ex, step: 'extract_recipe'); } + $this->logger->info('Recipe extracted from {url}: name="{name}"', [ + 'url' => UrlRedactionHelper::redact($url), 'name' => $json['name'] ?? '(unnamed)', + ]); + $json = $this->checkRecipe($json); if (!$json) { $this->logger->error('Importing parsers resulted in null recipe.' . 'This is most probably a bug. Please report.'); - throw new ImportException($this->il10n->t('No recipe data found. This is a bug')); + throw new ImportException($this->il10n->t('No recipe data found. This is a bug'), step: 'extract_recipe'); } $json['url'] = $url; diff --git a/tests/Unit/Helper/HTMLParser/HttpJsonLdParserTest.php b/tests/Unit/Helper/HTMLParser/HttpJsonLdParserTest.php index d429b2044..519500d34 100644 --- a/tests/Unit/Helper/HTMLParser/HttpJsonLdParserTest.php +++ b/tests/Unit/Helper/HTMLParser/HttpJsonLdParserTest.php @@ -11,6 +11,7 @@ use OCA\Cookbook\Service\JsonService; use OCP\IL10N; use PHPUnit\Framework\TestCase; +use Psr\Log\LoggerInterface; /** * @coversDefaultClass \OCA\Cookbook\Helper\HTMLParser\HttpJsonLdParser @@ -49,7 +50,9 @@ public function testConstructor(): void { */ $l = $this->createStub(IL10N::class); - $parser = new HttpJsonLdParser($l, $jsonService); + $logger = $this->createStub(LoggerInterface::class); + + $parser = new HttpJsonLdParser($l, $logger, $jsonService); $lProperty = new \ReflectionProperty(HttpJsonLdParser::class, 'l'); $lProperty->setAccessible(true); @@ -71,7 +74,9 @@ public function testHTMLFile($file, $valid, $jsonFile): void { */ $l = $this->createStub(IL10N::class); - $parser = new HttpJsonLdParser($l, $jsonService); + $logger = $this->createStub(LoggerInterface::class); + + $parser = new HttpJsonLdParser($l, $logger, $jsonService); $content = file_get_contents(__DIR__ . "/res_JsonLd/$file"); @@ -113,7 +118,7 @@ public static function dataProviderImageReference(): array { * @covers ::parse */ public function testImageReference(array $input, array $expected): void { - $parser = new HttpJsonLdParser($this->createStub(IL10N::class), new JsonService()); + $parser = new HttpJsonLdParser($this->createStub(IL10N::class), $this->createStub(LoggerInterface::class), new JsonService()); $document = new \DOMDocument(); $document->loadHTML(''); diff --git a/tests/Unit/Helper/HTMLParser/HttpMicrodataParserTest.php b/tests/Unit/Helper/HTMLParser/HttpMicrodataParserTest.php index 7762d392c..25ef30752 100644 --- a/tests/Unit/Helper/HTMLParser/HttpMicrodataParserTest.php +++ b/tests/Unit/Helper/HTMLParser/HttpMicrodataParserTest.php @@ -10,6 +10,7 @@ use OCA\Cookbook\Helper\HTMLParser\HttpMicrodataParser; use OCP\IL10N; use PHPUnit\Framework\TestCase; +use Psr\Log\LoggerInterface; /** * @coversDefaultClass \OCA\Cookbook\Helper\HTMLParser\HttpMicrodataParser @@ -25,7 +26,9 @@ class HttpMicrodataParserTest extends TestCase { public function testConstructor(): void { $l = $this->createStub(IL10N::class); - $parser = new HttpMicrodataParser($l); + $logger = $this->createStub(LoggerInterface::class); + + $parser = new HttpMicrodataParser($l, $logger); $lProperty = new \ReflectionProperty(HttpMicrodataParser::class, 'l'); $lProperty->setAccessible(true); @@ -64,8 +67,9 @@ public function testHTMLFile($filename, $valid, $jsonFile, $skipped = false): vo } $l = $this->createStub(IL10N::class); + $logger = $this->createStub(LoggerInterface::class); - $parser = new HttpMicrodataParser($l); + $parser = new HttpMicrodataParser($l, $logger); $content = file_get_contents(__DIR__ . "/res_Microdata/$filename"); @@ -99,7 +103,8 @@ public static function imageAttributes() { */ public function testImageVariantsAsAttribute($attribute): void { $l = $this->createStub(IL10N::class); - $parser = new HttpMicrodataParser($l); + $logger = $this->createStub(LoggerInterface::class); + $parser = new HttpMicrodataParser($l, $logger); $content = file_get_contents(__DIR__ . '/res_Microdata/caseImageAttribute.html'); $content = str_replace('%IMAGE_NAME%', $attribute, $content); @@ -112,7 +117,8 @@ public function testImageVariantsAsAttribute($attribute): void { */ public function testImageVariantsAsContent($attribute): void { $l = $this->createStub(IL10N::class); - $parser = new HttpMicrodataParser($l); + $logger = $this->createStub(LoggerInterface::class); + $parser = new HttpMicrodataParser($l, $logger); $content = file_get_contents(__DIR__ . '/res_Microdata/caseImageContent.html'); $content = str_replace('%IMAGE_NAME%', $attribute, $content); @@ -131,7 +137,8 @@ public static function ingredientVariantAttributes() { */ public function testIngredientVariants($attribute): void { $l = $this->createStub(IL10N::class); - $parser = new HttpMicrodataParser($l); + $logger = $this->createStub(LoggerInterface::class); + $parser = new HttpMicrodataParser($l, $logger); $content = file_get_contents(__DIR__ . '/res_Microdata/caseIngredient.html'); $content = str_replace('%INGREDIENT_NAME%', $attribute, $content); @@ -151,7 +158,8 @@ public static function instructionVariantAttributes() { */ public function testInstructionVariants($attribute): void { $l = $this->createStub(IL10N::class); - $parser = new HttpMicrodataParser($l); + $logger = $this->createStub(LoggerInterface::class); + $parser = new HttpMicrodataParser($l, $logger); $content = file_get_contents(__DIR__ . '/res_Microdata/caseInstruction.html'); $content = str_replace('%INSTRUCTION_NAME%', $attribute, $content); diff --git a/tests/Unit/Helper/UrlRedactionHelperTest.php b/tests/Unit/Helper/UrlRedactionHelperTest.php new file mode 100644 index 000000000..12e40bc70 --- /dev/null +++ b/tests/Unit/Helper/UrlRedactionHelperTest.php @@ -0,0 +1,31 @@ + ['https://example.com/recipe/1', 'https://example.com/recipe/1'], + 'credentials' => ['https://user:secret@example.com/recipe', 'https://example.com/recipe'], + 'query and fragment' => ['https://example.com/recipe?token=abc#top', 'https://example.com/recipe'], + 'port' => ['http://example.com:8080/r', 'http://example.com:8080/r'], + 'no path' => ['https://example.com', 'https://example.com'], + 'invalid' => ['not a url', '[invalid URL]'], + 'null' => [null, '[invalid URL]'], + ]; + } + + /** + * @dataProvider dataProvider + */ + public function testRedact(?string $url, string $expected): void { + $this->assertEquals($expected, UrlRedactionHelper::redact($url)); + } +} diff --git a/tests/Unit/Service/RecipeExtractionServiceTest.php b/tests/Unit/Service/RecipeExtractionServiceTest.php index b5a29cb2b..3c953f3d8 100644 --- a/tests/Unit/Service/RecipeExtractionServiceTest.php +++ b/tests/Unit/Service/RecipeExtractionServiceTest.php @@ -13,6 +13,7 @@ use OCP\IL10N; use PHPUnit\Framework\MockObject\MockObject; use PHPUnit\Framework\TestCase; +use Psr\Log\LoggerInterface; class RecipeExtractionServiceTest extends TestCase { /** @@ -68,7 +69,8 @@ public function testParsingDelegation($jsonSuccess, $microdataSuccess, $exceptio } } - $sut = new RecipeExtractionService($jsonParser, $microdataParser, $this->l); + $logger = $this->createStub(LoggerInterface::class); + $sut = new RecipeExtractionService($jsonParser, $microdataParser, $this->l, $logger); try { $ret = $sut->parse($document, $url);