worker-s1.ipynb

{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {
    "pycharm": {
     "name": "#%% md\n"
    }
   },
   "source": [
    "# Debug notebook\n",
    "This notebook is only used to troubleshoot the S1 ARD workflow processor."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {
    "pycharm": {
     "name": "#%% md\n"
    }
   },
   "source": [
    "## S1 ARD workflow"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 1,
   "metadata": {
    "pycharm": {
     "name": "#%%\n"
    }
   },
   "outputs": [],
   "source": [
    "import json\n",
    "from utils.prepS1 import prepareS1\n",
    "\n",
    "def process_scene(json_data):\n",
    "    loaded_json = json.loads(json_data)\n",
    "    #for x in loaded_json:\n",
    "    #    logger.info(f\"{x}: {loaded_json[x]}\")\n",
    "    prepareS1(**loaded_json)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {
    "pycharm": {
     "name": "#%% md\n"
    }
   },
   "source": [
    "## S1 ARD job queue processor"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 2,
   "metadata": {
    "pycharm": {
     "name": "#%%\n"
    }
   },
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "2020-10-21 14:00:03 INFO     worker Worker with sessionID: db7afbf4-2c05-4895-a10b-bde6fd5b999b\n",
      "2020-10-21 14:00:03 INFO     worker Initial queue state: empty=False\n"
     ]
    }
   ],
   "source": [
    "import os\n",
    "import logging\n",
    "import rediswq\n",
    "\n",
    "level = os.getenv(\"LOGLEVEL\", \"INFO\").upper()\n",
    "logging.basicConfig(format=\"%(asctime)s %(levelname)-8s %(name)s %(message)s\", datefmt=\"%Y-%m-%d %H:%M:%S\", level=level)\n",
    "\n",
    "host = os.getenv(\"REDIS_SERVICE_HOST\", \"redis-master\")\n",
    "q = rediswq.RedisWQ(name=\"jobS1\", host=host)\n",
    "\n",
    "logger = logging.getLogger(\"worker\")\n",
    "logger.info(f\"Worker with sessionID: {q.sessionID()}\")\n",
    "logger.info(f\"Initial queue state: empty={q.empty()}\")"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "metadata": {
    "pycharm": {
     "name": "#%%\n"
    }
   },
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "2020-10-21 14:00:39 INFO     worker Working on {\"in_scene\": \"S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D\", \"s3_bucket\": \"public-eo-data\", \"s3_dir\": \"luigi/fiji/sentinel_1/\", \"ext_dem\": \"common_sensing/ancillary_products/SRTM1Sec/SRTM30_Fiji_E.tif\"}\n",
      "2020-10-21 14:00:39 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 Starting\n",
      "2020-10-21 14:00:39 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 DOWNLOADING via ASF\n",
      "2020-10-21 14:00:39 INFO     root fetching: https://api.daac.asf.alaska.edu/services/search/param?granule_list=S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D&output=csv\n",
      "2020-10-21 14:00:40 INFO     root logging into asf\n",
      "2020-10-21 14:00:44 INFO     root successfully logged into asf\n",
      "2020-10-21 14:01:45 INFO     root Extracting ASF scene: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.zip\n",
      "2020-10-21 14:02:15 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 DOWNLOADED via ASF\n",
      "2020-10-21 14:02:15 INFO     root ['/opt/snap/bin/gpt', '/opt/notebooks/utils/cs_s1_pt1_bnr_Orb_Cal_ML.xml', '-Pinput_grd=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE/manifest.safe', '-Poutput_ml=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML.dim']\n",
      "2020-10-21 14:02:15 DEBUG    root running ['/opt/snap/bin/gpt', '/opt/notebooks/utils/cs_s1_pt1_bnr_Orb_Cal_ML.xml', '-Pinput_grd=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE/manifest.safe', '-Poutput_ml=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML.dim']\n",
      "2020-10-21 14:02:17 INFO     snap_stderr stderr:INFO: org.esa.snap.core.gpf.operators.tooladapter.ToolAdapterIO: Initializing external tool adapters\n",
      "2020-10-21 14:02:20 INFO     snap_stderr stderr:INFO: org.esa.snap.core.util.EngineVersionCheckActivator: Please check regularly for new updates for the best SNAP experience.\n",
      "2020-10-21 14:02:21 INFO     snap_stdout Executing processing graph\n",
      "2020-10-21 14:02:23 INFO     snap_stderr stderr:INFO: org.hsqldb.persist.Logger: dataFileCache open start\n",
      "2020-10-21 14:02:23 INFO     snap_stdout version = 3.2\n",
      "2020-10-21 14:02:24 INFO     snap_stderr stderr:INFO: org.esa.snap.engine_utilities.download.DownloadableContentImpl: http retrieving http://aux.sentinel1.eo.esa.int/POEORB/2020/05/24/S1A_OPER_AUX_POEORB_OPOD_20200524T120752_V20200503T225942_20200505T005942.EOF\n",
      "2020-10-21 14:03:50 INFO     snap_stdout ....10%....20%....30%....40%....50%....60%....70%....80%....90% done.\n",
      "2020-10-21 14:03:51 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 PROCESSED to MULTILOOK starting PT2\n",
      "2020-10-21 14:03:51 DEBUG    root Endpoint URL: http://s3-uk-1.sa-catapult.co.uk\n",
      "2020-10-21 14:03:59 INFO     root ['/opt/snap/bin/gpt', '/opt/notebooks/utils/cs_s1_pt2A_TF.xml', '-Pinput_ml=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML.dim', '-Pext_dem=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/ext_dem.tif', '-Poutput_tf=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF.dim']\n",
      "2020-10-21 14:03:59 DEBUG    root running ['/opt/snap/bin/gpt', '/opt/notebooks/utils/cs_s1_pt2A_TF.xml', '-Pinput_ml=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML.dim', '-Pext_dem=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/ext_dem.tif', '-Poutput_tf=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF.dim']\n",
      "2020-10-21 14:04:01 INFO     snap_stderr stderr:INFO: org.esa.snap.core.gpf.operators.tooladapter.ToolAdapterIO: Initializing external tool adapters\n",
      "2020-10-21 14:04:04 INFO     snap_stderr stderr:INFO: org.esa.snap.core.util.EngineVersionCheckActivator: Please check regularly for new updates for the best SNAP experience.\n",
      "2020-10-21 14:04:05 INFO     snap_stdout Executing processing graph\n",
      "2020-10-21 14:04:07 INFO     snap_stderr stderr:INFO: org.hsqldb.persist.Logger: dataFileCache open start\n",
      "2020-10-21 14:20:41 INFO     snap_stdout ....10%....20%....30%....40%....50%....60%....70%....80%....90% done.\n",
      "2020-10-21 14:20:42 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 PROCESSED to TERRAIN FLATTEN starting PT3\n",
      "2020-10-21 14:20:42 INFO     root ['/opt/snap/bin/gpt', '/opt/notebooks/utils/cs_s1_pt3A_TC_db.xml', '-Pinput_tf=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF.dim', '-Pext_dem=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/ext_dem.tif', '-Poutput_db=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_dB.dim']\n",
      "2020-10-21 14:20:42 DEBUG    root running ['/opt/snap/bin/gpt', '/opt/notebooks/utils/cs_s1_pt3A_TC_db.xml', '-Pinput_tf=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF.dim', '-Pext_dem=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/ext_dem.tif', '-Poutput_db=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_dB.dim']\n",
      "2020-10-21 14:20:44 INFO     snap_stderr stderr:INFO: org.esa.snap.core.gpf.operators.tooladapter.ToolAdapterIO: Initializing external tool adapters\n",
      "2020-10-21 14:20:47 INFO     snap_stderr stderr:INFO: org.esa.snap.core.util.EngineVersionCheckActivator: Please check regularly for new updates for the best SNAP experience.\n",
      "2020-10-21 14:20:48 INFO     snap_stdout Executing processing graph\n",
      "2020-10-21 14:20:50 INFO     snap_stderr stderr:INFO: org.hsqldb.persist.Logger: dataFileCache open start\n",
      "2020-10-21 14:24:11 INFO     snap_stdout ....10%....20%....30%....40%....50%....60%....70%....80%....90% done.\n",
      "2020-10-21 14:24:12 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 PROCESSED to dB starting PT4\n",
      "2020-10-21 14:24:12 INFO     root ['/opt/snap/bin/gpt', '/opt/notebooks/utils/cs_s1_pt4A_Sm_Bm_TC_lsm.xml', '-Pinput_tf=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF.dim', '-Pext_dem=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/ext_dem.tif', '-Poutput_ls=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_lsm.dim']\n",
      "2020-10-21 14:24:12 DEBUG    root running ['/opt/snap/bin/gpt', '/opt/notebooks/utils/cs_s1_pt4A_Sm_Bm_TC_lsm.xml', '-Pinput_tf=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF.dim', '-Pext_dem=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/ext_dem.tif', '-Poutput_ls=/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_lsm.dim']\n",
      "2020-10-21 14:24:14 INFO     snap_stderr stderr:INFO: org.esa.snap.core.gpf.operators.tooladapter.ToolAdapterIO: Initializing external tool adapters\n",
      "2020-10-21 14:24:17 INFO     snap_stderr stderr:INFO: org.esa.snap.core.util.EngineVersionCheckActivator: Please check regularly for new updates for the best SNAP experience.\n",
      "2020-10-21 14:24:18 INFO     snap_stdout Executing processing graph\n",
      "2020-10-21 14:24:19 INFO     snap_stderr stderr:INFO: org.hsqldb.persist.Logger: dataFileCache open start\n",
      "2020-10-21 14:30:49 INFO     snap_stdout ....10%....20%....30%....40%....50%....60%....70%....80%....90% done.\n",
      "2020-10-21 14:30:50 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 PROCESSED to lsm starting COG conversion\n",
      "2020-10-21 14:30:50 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 Converting COGs\n",
      "2020-10-21 14:30:50 INFO     root converting /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_lsm.data/LayoverShadow_MASK_VH.img to cog at /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_LayoverShadow_MASK_VH.tif\n",
      "2020-10-21 14:30:50 INFO     botocore.credentials Found credentials in environment variables.\n",
      "2020-10-21 14:31:13 INFO     root converting /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_dB.data/Gamma0_VH_db.img to cog at /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VH_db.tif\n",
      "2020-10-21 14:31:13 INFO     botocore.credentials Found credentials in environment variables.\n",
      "2020-10-21 14:32:50 INFO     root converting /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_dB.data/Gamma0_VV_db.img to cog at /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VV_db.tif\n",
      "2020-10-21 14:32:50 INFO     botocore.credentials Found credentials in environment variables.\n",
      "2020-10-21 14:34:25 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 COGGED\n",
      "2020-10-21 14:34:25 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 Copying original METADATA\n",
      "2020-10-21 14:34:25 INFO     root Copying original metadata file to cog dir: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_dB.dim\n",
      "2020-10-21 14:34:25 INFO     root Copying original metadata file to cog dir: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_lsm.dim\n",
      "2020-10-21 14:34:25 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 COPIED original METADATA\n",
      "2020-10-21 14:34:25 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 Creating dataset YAML\n",
      "2020-10-21 14:34:25 INFO     root Preparing scene S1A_IW_GRDH_1SDV_20200504T064007_tmp\n",
      "2020-10-21 14:34:25 INFO     root Scene path /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007\n",
      "2020-10-21 14:34:25 INFO     root prod_path: ['/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VV_db.tif', '/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_LayoverShadow_MASK_VH.tif', '/tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VH_db.tif'], scene_name: S1A_IW_GRDH_1SDV_20200504T064007_tmp\n",
      "2020-10-21 14:34:25 DEBUG    root {'vv': {'path': 'S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VV_db.tif'}, 'layovershadow_mask': {'path': 'S1A_IW_GRDH_1SDV_20200504T064007_LayoverShadow_MASK_VH.tif'}, 'vh': {'path': 'S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VH_db.tif'}}\n",
      "2020-10-21 14:34:25 DEBUG    root in get geometry /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VH_db.tif\n",
      "2020-10-21 14:34:25 INFO     botocore.credentials Found credentials in environment variables.\n",
      "2020-10-21 14:34:25 DEBUG    root Created yaml: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/datacube-metadata.yaml\n",
      "2020-10-21 14:34:25 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 Created original METADATA\n",
      "2020-10-21 14:34:25 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 Uploading to S3 Bucket\n",
      "2020-10-21 14:34:25 DEBUG    root Endpoint URL: http://s3-uk-1.sa-catapult.co.uk\n",
      "2020-10-21 14:34:26 INFO     root Local source file: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VV_db.tif\n",
      "2020-10-21 14:34:26 INFO     root S3 target file: luigi/fiji/sentinel_1/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VV_db.tif\n",
      "2020-10-21 14:34:26 INFO     root Start: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VV_db.tif 2020-10-21 14:34:26\n",
      "2020-10-21 14:34:41 INFO     root Finish: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VV_db.tif 2020-10-21 14:34:41\n",
      "2020-10-21 14:34:41 DEBUG    root Endpoint URL: http://s3-uk-1.sa-catapult.co.uk\n",
      "2020-10-21 14:34:41 INFO     root Local source file: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/datacube-metadata.yaml\n",
      "2020-10-21 14:34:41 INFO     root S3 target file: luigi/fiji/sentinel_1/S1A_IW_GRDH_1SDV_20200504T064007/datacube-metadata.yaml\n",
      "2020-10-21 14:34:41 INFO     root Start: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/datacube-metadata.yaml 2020-10-21 14:34:41\n",
      "2020-10-21 14:34:41 INFO     root Finish: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/datacube-metadata.yaml 2020-10-21 14:34:41\n",
      "2020-10-21 14:34:41 DEBUG    root Endpoint URL: http://s3-uk-1.sa-catapult.co.uk\n",
      "2020-10-21 14:34:41 INFO     root Local source file: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_LayoverShadow_MASK_VH.tif\n",
      "2020-10-21 14:34:41 INFO     root S3 target file: luigi/fiji/sentinel_1/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_LayoverShadow_MASK_VH.tif\n",
      "2020-10-21 14:34:41 INFO     root Start: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_LayoverShadow_MASK_VH.tif 2020-10-21 14:34:41\n",
      "2020-10-21 14:34:42 INFO     root Finish: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_LayoverShadow_MASK_VH.tif 2020-10-21 14:34:42\n",
      "2020-10-21 14:34:42 DEBUG    root Endpoint URL: http://s3-uk-1.sa-catapult.co.uk\n",
      "2020-10-21 14:34:42 INFO     root Local source file: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_lsm.dim\n",
      "2020-10-21 14:34:42 INFO     root S3 target file: luigi/fiji/sentinel_1/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_lsm.dim\n",
      "2020-10-21 14:34:42 INFO     root Start: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_lsm.dim 2020-10-21 14:34:42\n",
      "2020-10-21 14:34:42 INFO     root Finish: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_lsm.dim 2020-10-21 14:34:42\n",
      "2020-10-21 14:34:42 DEBUG    root Endpoint URL: http://s3-uk-1.sa-catapult.co.uk\n",
      "2020-10-21 14:34:43 INFO     root Local source file: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VH_db.tif\n",
      "2020-10-21 14:34:43 INFO     root S3 target file: luigi/fiji/sentinel_1/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VH_db.tif\n",
      "2020-10-21 14:34:43 INFO     root Start: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VH_db.tif 2020-10-21 14:34:43\n",
      "2020-10-21 14:34:58 INFO     root Finish: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_Gamma0_VH_db.tif 2020-10-21 14:34:58\n",
      "2020-10-21 14:34:58 DEBUG    root Endpoint URL: http://s3-uk-1.sa-catapult.co.uk\n",
      "2020-10-21 14:34:58 INFO     root Local source file: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_dB.dim\n",
      "2020-10-21 14:34:58 INFO     root S3 target file: luigi/fiji/sentinel_1/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_dB.dim\n",
      "2020-10-21 14:34:58 INFO     root Start: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_dB.dim 2020-10-21 14:34:58\n",
      "2020-10-21 14:34:58 INFO     root Finish: /tmp/data/intermediate/S1A_IW_GRDH_1SDV_20200504T064007_tmp/S1A_IW_GRDH_1SDV_20200504T064007/S1A_IW_GRDH_1SDV_20200504T064007_S1A_IW_GRDH_1SDV_20200504T064007_Orb_Cal_Deb_ML_TF_TC_dB.dim 2020-10-21 14:34:58\n",
      "2020-10-21 14:34:58 INFO     root S1A_IW_GRDH_1SDV_20200504T064007_20200504T064042_032411_03C0C7_FE9D.SAFE S1A_IW_GRDH_1SDV_20200504T064007 Uploaded to S3 Bucket\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "not boo\n"
     ]
    },
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "2020-10-21 14:34:59 INFO     worker Total processing time 0:34:20\n"
     ]
    }
   ],
   "source": [
    "import datetime\n",
    "\n",
    "while not q.empty():\n",
    "    item = q.lease(lease_secs=1800, block=True, timeout=600)\n",
    "    if item is not None:\n",
    "        itemstr = item.decode(\"utf=8\")\n",
    "        logger.info(f\"Working on {itemstr}\")\n",
    "\n",
    "        start = datetime.datetime.now().replace(microsecond=0)\n",
    "        process_scene(itemstr)\n",
    "        q.complete(item)\n",
    "        end = datetime.datetime.now().replace(microsecond=0)\n",
    "        logger.info(f\"Total processing time {end - start}\")\n",
    "    else:\n",
    "        logger.info(\"Waiting for work\")"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {
    "pycharm": {
     "name": "#%%\n"
    }
   },
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "2020-10-21 14:34:59 INFO     worker Queue empty!\n"
     ]
    }
   ],
   "source": [
    "logger.info(\"Queue empty!\")"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {
    "pycharm": {
     "name": "#%% md\n"
    }
   },
   "source": [
    "---"
   ]
  }
 ],
 "metadata": {
  "kernelspec": {
   "display_name": "Python 3",
   "language": "python",
   "name": "python3"
  },
  "language_info": {
   "codemirror_mode": {
    "name": "ipython",
    "version": 3
   },
   "file_extension": ".py",
   "mimetype": "text/x-python",
   "name": "python",
   "nbconvert_exporter": "python",
   "pygments_lexer": "ipython3",
   "version": "3.7.4"
  }
 },
 "nbformat": 4,
 "nbformat_minor": 4
}