From d146d2b65c7cd99b6fffa4a5aac5247786b4686d Mon Sep 17 00:00:00 2001 From: "James R. Barlow" Date: Wed, 4 Mar 2020 21:24:13 -0800 Subject: [PATCH] The Great Logging Refactor Remove all instances of logger object being passed as parameters. This was a holdover from ruffus, and complicated a lot of simple things. --- src/ocrmypdf/__main__.py | 4 +-- src/ocrmypdf/_graft.py | 10 +++--- src/ocrmypdf/_jobcontext.py | 42 ++--------------------- src/ocrmypdf/_pipeline.py | 55 +++++++++++-------------------- src/ocrmypdf/_sync.py | 13 ++++---- src/ocrmypdf/exec/__init__.py | 3 -- src/ocrmypdf/exec/ghostscript.py | 10 +----- src/ocrmypdf/exec/qpdf.py | 8 +++-- src/ocrmypdf/exec/tesseract.py | 42 +++++++++++------------ src/ocrmypdf/exec/unpaper.py | 9 +++-- src/ocrmypdf/optimize.py | 50 ++++++++++++++-------------- src/ocrmypdf/pdfinfo/ghosttext.py | 4 +-- src/ocrmypdf/pdfinfo/info.py | 8 ++--- tests/test_ghostscript.py | 4 --- tests/test_optimize.py | 7 +--- tests/test_preprocessing.py | 11 +------ tests/test_rotation.py | 6 +--- tests/test_stdio.py | 2 +- tests/test_tess4.py | 18 +++------- 19 files changed, 107 insertions(+), 199 deletions(-) diff --git a/src/ocrmypdf/__main__.py b/src/ocrmypdf/__main__.py index bcfd6528..459b3040 100755 --- a/src/ocrmypdf/__main__.py +++ b/src/ocrmypdf/__main__.py @@ -21,13 +21,14 @@ import os import sys from . import __version__ -from ._jobcontext import make_logger from ._sync import run_pipeline from ._validation import check_closed_streams, check_options from .api import Verbosity, configure_logging from .cli import parser from .exceptions import BadArgsError, ExitCode, MissingDependencyError +log = logging.getLogger('ocrmypdf') + def run(args=None): options = parser.parse_args(args=args) @@ -47,7 +48,6 @@ def run(args=None): configure_logging( verbosity, progress_bar_friendly=options.progress_bar, manage_root_logger=True ) - log = make_logger('ocrmypdf') log.debug('ocrmypdf ' + __version__) try: check_options(options) diff --git a/src/ocrmypdf/_graft.py b/src/ocrmypdf/_graft.py index a535d492..fba24718 100644 --- a/src/ocrmypdf/_graft.py +++ b/src/ocrmypdf/_graft.py @@ -15,12 +15,14 @@ # You should have received a copy of the GNU General Public License # along with OCRmyPDF. If not, see . +import logging import os from contextlib import suppress from pathlib import Path import pikepdf +log = logging.getLogger(__name__) MAX_REPLACE_PAGES = 100 @@ -89,7 +91,7 @@ def strip_invisible_text(pdf, page): def _graft_text_layer( - *, pdf_base, page_num, text, font, font_key, procset, rotation, strip_old_text, log + *, pdf_base, page_num, text, font, font_key, procset, rotation, strip_old_text ): """Insert the text layer from text page 0 on to pdf_base at page_num""" @@ -179,7 +181,6 @@ def _find_font(text, pdf_base): class OcrGrafter: def __init__(self, context): self.context = context - self.log = context.log self.path_base = Path(context.origin).resolve() self.pdf_base = pikepdf.open(self.path_base) @@ -206,7 +207,7 @@ class OcrGrafter: if path_image is not None and path_image != self.path_base: # We are updating the old page with a rasterized PDF of the new # page (without changing objgen, to preserve references) - self.log.debug("Emplacement update") + log.debug("Emplacement update") with pikepdf.open(image) as pdf_image: self.emplacements += 1 foreign_image_page = pdf_image.pages[0] @@ -220,7 +221,7 @@ class OcrGrafter: content_rotation = autorotate_correction text_rotation = autorotate_correction text_misaligned = (text_rotation - content_rotation) % 360 - self.log.debug( + log.debug( f"Rotations for page {pageno}: [text, auto, misalign, content] = " f"{text_rotation}, {autorotate_correction}, " f"{text_misaligned}, {content_rotation}" @@ -238,7 +239,6 @@ class OcrGrafter: rotation=text_misaligned, procset=self.procset, strip_old_text=strip_old, - log=self.log, ) # Correct the rotation if applicable diff --git a/src/ocrmypdf/_jobcontext.py b/src/ocrmypdf/_jobcontext.py index 42c96282..59de5cdd 100644 --- a/src/ocrmypdf/_jobcontext.py +++ b/src/ocrmypdf/_jobcontext.py @@ -21,30 +21,10 @@ import shutil import sys -class PicklableLoggerMixin: - def __init__(self): - self._log = None - - @property - def log(self): - if not self._log: - self._log = self.get_logger() - return self._log - - def __getstate__(self): - # Python 3.6 is incapable of pickling a logger and marshalling it to another - # process (threading._RLock error), so we disconnect it before pickling, - # and create a new logger in the worker process. - state = self.__dict__.copy() - state['_log'] = None - return state - - -class PDFContext(PicklableLoggerMixin): +class PDFContext: """Holds our context for a particular run of the pipeline""" def __init__(self, options, work_folder, origin, pdfinfo): - PicklableLoggerMixin.__init__(self) self.options = options self.work_folder = work_folder self.origin = origin @@ -56,9 +36,6 @@ class PDFContext(PicklableLoggerMixin): if self.name == '-': self.name = 'stdin' - def get_logger(self): - return make_logger(self.options, filename=self.name) - def get_path(self, name): return os.path.join(self.work_folder, name) @@ -68,14 +45,13 @@ class PDFContext(PicklableLoggerMixin): yield PageContext(self, n) -class PageContext(PicklableLoggerMixin): +class PageContext: """Holds our context for a page Must be pickable, so only store intrinsic/simple data elements """ def __init__(self, pdf_context, pageno): - PicklableLoggerMixin.__init__(self) self.work_folder = pdf_context.work_folder self.origin = pdf_context.origin self.options = pdf_context.options @@ -84,9 +60,6 @@ class PageContext(PicklableLoggerMixin): self.pageinfo = pdf_context.pdfinfo[pageno] self._log = None - def get_logger(self): - return make_logger(self.options, filename=self.name, page=self.pageno + 1) - def get_path(self, name): return os.path.join(self.work_folder, "%06d_%s" % (self.pageno + 1, name)) @@ -111,14 +84,3 @@ class LogNamePageAdapter(logging.LoggerAdapter): '%4u: %s' % (self.extra['page'], msg), kwargs, ) - - -def make_logger(options=None, prefix='ocrmypdf', filename=None, page=None): - log = logging.getLogger(prefix) - if filename and page: - adapter = LogNamePageAdapter(log, dict(input_filename=filename, page=page)) - elif filename: - adapter = LogNameAdapter(log, dict(input_filename=filename)) - else: - adapter = log - return adapter diff --git a/src/ocrmypdf/_pipeline.py b/src/ocrmypdf/_pipeline.py index 58ac2495..98ed32fd 100644 --- a/src/ocrmypdf/_pipeline.py +++ b/src/ocrmypdf/_pipeline.py @@ -15,6 +15,7 @@ # You should have received a copy of the GNU General Public License # along with OCRmyPDF. If not, see . +import logging import os import re import sys @@ -44,10 +45,12 @@ from .optimize import optimize from .pdfa import generate_pdfa_ps from .pdfinfo import Colorspace, Encoding, PdfInfo +log = logging.getLogger(__name__) + VECTOR_PAGE_DPI = 400 -def triage_image_file(input_file, output_file, options, log): +def triage_image_file(input_file, output_file, options): log.info("Input file is not a PDF, checking if it is an image...") try: im = Image.open(input_file) @@ -124,7 +127,7 @@ def _pdf_guess_version(input_file, search_window=1024): return '' -def triage(original_filename, input_file, output_file, options, log): +def triage(original_filename, input_file, output_file, options): try: if _pdf_guess_version(input_file): if options.image_dpi: @@ -140,7 +143,7 @@ def triage(original_filename, input_file, output_file, options, log): msg = str(e).replace(input_file, original_filename) raise InputFileError(msg) from e - triage_image_file(input_file, output_file, options, log) + triage_image_file(input_file, output_file, options) return output_file @@ -156,7 +159,6 @@ def get_pdfinfo(input_file, detailed_page_analysis=False, progbar=False): def validate_pdfinfo_options(context): - log = context.log pdfinfo = context.pdfinfo options = context.options @@ -241,7 +243,6 @@ def get_canvas_square_dpi(pageinfo, options): def is_ocr_required(page_context): pageinfo = page_context.pageinfo options = page_context.options - log = page_context.log ocr_required = True @@ -322,7 +323,6 @@ def rasterize_preview(input_file, page_context): xres=canvas_dpi, yres=canvas_dpi, raster_device='jpeggray', - log=page_context.log, page_dpi=(page_dpi, page_dpi), pageno=page_context.pageinfo.pageno + 1, ) @@ -380,12 +380,11 @@ def get_orientation_correction(preview, page_context): preview, engine_mode=page_context.options.tesseract_oem, timeout=page_context.options.tesseract_timeout, - log=page_context.log, tesseract_env=page_context.options.tesseract_env, ) correction = orient_conf.angle % 360 - page_context.log.info(describe_rotation(page_context, orient_conf, correction)) + log.info(describe_rotation(page_context, orient_conf, correction)) if ( orient_conf.confidence >= page_context.options.rotate_pages_threshold and correction != 0 @@ -426,7 +425,7 @@ def rasterize( device = colorspaces[device_idx] - page_context.log.debug(f"Rasterize with {device}") + log.debug(f"Rasterize with {device}") # Produce the page image with square resolution or else deskew and OCR # will not work properly. @@ -439,7 +438,6 @@ def rasterize( xres=canvas_dpi, yres=canvas_dpi, raster_device=device, - log=page_context.log, page_dpi=(page_dpi, page_dpi), pageno=pageinfo.pageno + 1, rotation=correction, @@ -454,7 +452,7 @@ def preprocess_remove_background(input_file, page_context): leptonica.remove_background(input_file, output_file) return output_file else: - page_context.log.info("background removal skipped on mono page") + log.info("background removal skipped on mono page") return input_file @@ -470,13 +468,7 @@ def preprocess_clean(input_file, page_context): output_file = page_context.get_path('pp_clean.png') dpi = get_page_square_dpi(page_context.pageinfo, page_context.options) - unpaper.clean( - input_file, - output_file, - dpi, - page_context.log, - page_context.options.unpaper_args, - ) + unpaper.clean(input_file, output_file, dpi, page_context.options.unpaper_args) return output_file @@ -496,7 +488,7 @@ def create_ocr_image(image, page_context): draw = ImageDraw.ImageDraw(im) xres, yres = im.info['dpi'] - page_context.log.debug('resolution %r %r' % (xres, yres)) + log.debug('resolution %r %r' % (xres, yres)) if not options.force_ocr: # Do not mask text areas when forcing OCR, because we need to OCR @@ -520,7 +512,7 @@ def create_ocr_image(image, page_context): im.height - bbox[1] * yscale, ] pixcoords = [int(round(c)) for c in pixcoords] - page_context.log.debug('blanking %r', pixcoords) + log.debug('blanking %r', pixcoords) draw.rectangle(pixcoords, fill=white) # draw.rectangle(pixcoords, outline=pink) @@ -551,7 +543,6 @@ def ocr_tesseract_hocr(input_file, page_context): user_words=options.user_words, user_patterns=options.user_patterns, tesseract_env=options.tesseract_env, - log=page_context.log, ) return (hocr_out, hocr_text_out) @@ -591,11 +582,11 @@ def create_pdf_page_from_image(image, page_context): # This create a single page PDF with open(image, 'rb') as imfile, open(output_file, 'wb') as pdf: - page_context.log.debug('convert') + log.debug('convert') img2pdf.convert( imfile, with_pdfrw=False, layout_fun=layout_fun, outputstream=pdf ) - page_context.log.debug('convert done') + log.debug('convert done') return output_file @@ -631,7 +622,6 @@ def ocr_tesseract_textonly_pdf(input_image, page_context): user_words=options.user_words, user_patterns=options.user_patterns, tesseract_env=options.tesseract_env, - log=page_context.log, ) return (output_pdf, output_text) @@ -697,7 +687,7 @@ def convert_to_pdfa(input_pdf, input_ps_stub, context): try: len(pdf_file.docinfo) except TypeError: - context.log.error( + log.error( "File contains a malformed DocumentInfo block - continuing anyway" ) else: @@ -716,7 +706,6 @@ def convert_to_pdfa(input_pdf, input_ps_stub, context): pdf_pages=[fix_docinfo_file, input_ps_stub], output_file=output_file, compression=options.pdfa_image_compression, - log=context.log, pdfa_part=options.output_type[-1], # is pdfa-1, pdfa-2, or pdfa-3 ) @@ -738,22 +727,18 @@ def metadata_fixup(working_file, context): if not missing: return if options.output_type.startswith('pdfa'): - context.log.warning( + log.warning( "Some input metadata could not be copied because it is not " "permitted in PDF/A. You may wish to examine the output " "PDF's XMP metadata." ) - context.log.debug( - "The following metadata fields were not copied: %r", missing - ) + log.debug("The following metadata fields were not copied: %r", missing) else: - context.log.error( + log.error( "Some input metadata could not be copied." "You may wish to examine the output PDF's XMP metadata." ) - context.log.info( - "The following metadata fields were not copied: %r", missing - ) + log.info("The following metadata fields were not copied: %r", missing) with pikepdf.open(context.origin) as original, pikepdf.open(working_file) as pdf: docinfo = get_docinfo(original, options) @@ -819,7 +804,7 @@ def merge_sidecars(txt_files, context): def copy_final(input_file, output_file, context): - context.log.debug('%s -> %s', input_file, output_file) + log.debug('%s -> %s', input_file, output_file) with open(input_file, 'rb') as input_stream: if output_file == '-': copyfileobj(input_stream, sys.stdout.buffer) diff --git a/src/ocrmypdf/_sync.py b/src/ocrmypdf/_sync.py index 07c355ab..dbb7603e 100644 --- a/src/ocrmypdf/_sync.py +++ b/src/ocrmypdf/_sync.py @@ -30,7 +30,7 @@ import PIL from tqdm import tqdm from ._graft import OcrGrafter -from ._jobcontext import PDFContext, cleanup_working_files, make_logger +from ._jobcontext import PDFContext, cleanup_working_files from ._pipeline import ( convert_to_pdfa, copy_final, @@ -66,6 +66,8 @@ from .exec import qpdf from .helpers import available_cpu_count from .pdfa import file_claims_pdfa +log = logging.getLogger(__name__) + PageResult = namedtuple( 'PageResult', 'pageno, pdf_page_from_image, ocr, text, orientation_correction' ) @@ -231,7 +233,7 @@ def exec_concurrent(context): # Run exec_page_sync on every page context max_workers = min(len(context.pdfinfo), context.options.jobs) if max_workers > 1: - context.log.info("Start processing %d pages concurrently", max_workers) + log.info("Start processing %d pages concurrently", max_workers) # Tesseract 4.x can be multithreaded, and we also run multiple workers. We want # to manage how many threads it uses to avoid creating total threads than cores. @@ -250,7 +252,7 @@ def exec_concurrent(context): except ValueError: # OMP_THREAD_LIMIT initialized to non-numeric context.log.error("Environment variable OMP_THREAD_LIMIT is not numeric") if tess_threads > 1: - context.log.info("Using Tesseract OpenMP thread limit %d", tess_threads) + log.info("Using Tesseract OpenMP thread limit %d", tess_threads) if context.options.use_threads: from multiprocessing.dummy import Pool @@ -352,8 +354,6 @@ def configure_debug_logging(log_filename, prefix=''): def run_pipeline(options, api=False): - log = make_logger(options, __name__) - # Any changes to options will not take effect for options that are already # bound to function parameters in the pipeline. (For example # options.input_file, options.pdf_renderer are already bound.) @@ -377,7 +377,6 @@ def run_pipeline(options, api=False): start_input_file, os.path.join(work_folder, 'origin.pdf'), options, - log, ) # Gather pdfinfo and create context @@ -412,7 +411,7 @@ def run_pipeline(options, api=False): pdfa_info['conformance'], ) return ExitCode.pdfa_conversion_failed - if not qpdf.check(options.output_file, log): + if not qpdf.check(options.output_file): log.warning('Output file: The generated PDF is INVALID') return ExitCode.invalid_output_pdf report_output_file_size(options, start_input_file, options.output_file) diff --git a/src/ocrmypdf/exec/__init__.py b/src/ocrmypdf/exec/__init__.py index a19b2043..e2bbf0a5 100644 --- a/src/ocrmypdf/exec/__init__.py +++ b/src/ocrmypdf/exec/__init__.py @@ -268,9 +268,6 @@ def check_external_program( recommended=False, **kwargs, # To consume log parameter ): - if kwargs: - if not 'log' in kwargs: - log.warning('check_external_program(log=...) is deprecated') try: found_version = version_checker() except (CalledProcessError, FileNotFoundError, MissingDependencyError): diff --git a/src/ocrmypdf/exec/ghostscript.py b/src/ocrmypdf/exec/ghostscript.py index 856bc0c1..de4cbda2 100644 --- a/src/ocrmypdf/exec/ghostscript.py +++ b/src/ocrmypdf/exec/ghostscript.py @@ -34,7 +34,7 @@ from PIL import Image from ..exceptions import MissingDependencyError, SubprocessOutputError from . import get_version, run -gslog = logging.getLogger() +log = logging.getLogger(__name__) GS = 'gs' if os.name == 'nt': @@ -138,7 +138,6 @@ def rasterize_pdf( xres, yres, raster_device, - log, pageno=1, page_dpi=None, rotation=None, @@ -155,7 +154,6 @@ def rasterize_pdf( :param xres: resolution at which to rasterize page :param yres: :param raster_device: - :param log: :param pageno: page number to rasterize (beginning at page 1) :param page_dpi: resolution tuple (x, y) overriding output image DPI :param rotation: 0, 90, 180, 270: clockwise angle to rotate page @@ -165,8 +163,6 @@ def rasterize_pdf( res = round(xres, 6), round(yres, 6) if not page_dpi: page_dpi = res - if not log: - log = gslog args_gs = ( [ @@ -191,7 +187,6 @@ def rasterize_pdf( ] ) - log.debug(args_gs) try: p = run(args_gs, stdout=PIPE, stderr=PIPE, check=True) except CalledProcessError as e: @@ -224,7 +219,6 @@ def generate_pdfa( pdf_pages, output_file, compression, - log, threads=None, # deprecated parameter pdf_version='1.5', pdfa_part='2', @@ -246,8 +240,6 @@ def generate_pdfa( images entirely. (The feature was added in 9.23 but broken, and the 9.24 release of Ghostscript had regressions, so we don't support it until 9.25.) """ - if not log: - log = gslog if threads is not None: warnings.warn( "use of deprecated parameter 'threads'", category=DeprecationWarning diff --git a/src/ocrmypdf/exec/qpdf.py b/src/ocrmypdf/exec/qpdf.py index d46baf1c..32ef8cb6 100644 --- a/src/ocrmypdf/exec/qpdf.py +++ b/src/ocrmypdf/exec/qpdf.py @@ -17,22 +17,24 @@ """Interface to qpdf executable""" +import logging from io import StringIO import pikepdf +log = logging.getLogger(__name__) + def version(): return pikepdf.__libqpdf_version__ -def check(input_file, log=None): +def check(input_file): pdf = None try: pdf = pikepdf.open(input_file) except pikepdf.PdfError as e: - if log: - log.error(e) + log.error(e) return False else: messages = pdf.check() diff --git a/src/ocrmypdf/exec/tesseract.py b/src/ocrmypdf/exec/tesseract.py index abcbb2fa..4ebdb0cf 100644 --- a/src/ocrmypdf/exec/tesseract.py +++ b/src/ocrmypdf/exec/tesseract.py @@ -33,6 +33,8 @@ from ..exceptions import ( from ..helpers import page_number, safe_symlink from . import get_version, run +log = logging.getLogger(__name__) + OrientationConfidence = namedtuple('OrientationConfidence', ('angle', 'confidence')) HOCR_TEMPLATE = """ @@ -144,7 +146,7 @@ def tess_base_args(langs, engine_mode): return args -def get_orientation(input_file, engine_mode, timeout: float, log, tesseract_env=None): +def get_orientation(input_file, engine_mode, timeout: float, tesseract_env=None): args_tesseract = tess_base_args(['osd'], engine_mode) + [ '--psm', '0', @@ -165,7 +167,7 @@ def get_orientation(input_file, engine_mode, timeout: float, log, tesseract_env= except TimeoutExpired: return OrientationConfidence(angle=0, confidence=0.0) except CalledProcessError as e: - tesseract_log_output(log, e.output, input_file) + tesseract_log_output(e.output, input_file) if ( b'Too few characters. Skipping this page' in e.output or b'Image too large' in e.output @@ -187,9 +189,9 @@ def get_orientation(input_file, engine_mode, timeout: float, log, tesseract_env= return oc -def tesseract_log_output(mainlog, stdout, input_file): - log = TesseractLoggerAdapter( - mainlog, extra=mainlog.extra if hasattr(mainlog, 'extra') else None +def tesseract_log_output(stdout, input_file): + tlog = TesseractLoggerAdapter( + log, extra=log.extra if hasattr(log, 'extra') else None ) try: @@ -204,28 +206,28 @@ def tesseract_log_output(mainlog, stdout, input_file): elif line.startswith("Warning in pixReadMem"): continue elif 'diacritics' in line: - log.warning("lots of diacritics - possibly poor OCR") + tlog.warning("lots of diacritics - possibly poor OCR") elif line.startswith('OSD: Weak margin'): - log.warning("unsure about page orientation") + tlog.warning("unsure about page orientation") elif 'Error in pixScanForForeground' in line: pass # Appears to be spurious/problem with nonwhite borders elif 'Error in boxClipToRectangle' in line: pass # Always appears with pixScanForForeground message elif 'parameter not found: ' in line.lower(): - log.error(line.strip()) + tlog.error(line.strip()) problem = line.split('found: ')[1] raise TesseractConfigError(problem) elif 'error' in line.lower() or 'exception' in line.lower(): - log.error(line.strip()) + tlog.error(line.strip()) elif 'warning' in line.lower(): - log.warning(line.strip()) + tlog.warning(line.strip()) elif 'read_params_file' in line.lower(): - log.error(line.strip()) + tlog.error(line.strip()) else: - log.info(line.strip()) + tlog.info(line.strip()) -def page_timedout(log, input_file, timeout): +def page_timedout(input_file, timeout): if timeout == 0: return prefix = f"{(page_number(input_file)):4d}: [tesseract] " @@ -257,7 +259,6 @@ def generate_hocr( user_words, user_patterns, tesseract_env, - log, ): output_hocr = next(o for o in output_files if fspath(o).endswith('.hocr')) @@ -292,17 +293,17 @@ def generate_hocr( # Generate a HOCR file with no recognized text if tesseract times out # Temporary workaround to hocrTransform not being able to function if # it does not have a valid hOCR file. - page_timedout(log, input_file, timeout) + page_timedout(input_file, timeout) _generate_null_hocr(output_hocr, output_sidecar, input_file) except CalledProcessError as e: - tesseract_log_output(log, e.output, input_file) + tesseract_log_output(e.output, input_file) if b'Image too large' in e.output: _generate_null_hocr(output_hocr, output_sidecar, input_file) return raise SubprocessOutputError() from e else: - tesseract_log_output(log, stdout, input_file) + tesseract_log_output(stdout, input_file) # The sidecar text file will get the suffix .txt; rename it to # whatever caller wants it named if os.path.exists(prefix + '.txt'): @@ -340,7 +341,6 @@ def generate_pdf( user_words, user_patterns, tesseract_env, - log, ): """Use Tesseract to render a PDF. @@ -389,13 +389,13 @@ def generate_pdf( if os.path.exists(prefix + '.txt'): shutil.move(prefix + '.txt', output_text) except TimeoutExpired: - page_timedout(log, input_image, timeout) + page_timedout(input_image, timeout) use_skip_page(text_only, skip_pdf, output_pdf, output_text) except CalledProcessError as e: - tesseract_log_output(log, e.output, input_image) + tesseract_log_output(e.output, input_image) if b'Image too large' in e.output: use_skip_page(text_only, skip_pdf, output_pdf, output_text) return raise SubprocessOutputError() from e else: - tesseract_log_output(log, stdout, input_image) + tesseract_log_output(stdout, input_image) diff --git a/src/ocrmypdf/exec/unpaper.py b/src/ocrmypdf/exec/unpaper.py index 2984b455..0228beb6 100644 --- a/src/ocrmypdf/exec/unpaper.py +++ b/src/ocrmypdf/exec/unpaper.py @@ -20,6 +20,7 @@ """Interface to unpaper executable""" +import logging import os import shlex from functools import lru_cache @@ -32,13 +33,15 @@ from ..exceptions import MissingDependencyError, SubprocessOutputError from . import get_version from . import run as external_run +log = logging.getLogger(__name__) + @lru_cache(maxsize=1) def version(): return get_version('unpaper') -def run(input_file, output_file, dpi, log, mode_args): +def run(input_file, output_file, dpi, mode_args): args_unpaper = ['unpaper', '-v', '--dpi', str(dpi)] + mode_args SUFFIXES = {'1': '.pbm', 'L': '.pgm', 'RGB': '.ppm'} @@ -110,7 +113,7 @@ def validate_custom_args(args: str): return unpaper_args -def clean(input_file, output_file, dpi, log, unpaper_args=None): +def clean(input_file, output_file, dpi, unpaper_args=None): default_args = [ '--layout', 'none', @@ -124,4 +127,4 @@ def clean(input_file, output_file, dpi, log, unpaper_args=None): ] if not unpaper_args: unpaper_args = default_args - run(input_file, output_file, dpi, log, unpaper_args) + run(input_file, output_file, dpi, unpaper_args) diff --git a/src/ocrmypdf/optimize.py b/src/ocrmypdf/optimize.py index 839a8ff9..e6f0bd3f 100644 --- a/src/ocrmypdf/optimize.py +++ b/src/ocrmypdf/optimize.py @@ -16,6 +16,7 @@ # along with OCRmyPDF. If not, see . import concurrent.futures +import logging import sys import tempfile from collections import defaultdict @@ -33,6 +34,8 @@ from .exceptions import OutputFileAccessError from .exec import jbig2enc, pngquant from .helpers import safe_symlink +log = logging.getLogger(__name__) + DEFAULT_JPEG_QUALITY = 75 DEFAULT_PNG_QUALITY = 70 @@ -53,7 +56,7 @@ def tif_name(root, xref): return img_name(root, xref, '.tif') -def extract_image_filter(pike, root, log, image, xref): +def extract_image_filter(pike, root, image, xref): if image.Subtype != Name.Image: return None if image.Length < 100: @@ -79,8 +82,8 @@ def extract_image_filter(pike, root, log, image, xref): return pim, filtdp -def extract_image_jbig2(*, pike, root, log, image, xref, options): - result = extract_image_filter(pike, root, log, image, xref) +def extract_image_jbig2(*, pike, root, image, xref, options): + result = extract_image_filter(pike, root, image, xref) if result is None: return None pim, filtdp = result @@ -101,8 +104,8 @@ def extract_image_jbig2(*, pike, root, log, image, xref, options): return None -def extract_image_generic(*, pike, root, log, image, xref, options): - result = extract_image_filter(pike, root, log, image, xref) +def extract_image_generic(*, pike, root, image, xref, options): + result = extract_image_filter(pike, root, image, xref) if result is None: return None pim, filtdp = result @@ -170,7 +173,7 @@ def extract_image_generic(*, pike, root, log, image, xref, options): return None -def extract_images(pike, root, log, options, extract_fn): +def extract_images(pike, root, options, extract_fn): """Extract image using extract_fn Enumerate images on each page, lookup their xref/ID number in the PDF. @@ -212,7 +215,7 @@ def extract_images(pike, root, log, options, extract_fn): image = pike.get_object((xref, 0)) try: result = extract_fn( - pike=pike, root=root, log=log, image=image, xref=xref, options=options + pike=pike, root=root, image=image, xref=xref, options=options ) except Exception as e: log.debug("Image xref %s, error %s", xref, repr(e)) @@ -223,12 +226,12 @@ def extract_images(pike, root, log, options, extract_fn): yield pageno_for_xref[xref], xref, ext -def extract_images_generic(pike, root, log, options): +def extract_images_generic(pike, root, options): """Extract any >=2bpp image we think we can improve""" jpegs = [] pngs = [] - for _, xref, ext in extract_images(pike, root, log, options, extract_image_generic): + for _, xref, ext in extract_images(pike, root, options, extract_image_generic): log.debug('xref = %s ext = %s', xref, ext) if ext == '.png': pngs.append(xref) @@ -238,13 +241,11 @@ def extract_images_generic(pike, root, log, options): return jpegs, pngs -def extract_images_jbig2(pike, root, log, options): +def extract_images_jbig2(pike, root, options): """Extract any bitonal image that we think we can improve as JBIG2""" jbig2_groups = defaultdict(list) - for pageno, xref, ext in extract_images( - pike, root, log, options, extract_image_jbig2 - ): + for pageno, xref, ext in extract_images(pike, root, options, extract_image_jbig2): group = pageno // options.jbig2_page_group_size jbig2_groups[group].append((xref, ext)) @@ -256,7 +257,7 @@ def extract_images_jbig2(pike, root, log, options): return jbig2_groups -def _produce_jbig2_images(jbig2_groups, root, log, options): +def _produce_jbig2_images(jbig2_groups, root, options): """Produce JBIG2 images from their groups""" def jbig2_group_futures(executor, root, groups): @@ -304,7 +305,7 @@ def _produce_jbig2_images(jbig2_groups, root, log, options): pbar.update() -def convert_to_jbig2(pike, jbig2_groups, root, log, options): +def convert_to_jbig2(pike, jbig2_groups, root, options): """Convert images to JBIG2 and insert into PDF. When the JBIG2 page group size is > 1 we do several JBIG2 images at once @@ -318,7 +319,7 @@ def convert_to_jbig2(pike, jbig2_groups, root, log, options): and needs no dictionary. Currently this must be lossless JBIG2. """ - _produce_jbig2_images(jbig2_groups, root, log, options) + _produce_jbig2_images(jbig2_groups, root, options) for group, xref_exts in jbig2_groups.items(): prefix = f'group{group:08d}' @@ -342,7 +343,7 @@ def convert_to_jbig2(pike, jbig2_groups, root, log, options): ) -def transcode_jpegs(pike, jpegs, root, log, options): +def transcode_jpegs(pike, jpegs, root, options): for xref in tqdm( jpegs, desc="JPEGs", unit='image', disable=not options.progress_bar ): @@ -365,7 +366,7 @@ def transcode_jpegs(pike, jpegs, root, log, options): im_obj.write(compdata.read(), filter=Name.DCTDecode) -def transcode_pngs(pike, images, image_name_fn, root, log, options): +def transcode_pngs(pike, images, image_name_fn, root, options): modified = set() if options.optimize >= 2: png_quality = ( @@ -500,7 +501,6 @@ def rewrite_png(pike, im_obj, compdata, log): def optimize(input_file, output_file, context, save_settings): - log = context.log options = context.options if options.optimize == 0: safe_symlink(input_file, output_file) @@ -517,15 +517,15 @@ def optimize(input_file, output_file, context, save_settings): root = Path(output_file).parent / 'images' root.mkdir(exist_ok=True) - jpegs, pngs = extract_images_generic(pike, root, log, options) - transcode_jpegs(pike, jpegs, root, log, options) + jpegs, pngs = extract_images_generic(pike, root, options) + transcode_jpegs(pike, jpegs, root, options) # if options.optimize >= 2: # Try pngifying the jpegs - # transcode_pngs(pike, jpegs, jpg_name, root, log, options) - transcode_pngs(pike, pngs, png_name, root, log, options) + # transcode_pngs(pike, jpegs, jpg_name, root, options) + transcode_pngs(pike, pngs, png_name, root, options) - jbig2_groups = extract_images_jbig2(pike, root, log, options) - convert_to_jbig2(pike, jbig2_groups, root, log, options) + jbig2_groups = extract_images_jbig2(pike, root, options) + convert_to_jbig2(pike, jbig2_groups, root, options) target_file = Path(output_file).with_suffix('.opt.pdf') pike.remove_unreferenced_resources() diff --git a/src/ocrmypdf/pdfinfo/ghosttext.py b/src/ocrmypdf/pdfinfo/ghosttext.py index 9626fad7..07e72f19 100644 --- a/src/ocrmypdf/pdfinfo/ghosttext.py +++ b/src/ocrmypdf/pdfinfo/ghosttext.py @@ -21,7 +21,7 @@ import xml.etree.ElementTree as ET from ..exec import ghostscript -gslog = logging.getLogger() +log = logging.getLogger(__name__) # Forgive me for I have sinned # I am using regular expressions to parse XML. However the XML in this case, @@ -77,7 +77,7 @@ def page_get_textblocks(infile, pageno, xmltext, height): return [block for block in joined_blocks()] -def extract_text_xml(infile, pdf, pageno=None, log=gslog): +def extract_text_xml(infile, pdf, pageno=None): existing_text = ghostscript.extract_text(infile, pageno=None) existing_text = regex_remove_char_tags.sub(b' ', existing_text) diff --git a/src/ocrmypdf/pdfinfo/info.py b/src/ocrmypdf/pdfinfo/info.py index d304688b..329661b3 100644 --- a/src/ocrmypdf/pdfinfo/info.py +++ b/src/ocrmypdf/pdfinfo/info.py @@ -616,7 +616,7 @@ def _pdf_get_pageinfo(pdf, pageno: int, infile: PathLike, xmltext: str): return pageinfo -def _pdf_get_all_pageinfo(infile, detailed_analysis=False, log=None, progbar=False): +def _pdf_get_all_pageinfo(infile, detailed_analysis=False, progbar=False): pdf = pikepdf.open(infile) # Do not close in this function try: if pdf.is_encrypted: @@ -624,7 +624,7 @@ def _pdf_get_all_pageinfo(infile, detailed_analysis=False, log=None, progbar=Fal if detailed_analysis: pages_xml = None else: - pages_xml = ghosttext.extract_text_xml(infile, pdf, pageno=None, log=log) + pages_xml = ghosttext.extract_text_xml(infile, pdf, pageno=None) pages = [] for n, _ in tqdm( @@ -758,12 +758,12 @@ class PageInfo: class PdfInfo: """Get summary information about a PDF""" - def __init__(self, infile, detailed_page_analysis=False, log=logger, progbar=False): + def __init__(self, infile, detailed_page_analysis=False, progbar=False): self._infile = infile if ghostscript.version() in ('9.52',): detailed_page_analysis = True # txtwrite doesn't work in these versions self._pages, pdf = _pdf_get_all_pageinfo( - infile, detailed_page_analysis, log=log, progbar=progbar + infile, detailed_page_analysis, progbar=progbar ) self._needs_rendering = pdf.root.get('/NeedsRendering', False) self._has_acroform = False diff --git a/tests/test_ghostscript.py b/tests/test_ghostscript.py index 3aed104a..5bb7b76f 100644 --- a/tests/test_ghostscript.py +++ b/tests/test_ghostscript.py @@ -73,14 +73,12 @@ def test_rasterize_size(francais, outdir, caplog): target_size = Decimal('50.0'), Decimal('30.0') forced_dpi = 42.0, 4242.0 - log = logging.getLogger() rasterize_pdf( path, outdir / 'out.png', target_size[0] / page_size[0], target_size[1] / page_size[1], raster_device='pngmono', - log=log, page_dpi=forced_dpi, ) @@ -97,7 +95,6 @@ def test_rasterize_rotated(francais, outdir, caplog): target_size = Decimal('50.0'), Decimal('30.0') forced_dpi = 42.0, 4242.0 - log = logging.getLogger() caplog.set_level(logging.DEBUG) rasterize_pdf( path, @@ -105,7 +102,6 @@ def test_rasterize_rotated(francais, outdir, caplog): target_size[0] / page_size[0], target_size[1] / page_size[1], raster_device='pngmono', - log=log, page_dpi=forced_dpi, rotation=90, ) diff --git a/tests/test_optimize.py b/tests/test_optimize.py index 0c78d653..6cdc1c71 100644 --- a/tests/test_optimize.py +++ b/tests/test_optimize.py @@ -43,12 +43,7 @@ def test_mono_not_inverted(resources, outdir): opt.main(infile, outdir / 'out.pdf', level=3) rasterize_pdf( - outdir / 'out.pdf', - outdir / 'im.png', - xres=10, - yres=10, - raster_device='pnggray', - log=logging.getLogger(name='test_mono_not_inverted'), + outdir / 'out.pdf', outdir / 'im.png', xres=10, yres=10, raster_device='pnggray' ) with Image.open(fspath(outdir / 'im.png')) as im: diff --git a/tests/test_preprocessing.py b/tests/test_preprocessing.py index 4054e4e4..50eb6b56 100644 --- a/tests/test_preprocessing.py +++ b/tests/test_preprocessing.py @@ -55,7 +55,6 @@ def test_deskew(spoof_tesseract_noop, resources, outdir): xres=150, yres=150, raster_device='pngmono', - log=log, pageno=1, ) @@ -80,18 +79,10 @@ def test_remove_background(spoof_tesseract_noop, resources, outdir): env=spoof_tesseract_noop, ) - log = logging.getLogger() - output_png = outdir / 'remove_bg.png' ghostscript.rasterize_pdf( - output_pdf, - output_png, - xres=100, - yres=100, - raster_device='png16m', - log=log, - pageno=1, + output_pdf, output_png, xres=100, yres=100, raster_device='png16m', pageno=1 ) # The output image should contain pure white and black diff --git a/tests/test_rotation.py b/tests/test_rotation.py index 05d42300..796c2bfb 100644 --- a/tests/test_rotation.py +++ b/tests/test_rotation.py @@ -48,8 +48,6 @@ RENDERERS = ['hocr', 'sandwich'] def check_monochrome_correlation( outdir, reference_pdf, reference_pageno, test_pdf, test_pageno ): - gslog = logging.getLogger() - reference_png = outdir / f'{reference_pdf.name}.ref{reference_pageno:04d}.png' test_png = outdir / f'{test_pdf.name}.test{test_pageno:04d}.png' @@ -63,7 +61,6 @@ def check_monochrome_correlation( xres=100, yres=100, raster_device='pngmono', - log=gslog, pageno=pageno, rotation=0, ) @@ -268,7 +265,6 @@ def test_tesseract_orientation(resources, tmp_path): pix_rotated = pix.rotate_orth(2) # 180 degrees clockwise pix_rotated.write_implied_format(tmp_path / '000001.png') - log = logging.getLogger() tesseract.get_orientation( # Test results of this are unreliable - tmp_path / '000001.png', engine_mode='3', timeout=10, log=log + tmp_path / '000001.png', engine_mode='3', timeout=10 ) diff --git a/tests/test_stdio.py b/tests/test_stdio.py index 250ca6f2..150e40ff 100644 --- a/tests/test_stdio.py +++ b/tests/test_stdio.py @@ -74,7 +74,7 @@ def test_stdout(spoof_tesseract_noop, ocrmypdf_exec, resources, outpdf): ) assert p.returncode == ExitCode.ok - assert qpdf.check(output_file, log=None) + assert qpdf.check(output_file) @pytest.mark.skipif( diff --git a/tests/test_tess4.py b/tests/test_tess4.py index a66f2186..33110a43 100644 --- a/tests/test_tess4.py +++ b/tests/test_tess4.py @@ -86,8 +86,6 @@ def test_no_languages(tmp_path): def test_image_too_large_hocr(monkeypatch, resources, outdir): - log = logging.getLogger('test_image_too_large_hocr') - def dummy_run(args, *, env=None, **kwargs): raise subprocess.CalledProcessError(1, 'tesseract', output=b'Image too large') @@ -100,7 +98,6 @@ def test_image_too_large_hocr(monkeypatch, resources, outdir): tessconfig=[], timeout=180.0, pagesegmode=None, - log=log, user_words=None, user_patterns=None, tesseract_env=None, @@ -109,8 +106,6 @@ def test_image_too_large_hocr(monkeypatch, resources, outdir): def test_image_too_large_pdf(monkeypatch, resources, outdir): - log = logging.getLogger('test_image_too_large_pdf') - def dummy_run(args, *, env=None, **kwargs): raise subprocess.CalledProcessError(1, 'tesseract', output=b'Image too large') @@ -126,7 +121,6 @@ def test_image_too_large_pdf(monkeypatch, resources, outdir): tessconfig=[], timeout=180.0, pagesegmode=None, - log=log, user_words=None, user_patterns=None, tesseract_env=None, @@ -137,8 +131,7 @@ def test_image_too_large_pdf(monkeypatch, resources, outdir): def test_timeout(caplog): - log = logging.getLogger('test_timeout') - tesseract.page_timedout(log, '123456.png', 5) + tesseract.page_timedout('123456.png', 5) assert "123456" in caplog.text assert "took too long" in caplog.text @@ -160,10 +153,8 @@ def test_timeout(caplog): ], ) def test_tesseract_log_output(caplog, in_, logged): - log = logging.getLogger('tesseract_log_output') - log.setLevel(logging.INFO) - - tesseract.tesseract_log_output(log, in_, 'dummy') + caplog.set_level(logging.INFO) + tesseract.tesseract_log_output(in_, 'dummy') if logged == '': assert caplog.text == '' else: @@ -171,7 +162,6 @@ def test_tesseract_log_output(caplog, in_, logged): def test_tesseract_log_output_raises(caplog): - log = logging.getLogger('tesseract_log_output') with pytest.raises(tesseract.TesseractConfigError): - tesseract.tesseract_log_output(log, b'parameter not found: moo', 'dummy') + tesseract.tesseract_log_output(b'parameter not found: moo', 'dummy') assert 'not found' in caplog.text