diff --git a/src/ocrmypdf/_sync.py b/src/ocrmypdf/_sync.py index 40534b18..90f87848 100644 --- a/src/ocrmypdf/_sync.py +++ b/src/ocrmypdf/_sync.py @@ -165,10 +165,10 @@ def run_pipeline(options): log = get_logger(options, __name__) log.debug('ocrmypdf ' + VERSION) - result = check_options(options, log) + result = check_options(options) if result != ExitCode.ok: return result - check_dependency_versions(options, log) + check_dependency_versions(options) # Any changes to options will not take effect for options that are already # bound to function parameters in the pipeline. (For example @@ -182,7 +182,7 @@ def run_pipeline(options): # variable, but harmless to set if ignored. os.environ.setdefault('OMP_THREAD_LIMIT', '1') - check_environ(options, log) + check_environ(options) if os.environ.get('PYTEST_CURRENT_TEST'): os.environ['_OCRMYPDF_TEST_INFILE'] = options.input_file @@ -191,8 +191,8 @@ def run_pipeline(options): atexit.register(cleanup_working_files, work_folder, options) try: - check_requested_output_file(options, log) - start_input_file = create_input_file(options, log, work_folder) + check_requested_output_file(options) + start_input_file = create_input_file(options, work_folder) # Triage image or pdf origin_pdf = triage( @@ -212,7 +212,7 @@ def run_pipeline(options): log.error("%s: %s" % (type(e).__name__, str(e))) return e.exit_code except Exception as e: - log.error("%s: %s" % (type(e).__name__, str(e))) + log.exception("An exception occurred while executing the pipeline") return ExitCode.other_error if options.output_file == '-': @@ -236,6 +236,6 @@ def run_pipeline(options): log.warning('Output file: The generated PDF is INVALID') return ExitCode.invalid_output_pdf - report_output_file_size(options, log, start_input_file, options.output_file) + report_output_file_size(options, start_input_file, options.output_file) return ExitCode.ok diff --git a/src/ocrmypdf/_validation.py b/src/ocrmypdf/_validation.py index 10671272..e80cd98f 100644 --- a/src/ocrmypdf/_validation.py +++ b/src/ocrmypdf/_validation.py @@ -51,6 +51,8 @@ from .exceptions import ( HOCR_OK_LANGS = frozenset(['eng', 'deu', 'spa', 'ita', 'por']) +log = logging.getLogger(__name__) + def complain(message): print(*textwrap.wrap(message), file=sys.stderr) @@ -61,7 +63,7 @@ def complain(message): verify_python3_env() -def check_options_languages(options, _log): +def check_options_languages(options): if not options.language: options.language = ['eng'] # Enforce English hegemony @@ -80,7 +82,7 @@ def check_options_languages(options, _log): raise MissingDependencyError(msg) -def check_options_output(options, log): +def check_options_output(options): # We have these constraints to check for. # 1. Ghostscript < 9.20 mangles multibyte Unicode # 2. hocr doesn't work on non-Latin languages (so don't select it) @@ -134,27 +136,26 @@ def check_options_output(options, log): if not options.lossless_reconstruction and options.redo_ocr: raise BadArgsError( "--redo-ocr is not currently compatible with --deskew, " - "--clean-final, and --remove-background", + "--clean-final, and --remove-background" ) -def check_options_sidecar(options, log): +def check_options_sidecar(options): if options.sidecar == '\0': if options.output_file == '-': raise BadArgsError( - "--sidecar filename must be specified when output file is " "stdout.", + "--sidecar filename must be specified when output file is " "stdout." ) options.sidecar = options.output_file + '.txt' -def check_options_preprocessing(options, log): +def check_options_preprocessing(options): if options.clean_final: options.clean = True if options.unpaper_args and not options.clean: raise BadArgsError("--clean is required for --unpaper-args") if options.clean: check_external_program( - log=log, program='unpaper', package='unpaper', version_checker=unpaper.version, @@ -170,7 +171,7 @@ def check_options_preprocessing(options, log): raise BadArgsError(str(e)) -def check_options_ocr_behavior(options, log): +def check_options_ocr_behavior(options): exclusive_options = sum( [ (1 if opt else 0) @@ -183,10 +184,9 @@ def check_options_ocr_behavior(options, log): ) -def check_options_optimizing(options, log): +def check_options_optimizing(options): if options.optimize >= 2: check_external_program( - log=log, program='pngquant', package='pngquant', version_checker=pngquant.version, @@ -198,7 +198,6 @@ def check_options_optimizing(options, log): # Although we use JBIG2 for optimize=1, don't nag about it unless the # user is asking for more optimization check_external_program( - log=log, program='jbig2', package='jbig2enc', version_checker=jbig2enc.version, @@ -216,7 +215,7 @@ def check_options_optimizing(options, log): ) -def check_options_advanced(options, log): +def check_options_advanced(options): if options.pdfa_image_compression != 'auto' and options.output_type.startswith( 'pdfa' ): @@ -228,7 +227,7 @@ def check_options_advanced(options, log): log.warning('Tesseract 4.x ignores --user-words, so this has no effect') -def check_options_metadata(options, log): +def check_options_metadata(options): import unicodedata docinfo = [options.title, options.author, options.keywords, options.subject] @@ -243,23 +242,23 @@ def check_options_metadata(options, log): ) -def check_options_pillow(options, log): +def check_options_pillow(options): PIL.Image.MAX_IMAGE_PIXELS = int(options.max_image_mpixels * 1_000_000) if PIL.Image.MAX_IMAGE_PIXELS == 0: PIL.Image.MAX_IMAGE_PIXELS = None -def check_options(options, log): +def check_options(options): try: - check_options_languages(options, log) - check_options_metadata(options, log) - check_options_output(options, log) - check_options_sidecar(options, log) - check_options_preprocessing(options, log) - check_options_ocr_behavior(options, log) - check_options_optimizing(options, log) - check_options_advanced(options, log) - check_options_pillow(options, log) + check_options_languages(options) + check_options_metadata(options) + check_options_output(options) + check_options_sidecar(options) + check_options_preprocessing(options) + check_options_ocr_behavior(options) + check_options_optimizing(options) + check_options_advanced(options) + check_options_pillow(options) return ExitCode.ok except ValueError as e: log.error(e) @@ -272,30 +271,6 @@ def check_options(options, log): return ExitCode.missing_dependency -# ---------- -# Logging - - -def logging_factory(logger_name, logger_args): - verbose = logger_args['verbose'] - quiet = logger_args['quiet'] - - root_logger = logging.getLogger(logger_name) - root_logger.setLevel(logging.DEBUG) - - handler = logging.StreamHandler(sys.stderr) - formatter_ = logging.Formatter("%(levelname)7s - %(message)s") - handler.setFormatter(formatter_) - if verbose: - handler.setLevel(logging.DEBUG) - elif quiet: - handler.setLevel(logging.WARNING) - else: - handler.setLevel(logging.INFO) - root_logger.addHandler(handler) - return root_logger - - def check_closed_streams(options): """Work around Python issue with multiprocessing forking on closed streams @@ -348,7 +323,7 @@ def check_closed_streams(options): return True -def log_page_orientations(pdfinfo, _log): +def log_page_orientations(pdfinfo): direction = {0: 'n', 90: 'e', 180: 's', 270: 'w'} orientations = [] for n, page in enumerate(pdfinfo): @@ -356,10 +331,10 @@ def log_page_orientations(pdfinfo, _log): if angle != 0: orientations.append('{0}{1}'.format(n + 1, direction.get(angle, ''))) if orientations: - _log.info('Page orientations detected: ' + ' '.join(orientations)) + log.info('Page orientations detected: ' + ' '.join(orientations)) -def check_environ(options, _log): +def check_environ(options): old_envvars = ( 'OCRMYPDF_TESSERACT', 'OCRMYPDF_QPDF', @@ -368,7 +343,7 @@ def check_environ(options, _log): ) for k in old_envvars: if k in os.environ: - _log.warning( + log.warning( textwrap.dedent( f"""\ OCRmyPDF no longer uses the environment variable {k}. @@ -377,13 +352,14 @@ def check_environ(options, _log): ) -def create_input_file(options, log, work_folder): +def create_input_file(options, work_folder): if options.input_file == '-': # stdin log.info('reading file from standard input') target = os.path.join(work_folder, 'stdin') with open(target, 'wb') as stream_buffer: from shutil import copyfileobj + copyfileobj(sys.stdin.buffer, stream_buffer) return target else: @@ -392,30 +368,30 @@ def create_input_file(options, log, work_folder): re_symlink(options.input_file, target, log) return target except FileNotFoundError: - log.error("File not found - " + options.input_file) + log.error("File not found - %s", options.input_file) raise InputFileError() -def check_input_file(options, _log, start_input_file): +def check_input_file(options, start_input_file): if options.input_file == '-': # stdin - _log.info('reading file from standard input') + log.info('reading file from standard input') with open(start_input_file, 'wb') as stream_buffer: from shutil import copyfileobj copyfileobj(sys.stdin.buffer, stream_buffer) else: try: - re_symlink(options.input_file, start_input_file, _log) + re_symlink(options.input_file, start_input_file, log) except FileNotFoundError: - _log.error("File not found - " + options.input_file) + log.error("File not found - " + options.input_file) raise InputFileError() -def check_requested_output_file(options, _log): +def check_requested_output_file(options): if options.output_file == '-': if sys.stdout.isatty(): - _log.error( + log.error( textwrap.dedent( """\ Output was set to stdout '-' but it looks like stdout @@ -425,13 +401,13 @@ def check_requested_output_file(options, _log): ) raise BadArgsError() elif not is_file_writable(options.output_file): - _log.error( + log.error( "Output file location (" + options.output_file + ") is not a writable file." ) raise OutputFileAccessError() -def report_output_file_size(options, _log, input_file, output_file): +def report_output_file_size(options, input_file, output_file): try: output_size = Path(output_file).stat().st_size input_size = Path(input_file).stat().st_size @@ -462,7 +438,7 @@ def report_output_file_size(options, _log, input_file, output_file): else: explanation = "No reason for this increase is known. Please report this issue." - _log.warning( + log.warning( textwrap.dedent( f"""\ The output file size is {ratio:.2f}× larger than the input file. @@ -472,16 +448,14 @@ def report_output_file_size(options, _log, input_file, output_file): ) -def check_dependency_versions(options, log): +def check_dependency_versions(options): check_external_program( - log=log, program='tesseract', package={'darwin': 'tesseract', 'linux': 'tesseract-ocr'}, version_checker=tesseract.version, need_version='4.0.0', # using backport for Travis CI ) check_external_program( - log=log, program='gs', package='ghostscript', version_checker=ghostscript.version, @@ -495,7 +469,6 @@ def check_dependency_versions(options, log): ) return ExitCode.missing_dependency check_external_program( - log=log, program='qpdf', package='qpdf', version_checker=qpdf.version, diff --git a/src/ocrmypdf/exec/__init__.py b/src/ocrmypdf/exec/__init__.py index 31d3603f..670651fb 100644 --- a/src/ocrmypdf/exec/__init__.py +++ b/src/ocrmypdf/exec/__init__.py @@ -17,6 +17,7 @@ """Wrappers to manage subprocess calls""" +import logging import os import re import sys @@ -24,6 +25,8 @@ from subprocess import run, STDOUT, PIPE, CalledProcessError from ..exceptions import MissingDependencyError, ExitCode from collections.abc import Mapping +log = logging.Logger(__name__) + def get_version(program, *, version_arg='--version', regex=r'(\d+(\.\d+)*)'): "Get the version of the specified program" @@ -115,7 +118,7 @@ def _get_platform(): return sys.platform -def _error_trailer(log, program, package, **kwargs): +def _error_trailer(program, package, **kwargs): if isinstance(package, Mapping): package = package[_get_platform()] @@ -125,7 +128,7 @@ def _error_trailer(log, program, package, **kwargs): log.info(linux_install_advice.format(**locals())) -def _error_missing_program(log, program, package, required_for, recommended): +def _error_missing_program(program, package, required_for, recommended): if required_for: log.error(missing_optional_program.format(**locals())) elif recommended: @@ -135,9 +138,7 @@ def _error_missing_program(log, program, package, required_for, recommended): _error_trailer(**locals()) -def _error_old_version( - log, program, package, need_version, found_version, required_for -): +def _error_old_version(program, package, need_version, found_version, required_for): if required_for: log.error(old_version_required_for.format(**locals())) else: @@ -147,26 +148,27 @@ def _error_old_version( def check_external_program( *, - log, program, package, version_checker, need_version, required_for=None, 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): - _error_missing_program(log, program, package, required_for, recommended) + _error_missing_program(program, package, required_for, recommended) if not recommended: sys.exit(ExitCode.missing_dependency) return if found_version < need_version: - _error_old_version( - log, program, package, need_version, found_version, required_for - ) + _error_old_version(program, package, need_version, found_version, required_for) if not recommended: sys.exit(ExitCode.missing_dependency)