diff --git a/preprocessor/preprocessor/preprocess.py b/preprocessor/preprocessor/preprocess.py
index 2b35432e7e991bdc80a84866e853ead7f541fb06..355505e7bcb87946e9570fb2faacac9026ccefd1 100644
--- a/preprocessor/preprocessor/preprocess.py
+++ b/preprocessor/preprocessor/preprocess.py
@@ -6,7 +6,6 @@ import logging
import shutil
from typing import List
from pprint import pformat
-from time import time
from urllib.parse import urlparse
from .transfer import get_downloader, get_uploader
@@ -16,7 +15,7 @@ from .steps import (
georeference_step, extract_subdataset_step, calc_step, stack_bands_step, output_step
)
from .steps.browse_report import browse_georeference
-from .util import workdir
+from .util import workdir, Timer
logging.basicConfig()
@@ -72,25 +71,6 @@ def flatten(l):
return [item for sublist in l for item in sublist]
-class Timer:
- """ Helper timer class to allow logging of timing values
- """
- def __init__(self):
- self.start = None
- self.end = None
-
- def __enter__(self):
- self.start = time()
- return self
-
- def __exit__(self, *args, **kwargs):
- self.end = time()
-
- @property
- def elapsed(self):
- return (self.end if self.end is not None else time()) - self.start
-
-
# -----------------------------------------------------------------------------
@@ -117,7 +97,7 @@ def preprocess_internal(preprocess_config, previous_step='unpack'):
preprocessor(previous_step, step, **step_config)
logger.info(
- 'Finished preprocessing step %s after %f seconds.'
+ 'Finished preprocessing step %s after %.3f seconds.'
% (step, step_timer.elapsed)
)
force_refresh = True
@@ -158,7 +138,7 @@ def preprocess_file(config: dict, file_path: os.PathLike, use_dir: os.PathLike=N
source_archive_path = downloader.download(file_path, 'download')
logger.info(
- 'Downloaded file %s in %f seconds'
+ 'Downloaded file %s in %.3f seconds'
% (file_path, download_timer.elapsed)
)
@@ -171,7 +151,7 @@ def preprocess_file(config: dict, file_path: os.PathLike, use_dir: os.PathLike=N
# open the XML to retrieve the product type and level
product_type, product_level = extract_product_type_and_level(metadata_files, config)
- logger.info('Detected %s/%s' % (product_type, product_level))
+ logger.info('Detected product_type/level_type %s/%s' % (product_type, product_level))
# get a concrete configuration for the type, filled with the defaults
default_config = dict(config['preprocessing'].get('defaults', {}))
@@ -208,7 +188,7 @@ def preprocess_file(config: dict, file_path: os.PathLike, use_dir: os.PathLike=N
])
logger.info(
- 'Unpacked files: %s in %f seconds'
+ 'Unpacked files: %s in %.3f seconds'
% (', '.join(metadata_files + data_files), unpack_timer.elapsed)
)
else:
@@ -244,12 +224,12 @@ def preprocess_file(config: dict, file_path: os.PathLike, use_dir: os.PathLike=N
uploader.upload(upload_filenames, file_path)
logger.info(
- 'Finished uploading after %f seconds.'
+ 'Finished uploading after %.3f seconds.'
% (upload_timer.elapsed)
)
logger.info(
- 'Finished preprocessing of %s after %f seconds.'
+ 'Finished preprocessing of %s after %.3f seconds.'
% (file_path, preprocess_timer.elapsed)
)
@@ -278,7 +258,7 @@ def preprocess_browse(config: dict, browse_type: str, browse_report: dict, brows
source_filename_path = downloader.download(filename, 'download')
logger.info(
- 'Downloaded file %s in %f seconds'
+ 'Downloaded file %s in %.3f seconds'
% (filename, download_timer.elapsed)
)
@@ -300,7 +280,7 @@ def preprocess_browse(config: dict, browse_type: str, browse_report: dict, brows
# fetch the product type from the browse_type
product_type = config.get('browse_type_mapping', {}).get(browse_type, browse_type)
- logger.info('Detected %s' % (product_type))
+ logger.info('Detected product_type %s' % (product_type))
# get a concrete configuration for the type, filled with the defaults
default_config = dict(config['preprocessing'].get('defaults', {}))
@@ -336,12 +316,12 @@ def preprocess_browse(config: dict, browse_type: str, browse_report: dict, brows
uploader.upload(upload_filenames, file_path)
logger.info(
- 'Finished uploading after %f seconds.'
+ 'Finished uploading after %.3f seconds.'
% (upload_timer.elapsed)
)
logger.info(
- 'Finished preprocessing of browse "%s" after %f seconds.'
+ 'Finished preprocessing of browse "%s" after %.3f seconds.'
% (filename, preprocess_timer.elapsed)
)
diff --git a/preprocessor/preprocessor/steps/output.py b/preprocessor/preprocessor/steps/output.py
index 882e428ffe8cff4224f571fb66f1ef91db9f1557..d90c53435419f999964899080a7fa7fb6f277ef3 100644
--- a/preprocessor/preprocessor/steps/output.py
+++ b/preprocessor/preprocessor/steps/output.py
@@ -21,6 +21,7 @@ def output_step(source_dir: os.PathLike, target_dir: os.PathLike, options: dict=
warped_files = []
for filename in [path for path in glob(join(source_dir, '**'), recursive=True) if not os.path.isdir(path)]:
target_filename = join(target_dir, replace_ext(basename(filename), extension))
+ logger.debug('Warping file %s' % filename)
gdal.Warp(target_filename, filename, options=gdal.WarpOptions(
**options
))
@@ -28,6 +29,7 @@ def output_step(source_dir: os.PathLike, target_dir: os.PathLike, options: dict=
if len(warped_files) > 1:
tmp_filename = join(target_dir, '%s.%s' % (uuid4().hex, extension))
+ logger.debug('Warping files %s' % warped_files)
gdal.Warp(tmp_filename, warped_files, options=gdal.WarpOptions(
**options
))
diff --git a/preprocessor/preprocessor/transfer/swift.py b/preprocessor/preprocessor/transfer/swift.py
index ae0ac7a672bb82309902135dae0cd682640a74bd..7ecd853c33fadf17047d2fd1540bce1c9d51225b 100644
--- a/preprocessor/preprocessor/transfer/swift.py
+++ b/preprocessor/preprocessor/transfer/swift.py
@@ -6,7 +6,8 @@ import logging
from swiftclient.multithreading import OutputManager
from swiftclient.service import SwiftError, SwiftService, SwiftUploadObject
-
+logging.getLogger("requests").setLevel(logging.WARNING)
+logging.getLogger("swiftclient").setLevel(logging.WARNING)
logger = logging.getLogger(__name__)
class Base:
diff --git a/preprocessor/preprocessor/util.py b/preprocessor/preprocessor/util.py
index 11bdd5db94adf3f1759ab81624c34f829240e6d6..249176c5643c3f58d5fedbfed94a478992679dee 100644
--- a/preprocessor/preprocessor/util.py
+++ b/preprocessor/preprocessor/util.py
@@ -2,6 +2,7 @@ import os
from os.path import splitext
from contextlib import contextmanager
from tempfile import TemporaryDirectory, mkdtemp
+from time import time
try:
from osgeo import gdal
@@ -46,3 +47,22 @@ def pairwise(col):
yield (next(iterator), next(iterator))
except StopIteration:
break
+
+
+class Timer:
+ """ Helper timer class to allow logging of timing values
+ """
+ def __init__(self):
+ self.start = None
+ self.end = None
+
+ def __enter__(self):
+ self.start = time()
+ return self
+
+ def __exit__(self, *args, **kwargs):
+ self.end = time()
+
+ @property
+ def elapsed(self):
+ return (self.end if self.end is not None else time()) - self.start