search

NOAA-GFDL / MDTF-diagnostics

Analysis framework and collection of process-oriented diagnostics for weather and climate simulations
https://mdtf-diagnostics.readthedocs.io/en/main/
Other
56 stars 95 forks source link

Variable not accepted by framework (CMIP6 CESM2 variable standard name) #284

Closed chiaweh2 closed 2 years ago

chiaweh2 commented 2 years ago

Bug Severity

Describe the bug The variable is not accepted for its standard name based on the error code shown while execute the framework to test the POD. After I remove the variables with problems the framework proceeds.

Steps To Reproduce The json file is https://github.com/chiaweh2/MDTF-diagnostics/blob/feature/ocean_flux_matrix/diagnostics/ocn_surf_flux_diag/settings.jsonc The 2 variables causing the problem follows the CMIP convention. https://pcmdi.llnl.gov/mips/cmip3/variableList.html#Table_A1a

Environment Describe the system environment:

Log information and/or terminal output error code after executing the mdtf 

=== Starting /home/joedhsu/mdtf/MDTF-diagnostics/mdtf_framework.py

PACKAGE SETTINGS:
  case_list(0):
    CASENAME: NCAR_CESM2_hist_r1i1p1f1
    model: CMIP
    convention: CMIP
    FIRSTYR: 2000
    LASTYR: 2009
    pod_list:
      ocn_surf_flux_diag
    experiment: ""
  paths:
    CODE_ROOT: /home/joedhsu/mdtf/MDTF-diagnostics
    OBS_DATA_ROOT: /home/joedhsu/mdtf/inputdata/obs_data
    MODEL_DATA_ROOT: /home/joedhsu/mdtf/inputdata/model
    WORKING_DIR: /home/joedhsu/mdtf/wkdir
    OUTPUT_DIR: /home/joedhsu/mdtf/wkdir
    conda_root: /home/joedhsu/miniconda3
    conda_env_root: /home/joedhsu/miniconda3/envs
    TEMP_DIR_ROOT: /home/joedhsu/mdtf/wkdir
  settings:
    environment_manager: Conda
    runtime_manager: subprocess
    convention: CMIP
    data_manager: Local_File
    output_manager: html
    save_nc: true
    make_variab_tar: true
    file_transfer_timeout: 300
  env_vars:
    RGB: /home/joedhsu/mdtf/MDTF-diagnostics/shared/rgb
    MPLBACKEND: Agg
### MDTFFramework: initializing case 'NCAR_CESM2_hist_r1i1p1f1'.
WARNING: Deactivated <#jmIk:ocn_surf_flux_diag.sfcWind> due to PodConfigEvent("Deactivating <#jmIk:ocn_surf_flux_diag.sfcWind> due to variable name translation: "Standard name 'wind_speed' not defined in convention 'CMIP'.".").
Request for <#jmIk:ocn_surf_flux_diag.sfcWind> (='(not translated)' @ 1day) failed; looking for alternate data.
ERROR: Deactivated <#j3MU:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag> due to PodDataError("Requested data not available for POD <#j3MU:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#jmIk:ocn_surf_flux_diag.sfcWind>.").
ERROR: Deactivated <#SV0O:NCAR_CESM2_hist_r1i1p1f1> due to ChildFailureEvent("Deactivating <#SV0O:NCAR_CESM2_hist_r1i1p1f1> due to failure of all child objects.").

After removing the variables

=== Starting /home/joedhsu/mdtf/MDTF-diagnostics/mdtf_framework.py

PACKAGE SETTINGS:
  case_list(0):
    CASENAME: NCAR_CESM2_hist_r1i1p1f1
    model: CMIP
    convention: CMIP
    FIRSTYR: 2000
    LASTYR: 2009
    pod_list:
      ocn_surf_flux_diag
    experiment: ""
  paths:
    CODE_ROOT: /home/joedhsu/mdtf/MDTF-diagnostics
    OBS_DATA_ROOT: /home/joedhsu/mdtf/inputdata/obs_data
    MODEL_DATA_ROOT: /home/joedhsu/mdtf/inputdata/model
    WORKING_DIR: /home/joedhsu/mdtf/wkdir
    OUTPUT_DIR: /home/joedhsu/mdtf/wkdir
    conda_root: /home/joedhsu/miniconda3
    conda_env_root: /home/joedhsu/miniconda3/envs
    TEMP_DIR_ROOT: /home/joedhsu/mdtf/wkdir
  settings:
    environment_manager: Conda
    runtime_manager: subprocess
    convention: CMIP
    data_manager: Local_File
    file_transfer_timeout: 300
    output_manager: html
    save_nc: true
    make_variab_tar: true
  env_vars:
    RGB: /home/joedhsu/mdtf/MDTF-diagnostics/shared/rgb
    MPLBACKEND: Agg
### MDTFFramework: initializing case 'NCAR_CESM2_hist_r1i1p1f1'.
### MDTFFramework: requesting data for case 'NCAR_CESM2_hist_r1i1p1f1'.
Starting data file search at /home/joedhsu/mdtf/inputdata/model:
Directory crawl found 6 files.
Querying <ts> (surface_temperature).
Querying <psl> (air_pressure_at_mean_sea_level).
Querying <hfls> (surface_upward_latent_heat_flux).
Querying <pr> (precipitation_flux).
WARNING: /home/joedhsu/mdtf/MDTF-diagnostics/src/data_manager.py:1010: FutureWarning: Passing 'suffixes' which cause duplicate columns {'sample_dataset_x'} in the result is deprecated and will raise a MergeError in a future version.
  how='inner', on=key_col, sort=False, validate='1:1'

Fetching <#i8E1:ocn_surf_flux_diag.ts> (='ts' @ 1day).
Fetching <#i8JC:ocn_surf_flux_diag.psl> (='psl' @ 1day).
Fetching <#i8OD:ocn_surf_flux_diag.hfls> (='hfls' @ 1day).
Fetching <#i8TK:ocn_surf_flux_diag.pr> (='pr' @ 1day).
wrongkindofdoctor commented 2 years ago

Thanks for all of the info, @chiaweh2! It looks like wind_speed is missing from the CMIP fieldlist, so I put in a PR to add it (note that I didn't see it in the link you included, but was able to find it in the CF standard Name table). The rest of your variable standard names already exist in the CMIP field list, so it may be that adding wind_speed will fix the translation for the other variable that is giving you trouble (not sure which one it is based on your logs). If not, I will continue working on the problem.

Note that I will first merge in PR #266 (I'll nudge John to give his final approval), which will allow specification of a new "modifier" attribute for sfcWind in your settings.jsonc file. This will differentiate a 3D wind_speed field defined at the surface (or another height) from a 4D wind_speed field that a POD might require a specific pressure level (or levels) from.

chiaweh2 commented 2 years ago

@wrongkindofdoctor thank you for the explanation and adding/checking the variables. The other variables that has problem is specific humidity - huss. I notice it is not in the fieldlist, either. Since the PR you mentioned is not merged to develop branch yet, do I add the variables myself to the field list now to keep working on the POD? Or is there any other way that I can solve this error for now. Thank you!

chiaweh2 commented 2 years ago

@wrongkindofdoctor just a quick update on my testing. Adding the variable in the fieldlist in CMIP seems to work. However, it is showing error in the following

=== Starting /home/joedhsu/mdtf/MDTF-diagnostics/mdtf_framework.py

PACKAGE SETTINGS:
  case_list(0):
    CASENAME: NCAR_CESM2_hist_r1i1p1f1
    model: CMIP
    convention: CMIP
    FIRSTYR: 2000
    LASTYR: 2009
    pod_list:
      ocn_surf_flux_diag
    experiment: ""
  paths:
    CODE_ROOT: /home/joedhsu/mdtf/MDTF-diagnostics
    OBS_DATA_ROOT: /home/joedhsu/mdtf/inputdata/obs_data
    MODEL_DATA_ROOT: /home/joedhsu/mdtf/inputdata/model
    WORKING_DIR: /home/joedhsu/mdtf/wkdir
    OUTPUT_DIR: /home/joedhsu/mdtf/wkdir
    conda_root: /home/joedhsu/miniconda3
    conda_env_root: /home/joedhsu/miniconda3/envs
    TEMP_DIR_ROOT: /home/joedhsu/mdtf/wkdir
  settings:
    output_manager: html
    save_nc: true
    make_variab_tar: true
    convention: CMIP
    data_manager: Local_File
    environment_manager: Conda
    runtime_manager: subprocess
    file_transfer_timeout: 300
  env_vars:
    RGB: /home/joedhsu/mdtf/MDTF-diagnostics/shared/rgb
    MPLBACKEND: Agg
### MDTFFramework: initializing case 'NCAR_CESM2_hist_r1i1p1f1'.
### MDTFFramework: requesting data for case 'NCAR_CESM2_hist_r1i1p1f1'.
Starting data file search at /home/joedhsu/mdtf/inputdata/model:
Directory crawl found 6 files.
Querying <ts> (surface_temperature).
Querying <psl> (air_pressure_at_mean_sea_level).
Querying <sfcWind> (wind_speed).
Querying <huss> (specific_humidity).
Querying <hfls> (surface_upward_latent_heat_flux).
Querying <pr> (precipitation_flux).
WARNING: /home/joedhsu/mdtf/MDTF-diagnostics/src/data_manager.py:1010: FutureWarning: Passing 'suffixes' which cause duplicate columns {'sample_dataset_x'} in the result is deprecated and will raise a MergeError in a future version.
  how='inner', on=key_col, sort=False, validate='1:1'

Fetching <#nDMz:ocn_surf_flux_diag.ts> (='ts' @ 1day).
Fetching <#nDSf:ocn_surf_flux_diag.psl> (='psl' @ 1day).
Fetching <#nDXu:ocn_surf_flux_diag.sfcWind> (='sfcWind' @ 1day).
Fetching <#nE2M:ocn_surf_flux_diag.huss> (='huss' @ 1day).
Fetching <#nE83:ocn_surf_flux_diag.hfls> (='hfls' @ 1day).
Fetching <#nEdk:ocn_surf_flux_diag.pr> (='pr' @ 1day).
Preprocessing <#nDMz:ocn_surf_flux_diag.ts> (='ts' @ 1day).
WARNING: /home/joedhsu/miniconda3/envs/_MDTF_base/lib/python3.7/site-packages/xarray/conventions.py:500: SerializationWarning: variable 'ts' has multiple fill values {1e+20, 1e+20}, decoding all values to NaN.
  decode_timedelta=decode_timedelta,

No standard_name for 'time_bnds' found in dataset; setting to 'time'.
No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.
No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.
Received event while preprocessing <#nDMz:ocn_surf_flux_diag.ts>: DataPreprocessEvent("Caught exception while Preprocessing on <#nDMz:ocn_surf_flux_diag.ts> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")
Deactivated <#nDMz:ocn_surf_flux_diag.ts> due to ChildFailureEvent("Deactivating <#nDMz:ocn_surf_flux_diag.ts> due to failure of all child objects.").
Request for <#nDMz:ocn_surf_flux_diag.ts> (='ts' @ 1day) failed; looking for alternate data.
ERROR: Deactivated <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag> due to PodDataError("Requested data not available for POD <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#nDMz:ocn_surf_flux_diag.ts>.").
ERROR: Deactivated <#nbhb:NCAR_CESM2_hist_r1i1p1f1> due to ChildFailureEvent("Deactivating <#nbhb:NCAR_CESM2_hist_r1i1p1f1> due to failure of all child objects.").
Deactivated <#nDSf:ocn_surf_flux_diag.psl> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#nDMz:ocn_surf_flux_diag.ts>.") from deactivation of parent <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#nDXu:ocn_surf_flux_diag.sfcWind> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#nDMz:ocn_surf_flux_diag.ts>.") from deactivation of parent <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#nE2M:ocn_surf_flux_diag.huss> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#nDMz:ocn_surf_flux_diag.ts>.") from deactivation of parent <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#nE83:ocn_surf_flux_diag.hfls> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#nDMz:ocn_surf_flux_diag.ts>.") from deactivation of parent <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#nEdk:ocn_surf_flux_diag.pr> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#nDMz:ocn_surf_flux_diag.ts>.") from deactivation of parent <#nDDS:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Preprocessing <#nDSf:ocn_surf_flux_diag.psl> (='psl' @ 1day).
WARNING: /home/joedhsu/miniconda3/envs/_MDTF_base/lib/python3.7/site-packages/xarray/conventions.py:500: SerializationWarning: variable 'psl' has multiple fill values {1e+20, 1e+20}, decoding all values to NaN.
  decode_timedelta=decode_timedelta,
wrongkindofdoctor commented 2 years ago

@chiaweh2 I merged both PRs. It looks like I need to add some similar mods for specific humidity; the CMIP fieldlist has the 4d field (called 'hus'), but not a 3D field defined on a single surface. I'll put that in right away.

wrongkindofdoctor commented 2 years ago

@chiaweh2 Okay, 3D specific humidity is in the CMIP fieldlist. Go ahead and pull the develop branch updates into your POD branch, and add the "modifier" attribute to "sfcWind" and "huss" in your POD's settings.jsonc file like so:

"sfcWind": {
      "standard_name": "wind_speed",
      "units": "m s-1",
      "modifier": "atmos_height",
      "dimensions": [
        "time",
        "lat",
        "lon"
      ]
    },
    "huss": {
      "standard_name": "specific_humidity",
      "units": "1",
      "modifier": "atmos_height",
      "dimensions": [
        "time",
        "lat",
        "lon"
      ]
    },

This hopefully will resolve the time slice error, since the atmos_height modifier will tell the POD to use the 3D surface fields instead of a (non-existent) slice of the 4D fields. Let me know if you have further issues, and point me toward the test obs and model datasets you are using so I can try to fully replicate the problem.

chiaweh2 commented 2 years ago

@wrongkindofdoctor Thank you so much for the update! I have fetched and merged my feature branch with upstream/develop. However, there still seems to have error when querying the variable sfcWind. I notice in your two commits including the 3_d surface field for specific humidity and surface wind it is included as the name of "hus" and "wind_speed" but not "huss" and "sfcWind". Should this be the reason of the error that I am having? Or the error is caused by something else? Thank you!

### MDTFFramework: initializing case 'NCAR_CESM2_hist_r1i1p1f1'.
### MDTFFramework: requesting data for case 'NCAR_CESM2_hist_r1i1p1f1'.
Starting data file search at /home/joedhsu/mdtf/inputdata/model:
Directory crawl found 6 files.
Querying <ts> (surface_temperature).
Querying <psl> (air_pressure_at_mean_sea_level).
Querying <wind_speed> (wind_speed).
Deactivated <#bKqJ:ocn_surf_flux_diag.sfcWind> due to DataQueryEvent("No data found.").
Request for <#bKqJ:ocn_surf_flux_diag.sfcWind> (='wind_speed' @ 1day) failed; looking for alternate data.
ERROR: Deactivated <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag> due to PodDataError("Requested data not available for POD <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#bKqJ:ocn_surf_flux_diag.sfcWind>.").
ERROR: Deactivated <#bBKO:NCAR_CESM2_hist_r1i1p1f1> due to ChildFailureEvent("Deactivating <#bBKO:NCAR_CESM2_hist_r1i1p1f1> due to failure of all child objects.").
Deactivated <#bKfS:ocn_surf_flux_diag.ts> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#bKqJ:ocn_surf_flux_diag.sfcWind>.") from deactivation of parent <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#bKls:ocn_surf_flux_diag.psl> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#bKqJ:ocn_surf_flux_diag.sfcWind>.") from deactivation of parent <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#bKvV:ocn_surf_flux_diag.huss> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#bKqJ:ocn_surf_flux_diag.sfcWind>.") from deactivation of parent <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#bKBb:ocn_surf_flux_diag.hfls> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#bKqJ:ocn_surf_flux_diag.sfcWind>.") from deactivation of parent <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#bKGj:ocn_surf_flux_diag.pr> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#bKqJ:ocn_surf_flux_diag.sfcWind>.") from deactivation of parent <#bK78:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Querying <hus> (specific_humidity).
Querying <hfls> (surface_upward_latent_heat_flux).
Querying <pr> (precipitation_flux).
Received event at DataSource level: DataQueryEvent("Too many iterations in select_data() for <#bBKO:NCAR_CESM2_hist_r1i1p1f1>.").
### MDTFFramework: Data request for case 'NCAR_CESM2_hist_r1i1p1f1' failed; skipping execution.

For model, I am using the CESM2 CMIP6 historical run in r1i1p1f1 with daily output and observational data is download by myself which is not yet included in the sample data. If needed, I can provide the observational data. However, I think my current error is not related to the observational data? My newest merged and edit feature branch is here

wrongkindofdoctor commented 2 years ago

@chiaweh2 I changed the 3d variable name from "wind_speed" to "sfcWind" and 3D "hus" to "huss" in the CMIP fieldlist on the develop branch. Neither name was listed as a variable in the table I linked previously, but sfcWind and huss appear in the esgf CMIP 6 variable name side bar. Looking at some of the the file metadata, "huss" is for near-surface specific humidity, while "hus" is the name for the 4D field.

If this does not solve the variable mismatch problem, or you have other issues that you don't think can be solved by looking at the error log, please send me the obs data file if it is not too large, or post it on a server where I can access it. For the model data, if you can give me a two sample values for huss, sfcWind, and hfls, I can add the variables to the synthetic data generator and create some daily output to test with.

chiaweh2 commented 2 years ago

@wrongkindofdoctor Thank you! It works but seems to proceed to the next error (shown below). Based on the error code, it seem to related to the "lon_bnds", "lat_bnds", and "time_bnds" variables that are renamed to longitude, latitude, and time. The error seems to occur when cropping the time range.

I have prepared the Observational data and model data for the three variables you listed in case you want to check out the data structure. You can download through here

### MDTFFramework: initializing case 'NCAR_CESM2_hist_r1i1p1f1'.
### MDTFFramework: requesting data for case 'NCAR_CESM2_hist_r1i1p1f1'.
Starting data file search at /home/joedhsu/mdtf/inputdata/model:
Directory crawl found 6 files.
Querying <ts> (surface_temperature).
Querying <psl> (air_pressure_at_mean_sea_level).
Querying <sfcWind> (wind_speed).
Querying <huss> (specific_humidity).
Querying <hfls> (surface_upward_latent_heat_flux).
Querying <pr> (precipitation_flux).
WARNING: /home/joedhsu/mdtf/MDTF-diagnostics/src/data_manager.py:1021: FutureWarning: Passing 'suffixes' which cause duplicate columns {'sample_dataset_x'} in the result is deprecated and will raise a MergeError in a future version.
  how='inner', on=key_col, sort=False, validate='1:1'

Fetching <#2ZqQ:ocn_surf_flux_diag.ts> (='ts' @ 1day).
Fetching <#351a:ocn_surf_flux_diag.psl> (='psl' @ 1day).
Fetching <#3adQ:ocn_surf_flux_diag.sfcWind> (='sfcWind' @ 1day).
Fetching <#3fk0:ocn_surf_flux_diag.huss> (='huss' @ 1day).
Fetching <#3kzQ:ocn_surf_flux_diag.hfls> (='hfls' @ 1day).
Fetching <#3pKk:ocn_surf_flux_diag.pr> (='pr' @ 1day).
Preprocessing <#2ZqQ:ocn_surf_flux_diag.ts> (='ts' @ 1day).
WARNING: /home/joedhsu/miniconda3/envs/_MDTF_base/lib/python3.7/site-packages/xarray/conventions.py:500: SerializationWarning: variable 'ts' has multiple fill values {1e+20, 1e+20}, decoding all values to NaN.
  decode_timedelta=decode_timedelta,

No standard_name for 'time_bnds' found in dataset; setting to 'time'.
No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.
No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.
Received event while preprocessing <#2ZqQ:ocn_surf_flux_diag.ts>: DataPreprocessEvent("Caught exception while Preprocessing on <#2ZqQ:ocn_surf_flux_diag.ts> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")
Deactivated <#2ZqQ:ocn_surf_flux_diag.ts> due to ChildFailureEvent("Deactivating <#2ZqQ:ocn_surf_flux_diag.ts> due to failure of all child objects.").
Request for <#2ZqQ:ocn_surf_flux_diag.ts> (='ts' @ 1day) failed; looking for alternate data.
ERROR: Deactivated <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag> due to PodDataError("Requested data not available for POD <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#2ZqQ:ocn_surf_flux_diag.ts>.").
ERROR: Deactivated <#TyKm:NCAR_CESM2_hist_r1i1p1f1> due to ChildFailureEvent("Deactivating <#TyKm:NCAR_CESM2_hist_r1i1p1f1> due to failure of all child objects.").
Deactivated <#351a:ocn_surf_flux_diag.psl> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#2ZqQ:ocn_surf_flux_diag.ts>.") from deactivation of parent <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#3adQ:ocn_surf_flux_diag.sfcWind> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#2ZqQ:ocn_surf_flux_diag.ts>.") from deactivation of parent <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#3fk0:ocn_surf_flux_diag.huss> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#2ZqQ:ocn_surf_flux_diag.ts>.") from deactivation of parent <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#3kzQ:ocn_surf_flux_diag.hfls> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#2ZqQ:ocn_surf_flux_diag.ts>.") from deactivation of parent <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Deactivated <#3pKk:ocn_surf_flux_diag.pr> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#2ZqQ:ocn_surf_flux_diag.ts>.") from deactivation of parent <#2Qx4:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").
Preprocessing <#351a:ocn_surf_flux_diag.psl> (='psl' @ 1day).
WARNING: /home/joedhsu/miniconda3/envs/_MDTF_base/lib/python3.7/site-packages/xarray/conventions.py:500: SerializationWarning: variable 'psl' has multiple fill values {1e+20, 1e+20}, decoding all values to NaN.
  decode_timedelta=decode_timedelta,

No standard_name for 'time_bnds' found in dataset; setting to 'time'.
No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.
No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.
Received event while preprocessing <#351a:ocn_surf_flux_diag.psl>: DataPreprocessEvent("Caught exception while Preprocessing on <#351a:ocn_surf_flux_diag.psl> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")
Preprocessing <#3adQ:ocn_surf_flux_diag.sfcWind> (='sfcWind' @ 1day).
WARNING: /home/joedhsu/miniconda3/envs/_MDTF_base/lib/python3.7/site-packages/xarray/conventions.py:500: SerializationWarning: variable 'sfcWind' has multiple fill values {1e+20, 1e+20}, decoding all values to NaN.
  decode_timedelta=decode_timedelta,

No standard_name for 'time_bnds' found in dataset; setting to 'time'.
No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.
No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.
Received event while preprocessing <#3adQ:ocn_surf_flux_diag.sfcWind>: DataPreprocessEvent("Caught exception while Preprocessing on <#3adQ:ocn_surf_flux_diag.sfcWind> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")
Preprocessing <#3fk0:ocn_surf_flux_diag.huss> (='huss' @ 1day).
WARNING: /home/joedhsu/miniconda3/envs/_MDTF_base/lib/python3.7/site-packages/xarray/conventions.py:500: SerializationWarning: variable 'huss' has multiple fill values {1e+20, 1e+20}, decoding all values to NaN.
  decode_timedelta=decode_timedelta,

No standard_name for 'time_bnds' found in dataset; setting to 'time'.
No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.
No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.
Received event while preprocessing <#3fk0:ocn_surf_flux_diag.huss>: DataPreprocessEvent("Caught exception while Preprocessing on <#3fk0:ocn_surf_flux_diag.huss> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")
Preprocessing <#3kzQ:ocn_surf_flux_diag.hfls> (='hfls' @ 1day).
WARNING: /home/joedhsu/miniconda3/envs/_MDTF_base/lib/python3.7/site-packages/xarray/conventions.py:500: SerializationWarning: variable 'hfls' has multiple fill values {1e+20, 1e+20}, decoding all values to NaN.
  decode_timedelta=decode_timedelta,

No standard_name for 'time_bnds' found in dataset; setting to 'time'.
No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.
No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.
Received event while preprocessing <#3kzQ:ocn_surf_flux_diag.hfls>: DataPreprocessEvent("Caught exception while Preprocessing on <#3kzQ:ocn_surf_flux_diag.hfls> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")
Preprocessing <#3pKk:ocn_surf_flux_diag.pr> (='pr' @ 1day).
WARNING: /home/joedhsu/miniconda3/envs/_MDTF_base/lib/python3.7/site-packages/xarray/conventions.py:500: SerializationWarning: variable 'pr' has multiple fill values {1e+20, 1e+20}, decoding all values to NaN.
  decode_timedelta=decode_timedelta,

No standard_name for 'time_bnds' found in dataset; setting to 'time'.
No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.
No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.
Received event while preprocessing <#3pKk:ocn_surf_flux_diag.pr>: DataPreprocessEvent("Caught exception while Preprocessing on <#3pKk:ocn_surf_flux_diag.pr> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")
Received event at DataSource level: DataQueryEvent("Too many iterations in select_data() for <#TyKm:NCAR_CESM2_hist_r1i1p1f1>.").
### MDTFFramework: Data request for case 'NCAR_CESM2_hist_r1i1p1f1' failed; skipping execution.
<#TyKm:NCAR_CESM2_hist_r1i1p1f1>: Creating '/home/joedhsu/mdtf/wkdir/MDTF_NCAR_CESM2_hist_r1i1p1f1_2000_2009.v9.tar'.

--------------------------------------------------------------------------------
Exiting with errors.
Summary for NCAR_CESM2_hist_r1i1p1f1:
    The following PODs raised errors: ocn_surf_flux_diag
    Output written to /home/joedhsu/mdtf/wkdir/MDTF_NCAR_CESM2_hist_r1i1p1f1_2000_2009.v9
wrongkindofdoctor commented 2 years ago

@chiaweh2 I've been testing your POD on my debug_ofm branch here. I was able to get your POD to ingest the synthetic model data, and solved some issues with the environment. Note that I consulted the POD-specific error log located in wkdir/[model name]/ocn_surf_flux_diag/ocn_surf_flux_diag.log to pin this down; please include output from this log as we continue debugging the issue.

First, I added -metpy to python3_env_base.yml

Second, I added import os to ocn_surf_flux_diag.py.

After making these changes, I ran into a type issue in model_read where ds_atm_regional is defined. Numpy throws a TypeError for these two lines:

## Start execution of <#cTX3:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>
--------------------------------------------------------------------------------
_CONDA_EXE=/home/$USER/miniconda3/bin/conda
_CONDA_ROOT=/home/$USER/miniconda3
Found program python3.
Traceback (most recent call last):
  File "/home/$USER/mdtf/MDTF-diagnostics/diagnostics/ocn_surf_flux_diag/ocn_surf_flux_diag.py", line 45, in <module>
    ds_cesm2 = regional_var(varlist, lon_lim, lat_lim, year_lim)
  File "/home/$USER/mdtf/MDTF-diagnostics/diagnostics/ocn_surf_flux_diag/model_read.py", line 28, in regional_var
    (ds_atm['time.year']>=np.array(year_lim).min())&
  File "/home/$USER/miniconda3/envs/_MDTF_ocn_surf_flux_diag/lib/python3.7/site-packages/numpy/core/_methods.py", line 43, in _amin
    return umr_minimum(a, axis, None, out, keepdims, initial, where)
TypeError: cannot perform reduce with flexible type

I'm not entirely sure how to solve this at the moment, but this stackoverflow post may offer a starting point. You could try it, or maybe copy the time data to an int array without the time coordinate info, which is an object type, and may be causing the problem.

chiaweh2 commented 2 years ago

@wrongkindofdoctor Thank you! Do you mind providing me the synthetic data that you used? I don't seem to be able to make the framework to digest my dataset even after merging with develop branch. Based on the changes you made, I am suspecting it is the model data structure. Or should I fork your branch and merge with your debug branch?

For the needed package, I actually create a .yml file that include the needed module like metpy, but adding them into the python_base env is even better. Thank you!

Thank you for letting me know the log file position, the log file of my latest test run is here 

MDTF PACKAGE LOG

Started logging at 2021-10-29 15:45:57.214546
git hash/branch: 0b78ef333159ede159591c91017941bb967210a8 (on feature/ocean_flux_matrix)
sys.platform: 'linux'
sys.version: '3.7.10 | packaged by conda-forge | (default, Oct 13 2021, 20:51:14) 
[GCC 9.4.0]'
--------------------------------------------------------------------------------

15:45:57 DEBUG: log (logs.py line 328):
    Setting CASE_ROOT_DIR to MODEL_DATA_ROOT = '/home/joedhsu/mdtf/inputdata/model'.

15:45:57 DEBUG: log (logs.py line 328):
    'sample_dataset' not supplied, using CASENAME = 'NCAR_CESM2_hist_r1i1p1f1'.

15:45:57 DEBUG: log (logs.py line 328):
    Set program for <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag> to 'python'.

15:45:57 DEBUG: log (logs.py line 328):
    PrecipRateToFluxFunction edit_request on <#O7KF:ocn_surf_flux_diag.pr>: caught KeyError("Standard name 'precipitation_rate' not defined in convention 'CMIP'.") when trying to translate 'precipitation_rate'; varlist unaltered.

15:45:57 INFO: log (logs.py line 328):
    Starting data file search at /home/joedhsu/mdtf/inputdata/model:

15:45:57 INFO: log (logs.py line 328):
    Directory crawl found 6 files.

15:45:57 DEBUG: log (logs.py line 328):
    Query batch: [<#O7jY:ocn_surf_flux_diag.ts>, <#O7pC:ocn_surf_flux_diag.psl>, <#O7uU:ocn_surf_flux_diag.sfcWind>, <#O7Aa:ocn_surf_flux_diag.huss>, <#O7Fu:ocn_surf_flux_diag.hfls>, <#O7KF:ocn_surf_flux_diag.pr>].

15:45:57 INFO: log (logs.py line 328):
    Querying <ts> (surface_temperature).

15:45:57 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(3)> for <#O7jY:ocn_surf_flux_diag.ts>

15:45:57 INFO: log (logs.py line 328):
    Querying <psl> (air_pressure_at_mean_sea_level).

15:45:57 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(1)> for <#O7pC:ocn_surf_flux_diag.psl>

15:45:57 INFO: log (logs.py line 328):
    Querying <sfcWind> (wind_speed).

15:45:57 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(0)> for <#O7uU:ocn_surf_flux_diag.sfcWind>

15:45:57 INFO: log (logs.py line 328):
    Querying <huss> (specific_humidity).

15:45:57 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(4)> for <#O7Aa:ocn_surf_flux_diag.huss>

15:45:57 INFO: log (logs.py line 328):
    Querying <hfls> (surface_upward_latent_heat_flux).

15:45:57 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(5)> for <#O7Fu:ocn_surf_flux_diag.hfls>

15:45:57 INFO: log (logs.py line 328):
    Querying <pr> (precipitation_flux).

15:45:57 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(2)> for <#O7KF:ocn_surf_flux_diag.pr>

15:45:57 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#O7jY:ocn_surf_flux_diag.ts>

15:45:57 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#O7pC:ocn_surf_flux_diag.psl>

15:45:57 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#O7uU:ocn_surf_flux_diag.sfcWind>

15:45:57 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#O7Aa:ocn_surf_flux_diag.huss>

15:45:57 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#O7Fu:ocn_surf_flux_diag.hfls>

15:45:57 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#O7KF:ocn_surf_flux_diag.pr>

15:45:57 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1

15:45:57 DEBUG: log (logs.py line 328):
    Setting experiment_key for 'NCAR_CESM2_hist_r1i1p1f1' to 'NCAR_CESM2_hist_r1i1p1f1'

15:45:57 DEBUG: log (logs.py line 328):
    DataKey(3) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

15:45:57 DEBUG: log (logs.py line 328):
    DataKey(1) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

15:45:57 DEBUG: log (logs.py line 328):
    DataKey(0) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

15:45:57 DEBUG: log (logs.py line 328):
    DataKey(4) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

15:45:57 DEBUG: log (logs.py line 328):
    DataKey(5) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

15:45:57 DEBUG: log (logs.py line 328):
    DataKey(2) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

15:45:57 DEBUG: log (logs.py line 328):
    Fetch batch: [<#O7jY:ocn_surf_flux_diag.ts>, <#O7pC:ocn_surf_flux_diag.psl>, <#O7uU:ocn_surf_flux_diag.sfcWind>, <#O7Aa:ocn_surf_flux_diag.huss>, <#O7Fu:ocn_surf_flux_diag.hfls>, <#O7KF:ocn_surf_flux_diag.pr>].

15:45:57 INFO: log (logs.py line 328):
    Fetching <#O7jY:ocn_surf_flux_diag.ts> (='ts' @ 1day).

15:45:57 DEBUG: log (logs.py line 328):
    Fetching DataKey(3).

15:45:57 DEBUG: log (logs.py line 328):
    Fetch DataKey(3): found /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.ts.day.nc.

15:45:57 INFO: log (logs.py line 328):
    Fetching <#O7pC:ocn_surf_flux_diag.psl> (='psl' @ 1day).

15:45:57 DEBUG: log (logs.py line 328):
    Fetching DataKey(1).

15:45:57 DEBUG: log (logs.py line 328):
    Fetch DataKey(1): found /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.psl.day.nc.

15:45:57 INFO: log (logs.py line 328):
    Fetching <#O7uU:ocn_surf_flux_diag.sfcWind> (='sfcWind' @ 1day).

15:45:57 DEBUG: log (logs.py line 328):
    Fetching DataKey(0).

15:45:57 DEBUG: log (logs.py line 328):
    Fetch DataKey(0): found /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.sfcWind.day.nc.

15:45:57 INFO: log (logs.py line 328):
    Fetching <#O7Aa:ocn_surf_flux_diag.huss> (='huss' @ 1day).

15:45:57 DEBUG: log (logs.py line 328):
    Fetching DataKey(4).

15:45:57 DEBUG: log (logs.py line 328):
    Fetch DataKey(4): found /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.huss.day.nc.

15:45:57 INFO: log (logs.py line 328):
    Fetching <#O7Fu:ocn_surf_flux_diag.hfls> (='hfls' @ 1day).

15:45:57 DEBUG: log (logs.py line 328):
    Fetching DataKey(5).

15:45:57 DEBUG: log (logs.py line 328):
    Fetch DataKey(5): found /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.hfls.day.nc.

15:45:57 INFO: log (logs.py line 328):
    Fetching <#O7KF:ocn_surf_flux_diag.pr> (='pr' @ 1day).

15:45:57 DEBUG: log (logs.py line 328):
    Fetching DataKey(2).

15:45:57 DEBUG: log (logs.py line 328):
    Fetch DataKey(2): found /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.pr.day.nc.

15:45:57 INFO: log (logs.py line 328):
    Preprocessing <#O7jY:ocn_surf_flux_diag.ts> (='ts' @ 1day).

15:45:57 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.ts.day.nc'.

15:45:58 DEBUG: log (logs.py line 328):
    Read 770 mb for <#O7jY:ocn_surf_flux_diag.ts>.

15:45:58 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 0001-01-01 00:00:00' from dataset.

15:45:58 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

15:45:58 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

15:45:58 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

15:45:58 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

15:45:58 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

15:45:58 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

15:45:58 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

15:45:58 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#O7jY:ocn_surf_flux_diag.ts>.

15:45:58 INFO: log (logs.py line 328):
    Received event while preprocessing <#O7jY:ocn_surf_flux_diag.ts>: DataPreprocessEvent("Caught exception while Preprocessing on <#O7jY:ocn_surf_flux_diag.ts> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

15:45:58 DEBUG: log (logs.py line 328):
    Eliminating DataKey(3) for <#O7jY:ocn_surf_flux_diag.ts>.

15:45:58 INFO: log (logs.py line 328):
    Deactivated <#O7jY:ocn_surf_flux_diag.ts> due to ChildFailureEvent("Deactivating <#O7jY:ocn_surf_flux_diag.ts> due to failure of all child objects.").

15:45:58 INFO: log (logs.py line 328):
    Request for <#O7jY:ocn_surf_flux_diag.ts> (='ts' @ 1day) failed; looking for alternate data.

15:45:58 ERROR: log (logs.py line 328):
    Deactivated <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag> due to PodDataError("Requested data not available for POD <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#O7jY:ocn_surf_flux_diag.ts>.").

15:45:58 ERROR: log (logs.py line 328):
    Deactivated <#NWH4:NCAR_CESM2_hist_r1i1p1f1> due to ChildFailureEvent("Deactivating <#NWH4:NCAR_CESM2_hist_r1i1p1f1> due to failure of all child objects.").

15:45:58 INFO: log (logs.py line 328):
    Deactivated <#O7pC:ocn_surf_flux_diag.psl> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#O7jY:ocn_surf_flux_diag.ts>.") from deactivation of parent <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").

15:45:58 INFO: log (logs.py line 328):
    Deactivated <#O7uU:ocn_surf_flux_diag.sfcWind> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#O7jY:ocn_surf_flux_diag.ts>.") from deactivation of parent <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").

15:45:58 INFO: log (logs.py line 328):
    Deactivated <#O7Aa:ocn_surf_flux_diag.huss> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#O7jY:ocn_surf_flux_diag.ts>.") from deactivation of parent <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").

15:45:58 INFO: log (logs.py line 328):
    Deactivated <#O7Fu:ocn_surf_flux_diag.hfls> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#O7jY:ocn_surf_flux_diag.ts>.") from deactivation of parent <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").

15:45:58 INFO: log (logs.py line 328):
    Deactivated <#O7KF:ocn_surf_flux_diag.pr> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#O7jY:ocn_surf_flux_diag.ts>.") from deactivation of parent <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").

15:45:58 INFO: log (logs.py line 328):
    Preprocessing <#O7pC:ocn_surf_flux_diag.psl> (='psl' @ 1day).

15:45:58 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.psl.day.nc'.

15:45:59 DEBUG: log (logs.py line 328):
    Read 770 mb for <#O7pC:ocn_surf_flux_diag.psl>.

15:45:59 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 0001-01-01 00:00:00' from dataset.

15:45:59 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

15:45:59 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

15:45:59 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

15:45:59 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

15:45:59 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

15:45:59 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

15:45:59 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

15:45:59 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#O7pC:ocn_surf_flux_diag.psl>.

15:45:59 INFO: log (logs.py line 328):
    Received event while preprocessing <#O7pC:ocn_surf_flux_diag.psl>: DataPreprocessEvent("Caught exception while Preprocessing on <#O7pC:ocn_surf_flux_diag.psl> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

15:45:59 DEBUG: log (logs.py line 328):
    Eliminating DataKey(1) for <#O7pC:ocn_surf_flux_diag.psl>.

15:45:59 INFO: log (logs.py line 328):
    Preprocessing <#O7uU:ocn_surf_flux_diag.sfcWind> (='sfcWind' @ 1day).

15:45:59 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.sfcWind.day.nc'.

15:45:59 DEBUG: log (logs.py line 328):
    Read 770 mb for <#O7uU:ocn_surf_flux_diag.sfcWind>.

15:46:00 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 0001-01-01 00:00:00' from dataset.

15:46:00 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

15:46:00 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

15:46:00 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

15:46:00 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

15:46:00 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

15:46:00 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

15:46:00 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

15:46:00 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#O7uU:ocn_surf_flux_diag.sfcWind>.

15:46:00 INFO: log (logs.py line 328):
    Received event while preprocessing <#O7uU:ocn_surf_flux_diag.sfcWind>: DataPreprocessEvent("Caught exception while Preprocessing on <#O7uU:ocn_surf_flux_diag.sfcWind> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

15:46:00 DEBUG: log (logs.py line 328):
    Eliminating DataKey(0) for <#O7uU:ocn_surf_flux_diag.sfcWind>.

15:46:00 INFO: log (logs.py line 328):
    Preprocessing <#O7Aa:ocn_surf_flux_diag.huss> (='huss' @ 1day).

15:46:00 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.huss.day.nc'.

15:46:00 DEBUG: log (logs.py line 328):
    Read 770 mb for <#O7Aa:ocn_surf_flux_diag.huss>.

15:46:00 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 0001-01-01 00:00:00' from dataset.

15:46:00 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

15:46:00 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

15:46:00 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

15:46:00 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

15:46:00 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

15:46:00 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

15:46:00 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

15:46:00 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#O7Aa:ocn_surf_flux_diag.huss>.

15:46:00 INFO: log (logs.py line 328):
    Received event while preprocessing <#O7Aa:ocn_surf_flux_diag.huss>: DataPreprocessEvent("Caught exception while Preprocessing on <#O7Aa:ocn_surf_flux_diag.huss> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

15:46:00 DEBUG: log (logs.py line 328):
    Eliminating DataKey(4) for <#O7Aa:ocn_surf_flux_diag.huss>.

15:46:00 INFO: log (logs.py line 328):
    Preprocessing <#O7Fu:ocn_surf_flux_diag.hfls> (='hfls' @ 1day).

15:46:00 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.hfls.day.nc'.

15:46:01 DEBUG: log (logs.py line 328):
    Read 770 mb for <#O7Fu:ocn_surf_flux_diag.hfls>.

15:46:01 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 0001-01-01 00:00:00' from dataset.

15:46:01 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

15:46:01 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

15:46:01 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

15:46:01 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

15:46:01 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

15:46:01 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

15:46:01 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

15:46:01 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#O7Fu:ocn_surf_flux_diag.hfls>.

15:46:01 INFO: log (logs.py line 328):
    Received event while preprocessing <#O7Fu:ocn_surf_flux_diag.hfls>: DataPreprocessEvent("Caught exception while Preprocessing on <#O7Fu:ocn_surf_flux_diag.hfls> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

15:46:01 DEBUG: log (logs.py line 328):
    Eliminating DataKey(5) for <#O7Fu:ocn_surf_flux_diag.hfls>.

15:46:01 INFO: log (logs.py line 328):
    Preprocessing <#O7KF:ocn_surf_flux_diag.pr> (='pr' @ 1day).

15:46:01 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.pr.day.nc'.

15:46:01 DEBUG: log (logs.py line 328):
    Read 770 mb for <#O7KF:ocn_surf_flux_diag.pr>.

15:46:02 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 0001-01-01 00:00:00' from dataset.

15:46:02 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

15:46:02 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

15:46:02 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

15:46:02 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

15:46:02 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

15:46:02 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

15:46:02 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

15:46:02 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#O7KF:ocn_surf_flux_diag.pr>.

15:46:02 INFO: log (logs.py line 328):
    Received event while preprocessing <#O7KF:ocn_surf_flux_diag.pr>: DataPreprocessEvent("Caught exception while Preprocessing on <#O7KF:ocn_surf_flux_diag.pr> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

15:46:02 DEBUG: log (logs.py line 328):
    Eliminating DataKey(2) for <#O7KF:ocn_surf_flux_diag.pr>.

15:46:02 INFO: log (logs.py line 328):
    Received event at DataSource level: DataQueryEvent("Too many iterations in select_data() for <#NWH4:NCAR_CESM2_hist_r1i1p1f1>.").

15:46:02 DEBUG: log (logs.py line 328):
    Data request for <#O7jY:ocn_surf_flux_diag.ts> failed.

15:46:02 DEBUG: log (logs.py line 328):
    Data request for <#O7pC:ocn_surf_flux_diag.psl> failed.

15:46:02 DEBUG: log (logs.py line 328):
    Data request for <#O7uU:ocn_surf_flux_diag.sfcWind> failed.

15:46:02 DEBUG: log (logs.py line 328):
    Data request for <#O7Aa:ocn_surf_flux_diag.huss> failed.

15:46:02 DEBUG: log (logs.py line 328):
    Data request for <#O7Fu:ocn_surf_flux_diag.hfls> failed.

15:46:02 DEBUG: log (logs.py line 328):
    Data request for <#O7KF:ocn_surf_flux_diag.pr> failed.

15:46:02 DEBUG: log (logs.py line 328):
    Data request for <#O7bk:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag> failed.

15:46:02 DEBUG: log (logs.py line 328):
    Writing file /home/joedhsu/mdtf/wkdir/MDTF_NCAR_CESM2_hist_r1i1p1f1_2000_2009.v10/config_save.json

15:46:02 INFO: log (logs.py line 328):
    <#NWH4:NCAR_CESM2_hist_r1i1p1f1>: Creating '/home/joedhsu/mdtf/wkdir/MDTF_NCAR_CESM2_hist_r1i1p1f1_2000_2009.v10.tar'.
wrongkindofdoctor commented 2 years ago

@chiaweh2 Forking and merging my test branch is probably the easiest way to incorporate the changes. You can rebuild the python3_base environment by running ./src/conda_env_setup.sh --env python3_base --conda_root [path/to/conda installation] --env_dir [path/to/conda installation/envs] The synthetic test data files are in my public sftp directory here: ftp://sftp.gfdl.noaa.gov//pub/jessica.liptak/CMIP_synthetic_day_2000_2009.tar. You'll have to change the CASENAME to CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231, and adjust the MODEL_DATA_ROOT path to the appropriate location.

While you are testing the POD with the synthetic data, I can see what is going on with the NCAR dataset if you send me the rest of the files: pr, psl, ts. This may be a reflection of the framework's overly strict metadata requirements.

chiaweh2 commented 2 years ago

@wrongkindofdoctor Thank you! I will fork and merge you branch then. And thank you for providing the model data! The rest of the variables from my downloads are uploaded to my google drive here.

chiaweh2 commented 2 years ago

Hi @wrongkindofdoctor, I tried one quick test. I checkout your branch debug_ofm and test with synthetic data you provided. I found the error message is similar to my previous log. I paste it below. I am sure it is because there is something wrong in my setting but cannot figure out what is the problem. Could you help me on this? thank you!

MDTF PACKAGE LOG

Started logging at 2021-11-02 21:29:43.882906
git hash/branch: 9468862aeacb15f2187c51e24ed49b3c63ff45a9 (on ofm_debug_branch)
sys.platform: 'linux'
sys.version: '3.7.10 | packaged by conda-forge | (default, Oct 13 2021, 20:51:14) 
[GCC 9.4.0]'
--------------------------------------------------------------------------------

21:29:43 DEBUG: log (logs.py line 328):
    Setting CASE_ROOT_DIR to MODEL_DATA_ROOT = '/home/joedhsu/mdtf/inputdata/model'.

21:29:43 DEBUG: log (logs.py line 328):
    'sample_dataset' not supplied, using CASENAME = 'CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231'.

21:29:43 DEBUG: log (logs.py line 328):
    Set program for <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag> to 'python'.

21:29:43 DEBUG: log (logs.py line 328):
    PrecipRateToFluxFunction edit_request on <#lpu3:ocn_surf_flux_diag.pr>: caught KeyError("Standard name 'precipitation_rate' not defined in convention 'CMIP'.") when trying to translate 'precipitation_rate'; varlist unaltered.

21:29:43 INFO: log (logs.py line 328):
    Starting data file search at /home/joedhsu/mdtf/inputdata/model:

21:29:43 INFO: log (logs.py line 328):
    Directory crawl found 14 files.

21:29:43 DEBUG: log (logs.py line 328):
    Query batch: [<#lp4a:ocn_surf_flux_diag.ts>, <#lp9J:ocn_surf_flux_diag.psl>, <#lpeP:ocn_surf_flux_diag.sfcWind>, <#lpjU:ocn_surf_flux_diag.huss>, <#lpp2:ocn_surf_flux_diag.hfls>, <#lpu3:ocn_surf_flux_diag.pr>].

21:29:43 INFO: log (logs.py line 328):
    Querying <ts> (surface_temperature).

21:29:43 DEBUG: log (logs.py line 328):
    Query found <expt_key=('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', ''), DataKey(11)> for <#lp4a:ocn_surf_flux_diag.ts>

21:29:43 INFO: log (logs.py line 328):
    Querying <psl> (air_pressure_at_mean_sea_level).

21:29:44 DEBUG: log (logs.py line 328):
    Query found <expt_key=('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', ''), DataKey(6)> for <#lp9J:ocn_surf_flux_diag.psl>

21:29:44 INFO: log (logs.py line 328):
    Querying <sfcWind> (wind_speed).

21:29:44 DEBUG: log (logs.py line 328):
    Query found <expt_key=('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', ''), DataKey(7)> for <#lpeP:ocn_surf_flux_diag.sfcWind>

21:29:44 INFO: log (logs.py line 328):
    Querying <huss> (specific_humidity).

21:29:44 DEBUG: log (logs.py line 328):
    Query found <expt_key=('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', ''), DataKey(9)> for <#lpjU:ocn_surf_flux_diag.huss>

21:29:44 INFO: log (logs.py line 328):
    Querying <hfls> (surface_upward_latent_heat_flux).

21:29:44 DEBUG: log (logs.py line 328):
    Query found <expt_key=('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', ''), DataKey(8)> for <#lpp2:ocn_surf_flux_diag.hfls>

21:29:44 INFO: log (logs.py line 328):
    Querying <pr> (precipitation_flux).

21:29:44 DEBUG: log (logs.py line 328):
    Query found <expt_key=('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', ''), DataKey(10)> for <#lpu3:ocn_surf_flux_diag.pr>

21:29:44 DEBUG: log (logs.py line 328):
    1 expt attr choices for CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231 from <#lp4a:ocn_surf_flux_diag.ts>

21:29:44 DEBUG: log (logs.py line 328):
    1 expt attr choices for CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231 from <#lp9J:ocn_surf_flux_diag.psl>

21:29:44 DEBUG: log (logs.py line 328):
    1 expt attr choices for CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231 from <#lpeP:ocn_surf_flux_diag.sfcWind>

21:29:44 DEBUG: log (logs.py line 328):
    1 expt attr choices for CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231 from <#lpjU:ocn_surf_flux_diag.huss>

21:29:44 DEBUG: log (logs.py line 328):
    1 expt attr choices for CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231 from <#lpp2:ocn_surf_flux_diag.hfls>

21:29:44 DEBUG: log (logs.py line 328):
    1 expt attr choices for CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231 from <#lpu3:ocn_surf_flux_diag.pr>

21:29:44 DEBUG: log (logs.py line 328):
    1 expt attr choices for CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231

21:29:44 DEBUG: log (logs.py line 328):
    Setting experiment_key for 'CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231' to 'CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231'

21:29:44 DEBUG: log (logs.py line 328):
    DataKey(11) selected as part of experiment_key '('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', '')'.

21:29:44 DEBUG: log (logs.py line 328):
    DataKey(6) selected as part of experiment_key '('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', '')'.

21:29:44 DEBUG: log (logs.py line 328):
    DataKey(7) selected as part of experiment_key '('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', '')'.

21:29:44 DEBUG: log (logs.py line 328):
    DataKey(9) selected as part of experiment_key '('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', '')'.

21:29:44 DEBUG: log (logs.py line 328):
    DataKey(8) selected as part of experiment_key '('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', '')'.

21:29:44 DEBUG: log (logs.py line 328):
    DataKey(10) selected as part of experiment_key '('CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231', '', '')'.

21:29:44 DEBUG: log (logs.py line 328):
    Fetch batch: [<#lp4a:ocn_surf_flux_diag.ts>, <#lp9J:ocn_surf_flux_diag.psl>, <#lpeP:ocn_surf_flux_diag.sfcWind>, <#lpjU:ocn_surf_flux_diag.huss>, <#lpp2:ocn_surf_flux_diag.hfls>, <#lpu3:ocn_surf_flux_diag.pr>].

21:29:44 INFO: log (logs.py line 328):
    Fetching <#lp4a:ocn_surf_flux_diag.ts> (='ts' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Fetching DataKey(11).

21:29:44 DEBUG: log (logs.py line 328):
    Fetch DataKey(11): found /home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ts.day.nc.

21:29:44 INFO: log (logs.py line 328):
    Fetching <#lp9J:ocn_surf_flux_diag.psl> (='psl' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Fetching DataKey(6).

21:29:44 DEBUG: log (logs.py line 328):
    Fetch DataKey(6): found /home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.psl.day.nc.

21:29:44 INFO: log (logs.py line 328):
    Fetching <#lpeP:ocn_surf_flux_diag.sfcWind> (='sfcWind' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Fetching DataKey(7).

21:29:44 DEBUG: log (logs.py line 328):
    Fetch DataKey(7): found /home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.sfcWind.day.nc.

21:29:44 INFO: log (logs.py line 328):
    Fetching <#lpjU:ocn_surf_flux_diag.huss> (='huss' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Fetching DataKey(9).

21:29:44 DEBUG: log (logs.py line 328):
    Fetch DataKey(9): found /home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.huss.day.nc.

21:29:44 INFO: log (logs.py line 328):
    Fetching <#lpp2:ocn_surf_flux_diag.hfls> (='hfls' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Fetching DataKey(8).

21:29:44 DEBUG: log (logs.py line 328):
    Fetch DataKey(8): found /home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.hfls.day.nc.

21:29:44 INFO: log (logs.py line 328):
    Fetching <#lpu3:ocn_surf_flux_diag.pr> (='pr' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Fetching DataKey(10).

21:29:44 DEBUG: log (logs.py line 328):
    Fetch DataKey(10): found /home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.pr.day.nc.

21:29:44 INFO: log (logs.py line 328):
    Preprocessing <#lp4a:ocn_surf_flux_diag.ts> (='ts' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ts.day.nc'.

21:29:44 DEBUG: log (logs.py line 328):
    Read 2 mb for <#lp4a:ocn_surf_flux_diag.ts>.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 2000-01-01' from dataset.

21:29:44 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'time_bnds' found in dataset; setting to 'days since 2000-01-01'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lat_bnds' found in dataset; setting to 'degrees_north'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lon_bnds' found in dataset; setting to 'degrees_east'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#lp4a:ocn_surf_flux_diag.ts>.

21:29:44 INFO: log (logs.py line 328):
    Received event while preprocessing <#lp4a:ocn_surf_flux_diag.ts>: DataPreprocessEvent("Caught exception while Preprocessing on <#lp4a:ocn_surf_flux_diag.ts> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

21:29:44 DEBUG: log (logs.py line 328):
    Eliminating DataKey(11) for <#lp4a:ocn_surf_flux_diag.ts>.

21:29:44 INFO: log (logs.py line 328):
    Deactivated <#lp4a:ocn_surf_flux_diag.ts> due to ChildFailureEvent("Deactivating <#lp4a:ocn_surf_flux_diag.ts> due to failure of all child objects.").

21:29:44 INFO: log (logs.py line 328):
    Request for <#lp4a:ocn_surf_flux_diag.ts> (='ts' @ 1day) failed; looking for alternate data.

21:29:44 ERROR: log (logs.py line 328):
    Deactivated <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag> due to PodDataError("Requested data not available for POD <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>: No alternate data available for <#lp4a:ocn_surf_flux_diag.ts>.").

21:29:44 ERROR: log (logs.py line 328):
    Deactivated <#lfeA:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231> due to ChildFailureEvent("Deactivating <#lfeA:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231> due to failure of all child objects.").

21:29:44 INFO: log (logs.py line 328):
    Deactivated <#lp9J:ocn_surf_flux_diag.psl> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>: No alternate data available for <#lp4a:ocn_surf_flux_diag.ts>.") from deactivation of parent <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>.").

21:29:44 INFO: log (logs.py line 328):
    Deactivated <#lpeP:ocn_surf_flux_diag.sfcWind> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>: No alternate data available for <#lp4a:ocn_surf_flux_diag.ts>.") from deactivation of parent <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>.").

21:29:44 INFO: log (logs.py line 328):
    Deactivated <#lpjU:ocn_surf_flux_diag.huss> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>: No alternate data available for <#lp4a:ocn_surf_flux_diag.ts>.") from deactivation of parent <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>.").

21:29:44 INFO: log (logs.py line 328):
    Deactivated <#lpp2:ocn_surf_flux_diag.hfls> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>: No alternate data available for <#lp4a:ocn_surf_flux_diag.ts>.") from deactivation of parent <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>.").

21:29:44 INFO: log (logs.py line 328):
    Deactivated <#lpu3:ocn_surf_flux_diag.pr> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>: No alternate data available for <#lp4a:ocn_surf_flux_diag.ts>.") from deactivation of parent <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag>.").

21:29:44 INFO: log (logs.py line 328):
    Preprocessing <#lp9J:ocn_surf_flux_diag.psl> (='psl' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.psl.day.nc'.

21:29:44 DEBUG: log (logs.py line 328):
    Read 2 mb for <#lp9J:ocn_surf_flux_diag.psl>.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 2000-01-01' from dataset.

21:29:44 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'time_bnds' found in dataset; setting to 'days since 2000-01-01'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lat_bnds' found in dataset; setting to 'degrees_north'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lon_bnds' found in dataset; setting to 'degrees_east'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#lp9J:ocn_surf_flux_diag.psl>.

21:29:44 INFO: log (logs.py line 328):
    Received event while preprocessing <#lp9J:ocn_surf_flux_diag.psl>: DataPreprocessEvent("Caught exception while Preprocessing on <#lp9J:ocn_surf_flux_diag.psl> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

21:29:44 DEBUG: log (logs.py line 328):
    Eliminating DataKey(6) for <#lp9J:ocn_surf_flux_diag.psl>.

21:29:44 INFO: log (logs.py line 328):
    Preprocessing <#lpeP:ocn_surf_flux_diag.sfcWind> (='sfcWind' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.sfcWind.day.nc'.

21:29:44 DEBUG: log (logs.py line 328):
    Read 2 mb for <#lpeP:ocn_surf_flux_diag.sfcWind>.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 2000-01-01' from dataset.

21:29:44 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'time_bnds' found in dataset; setting to 'days since 2000-01-01'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lat_bnds' found in dataset; setting to 'degrees_north'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lon_bnds' found in dataset; setting to 'degrees_east'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#lpeP:ocn_surf_flux_diag.sfcWind>.

21:29:44 INFO: log (logs.py line 328):
    Received event while preprocessing <#lpeP:ocn_surf_flux_diag.sfcWind>: DataPreprocessEvent("Caught exception while Preprocessing on <#lpeP:ocn_surf_flux_diag.sfcWind> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

21:29:44 DEBUG: log (logs.py line 328):
    Eliminating DataKey(7) for <#lpeP:ocn_surf_flux_diag.sfcWind>.

21:29:44 INFO: log (logs.py line 328):
    Preprocessing <#lpjU:ocn_surf_flux_diag.huss> (='huss' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.huss.day.nc'.

21:29:44 DEBUG: log (logs.py line 328):
    Read 2 mb for <#lpjU:ocn_surf_flux_diag.huss>.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 2000-01-01' from dataset.

21:29:44 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'time_bnds' found in dataset; setting to 'days since 2000-01-01'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lat_bnds' found in dataset; setting to 'degrees_north'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lon_bnds' found in dataset; setting to 'degrees_east'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#lpjU:ocn_surf_flux_diag.huss>.

21:29:44 INFO: log (logs.py line 328):
    Received event while preprocessing <#lpjU:ocn_surf_flux_diag.huss>: DataPreprocessEvent("Caught exception while Preprocessing on <#lpjU:ocn_surf_flux_diag.huss> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

21:29:44 DEBUG: log (logs.py line 328):
    Eliminating DataKey(9) for <#lpjU:ocn_surf_flux_diag.huss>.

21:29:44 INFO: log (logs.py line 328):
    Preprocessing <#lpp2:ocn_surf_flux_diag.hfls> (='hfls' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.hfls.day.nc'.

21:29:44 DEBUG: log (logs.py line 328):
    Read 2 mb for <#lpp2:ocn_surf_flux_diag.hfls>.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 2000-01-01' from dataset.

21:29:44 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'time_bnds' found in dataset; setting to 'days since 2000-01-01'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lat_bnds' found in dataset; setting to 'degrees_north'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lon_bnds' found in dataset; setting to 'degrees_east'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#lpp2:ocn_surf_flux_diag.hfls>.

21:29:44 INFO: log (logs.py line 328):
    Received event while preprocessing <#lpp2:ocn_surf_flux_diag.hfls>: DataPreprocessEvent("Caught exception while Preprocessing on <#lpp2:ocn_surf_flux_diag.hfls> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

21:29:44 DEBUG: log (logs.py line 328):
    Eliminating DataKey(8) for <#lpp2:ocn_surf_flux_diag.hfls>.

21:29:44 INFO: log (logs.py line 328):
    Preprocessing <#lpu3:ocn_surf_flux_diag.pr> (='pr' @ 1day).

21:29:44 DEBUG: log (logs.py line 328):
    Loaded '/home/joedhsu/mdtf/inputdata/model/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231/day/CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.pr.day.nc'.

21:29:44 DEBUG: log (logs.py line 328):
    Read 2 mb for <#lpu3:ocn_surf_flux_diag.pr>.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating units for 'time' to value 'days since 2000-01-01' from dataset.

21:29:44 DEBUG: log (logs.py line 328):
    Updating calendar for 'time' to value 'noleap' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'time_bnds' found in dataset; setting to 'days since 2000-01-01'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lat_bnds' found in dataset; setting to 'degrees_north'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

21:29:44 INFO: log (logs.py line 328):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

21:29:44 INFO: log (logs.py line 328):
    No units for 'lon_bnds' found in dataset; setting to 'degrees_east'.

21:29:44 DEBUG: log (logs.py line 328):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

21:29:44 WARNING: log (logs.py line 328):
    cftime calendar info parse failed on 'time'.

21:29:44 DEBUG: log (logs.py line 328):
    Calling CropDateRangeFunction on <#lpu3:ocn_surf_flux_diag.pr>.

21:29:44 INFO: log (logs.py line 328):
    Received event while preprocessing <#lpu3:ocn_surf_flux_diag.pr>: DataPreprocessEvent("Caught exception while Preprocessing on <#lpu3:ocn_surf_flux_diag.pr> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

21:29:44 DEBUG: log (logs.py line 328):
    Eliminating DataKey(10) for <#lpu3:ocn_surf_flux_diag.pr>.

21:29:44 INFO: log (logs.py line 328):
    Received event at DataSource level: DataQueryEvent("Too many iterations in select_data() for <#lfeA:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231>.").

21:29:44 DEBUG: log (logs.py line 328):
    Data request for <#lp4a:ocn_surf_flux_diag.ts> failed.

21:29:44 DEBUG: log (logs.py line 328):
    Data request for <#lp9J:ocn_surf_flux_diag.psl> failed.

21:29:44 DEBUG: log (logs.py line 328):
    Data request for <#lpeP:ocn_surf_flux_diag.sfcWind> failed.

21:29:44 DEBUG: log (logs.py line 328):
    Data request for <#lpjU:ocn_surf_flux_diag.huss> failed.

21:29:44 DEBUG: log (logs.py line 328):
    Data request for <#lpp2:ocn_surf_flux_diag.hfls> failed.

21:29:44 DEBUG: log (logs.py line 328):
    Data request for <#lpu3:ocn_surf_flux_diag.pr> failed.

21:29:44 DEBUG: log (logs.py line 328):
    Data request for <#loVu:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231.ocn_surf_flux_diag> failed.

21:29:44 DEBUG: log (logs.py line 328):
    Writing file /home/joedhsu/mdtf/wkdir/MDTF_CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231_2000_2009.v2/config_save.json

21:29:44 INFO: log (logs.py line 328):
    <#lfeA:CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231>: Creating '/home/joedhsu/mdtf/wkdir/MDTF_CMIP_Synthetic_r1i1p1f1_gr1_20000101-20091231_2000_2009.v2.tar'.
chiaweh2 commented 2 years ago

Hi @wrongkindofdoctor, sorry for the consecutive post. I did another test which I simply download the sample data and obs_data and checkout the main branch it also show similar error code. It seems to always related to this error code 

ERROR: log (logs.py line 320):
    Deactivated <#z88C:GFDL.CM4.c96L32.am4g10r8.MJO_prop_amp> due to PodDataError("Requested data not available for POD <#z88C:GFDL.CM4.c96L32.am4g10r8.MJO_prop_amp>: No alternate data available for <#z8iN:MJO_prop_amp.pr>.")

I think this is some error due to my part for sure. However, I followed the installation through again and cannot find possible problem. Do you think this could related to the framework not install correctly? or the path is not set right? The log file for the sample data test is below. Thank you. 

MDTF PACKAGE LOG

Started logging at 2021-11-03 06:12:37.431126
git hash/branch: 3b85835d98da0a1e0d75ecdcf9600654bf2ead32 (on main_nochange)
sys.platform: 'linux'
sys.version: '3.7.10 | packaged by conda-forge | (default, Oct 13 2021, 20:51:14) 
[GCC 9.4.0]'
--------------------------------------------------------------------------------

06:12:37 DEBUG: log (logs.py line 320):
    Setting CASE_ROOT_DIR to MODEL_DATA_ROOT = '/home/joedhsu/mdtf/inputdata/model'.

06:12:37 DEBUG: log (logs.py line 320):
    'sample_dataset' not supplied, using CASENAME = 'GFDL.CM4.c96L32.am4g10r8'.

06:12:37 DEBUG: log (logs.py line 320):
    Set program for <#z88C:GFDL.CM4.c96L32.am4g10r8.MJO_prop_amp> to 'python'.

06:12:37 DEBUG: log (logs.py line 320):
    PrecipRateToFluxFunction edit_request on <#z8iN:MJO_prop_amp.pr>: caught KeyError("Standard name 'precipitation_rate' not defined in convention 'GFDL'.") when trying to translate 'precipitation_rate'; varlist unaltered.

06:12:37 INFO: log (logs.py line 320):
    Starting data file search at /home/joedhsu/mdtf/inputdata/model:

06:12:37 INFO: log (logs.py line 320):
    Directory crawl found 17 files.

06:12:37 DEBUG: log (logs.py line 320):
    Query batch: [<#z8iN:MJO_prop_amp.pr>, <#z8oi:MJO_prop_amp.prw>, <#z8tm:MJO_prop_amp.hus>].

06:12:37 INFO: log (logs.py line 320):
    Querying <precip> (precipitation_flux).

06:12:37 DEBUG: log (logs.py line 320):
    Query found <expt_key=('GFDL.CM4.c96L32.am4g10r8', '', ''), DataKey(6)> for <#z8iN:MJO_prop_amp.pr>

06:12:37 INFO: log (logs.py line 320):
    Querying <WVP> (atmosphere_mass_content_of_water_vapor).

06:12:37 DEBUG: log (logs.py line 320):
    Query found <expt_key=('GFDL.CM4.c96L32.am4g10r8', '', ''), DataKey(7)> for <#z8oi:MJO_prop_amp.prw>

06:12:37 INFO: log (logs.py line 320):
    Querying <sphum> (specific_humidity).

06:12:37 DEBUG: log (logs.py line 320):
    Query found <expt_key=('GFDL.CM4.c96L32.am4g10r8', '', ''), DataKey(8)> for <#z8tm:MJO_prop_amp.hus>

06:12:37 DEBUG: log (logs.py line 320):
    1 expt attr choices for GFDL.CM4.c96L32.am4g10r8 from <#z8iN:MJO_prop_amp.pr>

06:12:37 DEBUG: log (logs.py line 320):
    1 expt attr choices for GFDL.CM4.c96L32.am4g10r8 from <#z8oi:MJO_prop_amp.prw>

06:12:37 DEBUG: log (logs.py line 320):
    1 expt attr choices for GFDL.CM4.c96L32.am4g10r8 from <#z8tm:MJO_prop_amp.hus>

06:12:37 DEBUG: log (logs.py line 320):
    1 expt attr choices for GFDL.CM4.c96L32.am4g10r8

06:12:37 DEBUG: log (logs.py line 320):
    Setting experiment_key for 'GFDL.CM4.c96L32.am4g10r8' to 'GFDL.CM4.c96L32.am4g10r8'

06:12:37 DEBUG: log (logs.py line 320):
    DataKey(6) selected as part of experiment_key '('GFDL.CM4.c96L32.am4g10r8', '', '')'.

06:12:37 DEBUG: log (logs.py line 320):
    DataKey(7) selected as part of experiment_key '('GFDL.CM4.c96L32.am4g10r8', '', '')'.

06:12:37 DEBUG: log (logs.py line 320):
    DataKey(8) selected as part of experiment_key '('GFDL.CM4.c96L32.am4g10r8', '', '')'.

06:12:37 DEBUG: log (logs.py line 320):
    Fetch batch: [<#z8iN:MJO_prop_amp.pr>, <#z8oi:MJO_prop_amp.prw>, <#z8tm:MJO_prop_amp.hus>].

06:12:37 INFO: log (logs.py line 320):
    Fetching <#z8iN:MJO_prop_amp.pr> (='precip' @ 1day).

06:12:37 DEBUG: log (logs.py line 320):
    Fetching DataKey(6).

06:12:37 DEBUG: log (logs.py line 320):
    Fetch DataKey(6): found /home/joedhsu/mdtf/inputdata/model/GFDL.CM4.c96L32.am4g10r8/day/GFDL.CM4.c96L32.am4g10r8.precip.day.nc.

06:12:37 INFO: log (logs.py line 320):
    Fetching <#z8oi:MJO_prop_amp.prw> (='WVP' @ 1day).

06:12:37 DEBUG: log (logs.py line 320):
    Fetching DataKey(7).

06:12:37 DEBUG: log (logs.py line 320):
    Fetch DataKey(7): found /home/joedhsu/mdtf/inputdata/model/GFDL.CM4.c96L32.am4g10r8/day/GFDL.CM4.c96L32.am4g10r8.WVP.day.nc.

06:12:37 INFO: log (logs.py line 320):
    Fetching <#z8tm:MJO_prop_amp.hus> (='sphum' @ 1day).

06:12:37 DEBUG: log (logs.py line 320):
    Fetching DataKey(8).

06:12:37 DEBUG: log (logs.py line 320):
    Fetch DataKey(8): found /home/joedhsu/mdtf/inputdata/model/GFDL.CM4.c96L32.am4g10r8/day/GFDL.CM4.c96L32.am4g10r8.sphum.day.nc.

06:12:37 INFO: log (logs.py line 320):
    Preprocessing <#z8iN:MJO_prop_amp.pr> (='precip' @ 1day).

06:12:37 DEBUG: log (logs.py line 320):
    Loaded '/home/joedhsu/mdtf/inputdata/model/GFDL.CM4.c96L32.am4g10r8/day/GFDL.CM4.c96L32.am4g10r8.precip.day.nc'.

06:12:37 DEBUG: log (logs.py line 320):
    Read 144 mb for <#z8iN:MJO_prop_amp.pr>.

06:12:37 DEBUG: log (logs.py line 320):
    Correcting 'NOLEAP' to 'noleap' as the intended value for 'calendar'.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'precip' found in dataset; setting to 'precipitation_flux'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating units for 'time' to value 'days since 0001-01-01 00:00:00' from dataset.

06:12:37 DEBUG: log (logs.py line 320):
    Updating calendar for 'time' to value 'noleap' from dataset.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

06:12:37 INFO: log (logs.py line 320):
    Changing attribute 'units' for dataset variable 'time_bnds' from 'days' to our value 'days since 0001-01-01 00:00:00'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

06:12:37 DEBUG: log (logs.py line 320):
    Calling CropDateRangeFunction on <#z8iN:MJO_prop_amp.pr>.

06:12:37 INFO: log (logs.py line 320):
    Received event while preprocessing <#z8iN:MJO_prop_amp.pr>: DataPreprocessEvent("Caught exception while Preprocessing on <#z8iN:MJO_prop_amp.pr> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

06:12:37 DEBUG: log (logs.py line 320):
    Eliminating DataKey(6) for <#z8iN:MJO_prop_amp.pr>.

06:12:37 INFO: log (logs.py line 320):
    Deactivated <#z8iN:MJO_prop_amp.pr> due to ChildFailureEvent("Deactivating <#z8iN:MJO_prop_amp.pr> due to failure of all child objects.").

06:12:37 INFO: log (logs.py line 320):
    Request for <#z8iN:MJO_prop_amp.pr> (='precip' @ 1day) failed; looking for alternate data.

06:12:37 ERROR: log (logs.py line 320):
    Deactivated <#z88C:GFDL.CM4.c96L32.am4g10r8.MJO_prop_amp> due to PodDataError("Requested data not available for POD <#z88C:GFDL.CM4.c96L32.am4g10r8.MJO_prop_amp>: No alternate data available for <#z8iN:MJO_prop_amp.pr>.").

06:12:37 ERROR: log (logs.py line 320):
    Deactivated <#yZSj:GFDL.CM4.c96L32.am4g10r8> due to ChildFailureEvent("Deactivating <#yZSj:GFDL.CM4.c96L32.am4g10r8> due to failure of all child objects.").

06:12:37 INFO: log (logs.py line 320):
    Deactivated <#z8oi:MJO_prop_amp.prw> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#z88C:GFDL.CM4.c96L32.am4g10r8.MJO_prop_amp>: No alternate data available for <#z8iN:MJO_prop_amp.pr>.") from deactivation of parent <#z88C:GFDL.CM4.c96L32.am4g10r8.MJO_prop_amp>.").

06:12:37 INFO: log (logs.py line 320):
    Deactivated <#z8tm:MJO_prop_amp.hus> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#z88C:GFDL.CM4.c96L32.am4g10r8.MJO_prop_amp>: No alternate data available for <#z8iN:MJO_prop_amp.pr>.") from deactivation of parent <#z88C:GFDL.CM4.c96L32.am4g10r8.MJO_prop_amp>.").

06:12:37 INFO: log (logs.py line 320):
    Preprocessing <#z8oi:MJO_prop_amp.prw> (='WVP' @ 1day).

06:12:37 DEBUG: log (logs.py line 320):
    Loaded '/home/joedhsu/mdtf/inputdata/model/GFDL.CM4.c96L32.am4g10r8/day/GFDL.CM4.c96L32.am4g10r8.WVP.day.nc'.

06:12:37 DEBUG: log (logs.py line 320):
    Read 144 mb for <#z8oi:MJO_prop_amp.prw>.

06:12:37 DEBUG: log (logs.py line 320):
    Correcting 'NOLEAP' to 'noleap' as the intended value for 'calendar'.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'WVP' found in dataset; setting to 'atmosphere_mass_content_of_water_vapor'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating units for 'time' to value 'days since 0001-01-01 00:00:00' from dataset.

06:12:37 DEBUG: log (logs.py line 320):
    Updating calendar for 'time' to value 'noleap' from dataset.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

06:12:37 INFO: log (logs.py line 320):
    Changing attribute 'units' for dataset variable 'time_bnds' from 'days' to our value 'days since 0001-01-01 00:00:00'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

06:12:37 DEBUG: log (logs.py line 320):
    Calling CropDateRangeFunction on <#z8oi:MJO_prop_amp.prw>.

06:12:37 INFO: log (logs.py line 320):
    Received event while preprocessing <#z8oi:MJO_prop_amp.prw>: DataPreprocessEvent("Caught exception while Preprocessing on <#z8oi:MJO_prop_amp.prw> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

06:12:37 DEBUG: log (logs.py line 320):
    Eliminating DataKey(7) for <#z8oi:MJO_prop_amp.prw>.

06:12:37 INFO: log (logs.py line 320):
    Preprocessing <#z8tm:MJO_prop_amp.hus> (='sphum' @ 1day).

06:12:37 DEBUG: log (logs.py line 320):
    Loaded '/home/joedhsu/mdtf/inputdata/model/GFDL.CM4.c96L32.am4g10r8/day/GFDL.CM4.c96L32.am4g10r8.sphum.day.nc'.

06:12:37 DEBUG: log (logs.py line 320):
    Read 4619 mb for <#z8tm:MJO_prop_amp.hus>.

06:12:37 DEBUG: log (logs.py line 320):
    Correcting 'NOLEAP' to 'noleap' as the intended value for 'calendar'.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'sphum' found in dataset; setting to 'specific_humidity'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating units for 'time' to value 'days since 0001-01-01 00:00:00' from dataset.

06:12:37 DEBUG: log (logs.py line 320):
    Updating calendar for 'time' to value 'noleap' from dataset.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'time_bnds' found in dataset; setting to 'time'.

06:12:37 INFO: log (logs.py line 320):
    Changing attribute 'units' for dataset variable 'time_bnds' from 'days' to our value 'days since 0001-01-01 00:00:00'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating bounds for 'time' to value 'time_bnds' from dataset.

06:12:37 DEBUG: log (logs.py line 320):
    Updating name for 'plev' to value 'pfull' from dataset.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'pfull' found in dataset; setting to 'air_pressure'.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'lat_bnds' found in dataset; setting to 'latitude'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating bounds for 'lat' to value 'lat_bnds' from dataset.

06:12:37 INFO: log (logs.py line 320):
    No standard_name for 'lon_bnds' found in dataset; setting to 'longitude'.

06:12:37 DEBUG: log (logs.py line 320):
    Updating bounds for 'lon' to value 'lon_bnds' from dataset.

06:12:37 DEBUG: log (logs.py line 320):
    Calling CropDateRangeFunction on <#z8tm:MJO_prop_amp.hus>.

06:12:37 INFO: log (logs.py line 320):
    Received event while preprocessing <#z8tm:MJO_prop_amp.hus>: DataPreprocessEvent("Caught exception while Preprocessing on <#z8tm:MJO_prop_amp.hus> failed at CropDateRangeFunction: TypeError("_maybe_cast_slice_bound() missing 1 required positional argument: 'kind'").")

06:12:37 DEBUG: log (logs.py line 320):
    Eliminating DataKey(8) for <#z8tm:MJO_prop_amp.hus>.

06:12:37 INFO: log (logs.py line 320):
    Received event at DataSource level: DataQueryEvent("Too many iterations in select_data() for <#yZSj:GFDL.CM4.c96L32.am4g10r8>.").

06:12:37 DEBUG: log (logs.py line 320):
    Data request for <#z8iN:MJO_prop_amp.pr> failed.

06:12:37 DEBUG: log (logs.py line 320):
    Data request for <#z8oi:MJO_prop_amp.prw> failed.

06:12:37 DEBUG: log (logs.py line 320):
    Data request for <#z8tm:MJO_prop_amp.hus> failed.

06:12:37 DEBUG: log (logs.py line 320):
    Data request for <#z88C:GFDL.CM4.c96L32.am4g10r8.MJO_prop_amp> failed.

06:12:37 DEBUG: log (logs.py line 320):
    Writing file /home/joedhsu/mdtf/wkdir/MDTF_GFDL.CM4.c96L32.v2.am4g10r8_1_10/config_save.json

06:12:38 INFO: log (logs.py line 320):
    <#yZSj:GFDL.CM4.c96L32.am4g10r8>: Creating '/home/joedhsu/mdtf/wkdir/MDTF_GFDL.CM4.c96L32.v2.am4g10r8_1_10.tar'.
wrongkindofdoctor commented 2 years ago

@chiaweh2 I just tested mjo_prop_amp with the main branch and also encountered an error, though it does not seem to match your log. Based on my log, it looks like the input data files for the model were read in, but there is problem with the processed time values for sphum. For some reason, the times after year 9 are interpreted as year 1, not 10, so the last year in the array causes the error that the end time is 0001-01-01 instead of 0010-01-01. I'll add this to my pile of problems to figure out.

ETA: the sphum issue was apparently from a corrupt file. I replaced the file, and the mjo_prop_amp POD is running.

Unfortunately, I don't know what the issue is with the main branch on your end if you rebuilt the python3 and base environments. Maybe the standard is still set to 'CMIP' instead of 'GFDL'?

As an aside, I was able to hack together a solution that will allow the framework to check for the calendar attribute in other file metadata and ingest the test NCAR Dataset you provided. I still get the same numpy array type error in ocn_surf_flux_diag.py after reading the data, though:

Traceback (most recent call last):
  File "/home/$USER/mdtf/MDTF-diagnostics/diagnostics/ocn_surf_flux_diag/ocn_surf_flux_diag.py", line 45, in <module>
    ds_cesm2 = regional_var(varlist, lon_lim, lat_lim, year_lim)
  File "/home/$USER/mdtf/MDTF-diagnostics/diagnostics/ocn_surf_flux_diag/model_read.py", line 28, in regional_var
    (ds_atm['time.year']>=np.array(year_lim).min())&
  File "/home/$USER/miniconda3/envs/_MDTF_ocn_surf_flux_diag/lib/python3.7/site-packages/numpy/core/_methods.py", line 43, in _amin
    return umr_minimum(a, axis, None, out, keepdims, initial, where)
TypeError: cannot perform reduce with flexible type
chiaweh2 commented 2 years ago

@wrongkindofdoctor thank you so much for the testing. I will try a clean install on another directory. I will definitely get to the numpy error you shared once I get the framework to work properly. Thank you.

chiaweh2 commented 2 years ago

@wrongkindofdoctor Yes! Rebuild all conda environment does the trick. I can reproduce your error message with synthetic data now. Will update once I fix the error. Thank you again for the help.

chiaweh2 commented 2 years ago

@wrongkindofdoctor I fixed the numpy error! The POD can now exist normally with the figure and netCDF outputs when using the synthetic dataset you provided. My updated branch in my fork is here. However, my original CESM2 files is still not accepted by the framework. I include the log file of the failed attempt below. Have you included your hack into the develop branch yet? 

MDTF PACKAGE LOG

Started logging at 2021-11-04 08:47:58.590032
git hash/branch: c2bca98fbc25c43d1bdd50c7463cc3e96ca94076 (on feature/ocean_flux_matrix)
sys.platform: 'linux'
sys.version: '3.7.12 | packaged by conda-forge | (default, Oct 26 2021, 06:08:53) 
[GCC 9.4.0]'
--------------------------------------------------------------------------------

08:47:58 DEBUG: log (logs.py line 328):
    Setting CASE_ROOT_DIR to MODEL_DATA_ROOT = '/home/joedhsu/mdtf/inputdata/model'.

08:47:58 DEBUG: log (logs.py line 328):
    'sample_dataset' not supplied, using CASENAME = 'NCAR_CESM2_hist_r1i1p1f1'.

08:47:58 DEBUG: log (logs.py line 328):
    Set program for <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag> to 'python'.

08:47:58 DEBUG: log (logs.py line 328):
    PrecipRateToFluxFunction edit_request on <#Pmv0:ocn_surf_flux_diag.pr>: caught KeyError("Standard name 'precipitation_rate' not defined in convention 'CMIP'.") when trying to translate 'precipitation_rate'; varlist unaltered.

08:47:58 INFO: log (logs.py line 328):
    Starting data file search at /home/joedhsu/mdtf/inputdata/model:

08:47:59 INFO: log (logs.py line 328):
    Directory crawl found 17 files.

08:47:59 DEBUG: log (logs.py line 328):
    Query batch: [<#OV28:ocn_surf_flux_diag.ts>, <#P0MM:ocn_surf_flux_diag.psl>, <#P67M:ocn_surf_flux_diag.sfcWind>, <#PbQE:ocn_surf_flux_diag.huss>, <#PhgY:ocn_surf_flux_diag.hfls>, <#Pmv0:ocn_surf_flux_diag.pr>].

08:47:59 INFO: log (logs.py line 328):
    Querying <ts> (surface_temperature).

08:47:59 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(16)> for <#OV28:ocn_surf_flux_diag.ts>

08:47:59 INFO: log (logs.py line 328):
    Querying <psl> (air_pressure_at_mean_sea_level).

08:47:59 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(12)> for <#P0MM:ocn_surf_flux_diag.psl>

08:47:59 INFO: log (logs.py line 328):
    Querying <sfcWind> (wind_speed).

08:47:59 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(15)> for <#P67M:ocn_surf_flux_diag.sfcWind>

08:47:59 INFO: log (logs.py line 328):
    Querying <huss> (specific_humidity).

08:47:59 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(13)> for <#PbQE:ocn_surf_flux_diag.huss>

08:47:59 INFO: log (logs.py line 328):
    Querying <hfls> (surface_upward_latent_heat_flux).

08:47:59 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(14)> for <#PhgY:ocn_surf_flux_diag.hfls>

08:47:59 INFO: log (logs.py line 328):
    Querying <pr> (precipitation_flux).

08:47:59 DEBUG: log (logs.py line 328):
    Query found <expt_key=('NCAR_CESM2_hist_r1i1p1f1', '', ''), DataKey(11)> for <#Pmv0:ocn_surf_flux_diag.pr>

08:47:59 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#OV28:ocn_surf_flux_diag.ts>

08:47:59 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#P0MM:ocn_surf_flux_diag.psl>

08:47:59 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#P67M:ocn_surf_flux_diag.sfcWind>

08:47:59 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#PbQE:ocn_surf_flux_diag.huss>

08:47:59 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#PhgY:ocn_surf_flux_diag.hfls>

08:48:00 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1 from <#Pmv0:ocn_surf_flux_diag.pr>

08:48:00 DEBUG: log (logs.py line 328):
    1 expt attr choices for NCAR_CESM2_hist_r1i1p1f1

08:48:00 DEBUG: log (logs.py line 328):
    Setting experiment_key for 'NCAR_CESM2_hist_r1i1p1f1' to 'NCAR_CESM2_hist_r1i1p1f1'

08:48:00 DEBUG: log (logs.py line 328):
    DataKey(16) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

08:48:00 DEBUG: log (logs.py line 328):
    DataKey(12) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

08:48:00 DEBUG: log (logs.py line 328):
    DataKey(15) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

08:48:00 DEBUG: log (logs.py line 328):
    DataKey(13) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

08:48:00 DEBUG: log (logs.py line 328):
    DataKey(14) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

08:48:00 DEBUG: log (logs.py line 328):
    DataKey(11) selected as part of experiment_key '('NCAR_CESM2_hist_r1i1p1f1', '', '')'.

08:48:00 DEBUG: log (logs.py line 328):
    Fetch batch: [<#OV28:ocn_surf_flux_diag.ts>, <#P0MM:ocn_surf_flux_diag.psl>, <#P67M:ocn_surf_flux_diag.sfcWind>, <#PbQE:ocn_surf_flux_diag.huss>, <#PhgY:ocn_surf_flux_diag.hfls>, <#Pmv0:ocn_surf_flux_diag.pr>].

08:48:00 INFO: log (logs.py line 328):
    Fetching <#OV28:ocn_surf_flux_diag.ts> (='ts' @ 1day).

08:48:00 DEBUG: log (logs.py line 328):
    Fetching DataKey(16).

08:48:00 INFO: log (logs.py line 328):
    Deactivated <#G7Im:NCAR_CESM2_hist_r1i1p1f1.DataFrameDataKey_(16,)> due to DataFetchEvent("Fetch DataKey(16) (<#OV28:ocn_surf_flux_diag.ts>): File not found at /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.ts.day.nc.").

08:48:00 DEBUG: log (logs.py line 328):
    Eliminating DataKey(16) for <#OV28:ocn_surf_flux_diag.ts>.

08:48:00 INFO: log (logs.py line 328):
    Deactivated <#OV28:ocn_surf_flux_diag.ts> due to ChildFailureEvent("Deactivating <#OV28:ocn_surf_flux_diag.ts> due to failure of all child objects.").

08:48:00 INFO: log (logs.py line 328):
    Request for <#OV28:ocn_surf_flux_diag.ts> (='ts' @ 1day) failed; looking for alternate data.

08:48:00 ERROR: log (logs.py line 328):
    Deactivated <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag> due to PodDataError("Requested data not available for POD <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#OV28:ocn_surf_flux_diag.ts>.").

08:48:00 ERROR: log (logs.py line 328):
    Deactivated <#OeF2:NCAR_CESM2_hist_r1i1p1f1> due to ChildFailureEvent("Deactivating <#OeF2:NCAR_CESM2_hist_r1i1p1f1> due to failure of all child objects.").

08:48:00 INFO: log (logs.py line 328):
    Deactivated <#P0MM:ocn_surf_flux_diag.psl> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#OV28:ocn_surf_flux_diag.ts>.") from deactivation of parent <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").

08:48:00 INFO: log (logs.py line 328):
    Deactivated <#P67M:ocn_surf_flux_diag.sfcWind> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#OV28:ocn_surf_flux_diag.ts>.") from deactivation of parent <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").

08:48:00 INFO: log (logs.py line 328):
    Deactivated <#PbQE:ocn_surf_flux_diag.huss> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#OV28:ocn_surf_flux_diag.ts>.") from deactivation of parent <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").

08:48:00 INFO: log (logs.py line 328):
    Deactivated <#PhgY:ocn_surf_flux_diag.hfls> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#OV28:ocn_surf_flux_diag.ts>.") from deactivation of parent <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").

08:48:00 INFO: log (logs.py line 328):
    Deactivated <#Pmv0:ocn_surf_flux_diag.pr> due to PropagatedEvent("Caught exception PodDataError("Requested data not available for POD <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>: No alternate data available for <#OV28:ocn_surf_flux_diag.ts>.") from deactivation of parent <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag>.").

08:48:00 INFO: log (logs.py line 328):
    Fetching <#P0MM:ocn_surf_flux_diag.psl> (='psl' @ 1day).

08:48:00 DEBUG: log (logs.py line 328):
    Fetching DataKey(12).

08:48:00 DEBUG: log (logs.py line 328):
    Fetch DataKey(12): found /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.psl.day.nc.

08:48:00 INFO: log (logs.py line 328):
    Fetching <#P67M:ocn_surf_flux_diag.sfcWind> (='sfcWind' @ 1day).

08:48:00 DEBUG: log (logs.py line 328):
    Fetching DataKey(15).

08:48:00 DEBUG: log (logs.py line 328):
    Fetch DataKey(15): found /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.sfcWind.day.nc.

08:48:00 INFO: log (logs.py line 328):
    Fetching <#PbQE:ocn_surf_flux_diag.huss> (='huss' @ 1day).

08:48:00 DEBUG: log (logs.py line 328):
    Fetching DataKey(13).

08:48:00 DEBUG: log (logs.py line 328):
    Fetch DataKey(13): found /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.huss.day.nc.

08:48:00 INFO: log (logs.py line 328):
    Fetching <#PhgY:ocn_surf_flux_diag.hfls> (='hfls' @ 1day).

08:48:00 DEBUG: log (logs.py line 328):
    Fetching DataKey(14).

08:48:00 DEBUG: log (logs.py line 328):
    Fetch DataKey(14): found /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.hfls.day.nc.

08:48:00 INFO: log (logs.py line 328):
    Fetching <#Pmv0:ocn_surf_flux_diag.pr> (='pr' @ 1day).

08:48:00 DEBUG: log (logs.py line 328):
    Fetching DataKey(11).

08:48:00 DEBUG: log (logs.py line 328):
    Fetch DataKey(11): found /home/joedhsu/mdtf/inputdata/model/NCAR_CESM2_hist_r1i1p1f1/day/NCAR_CESM2_hist_r1i1p1f1.pr.day.nc.

08:48:00 INFO: log (logs.py line 328):
    Received event at DataSource level: DataQueryEvent("Too many iterations in select_data() for <#OeF2:NCAR_CESM2_hist_r1i1p1f1>.").

08:48:00 DEBUG: log (logs.py line 328):
    Data request for <#OV28:ocn_surf_flux_diag.ts> failed.

08:48:00 DEBUG: log (logs.py line 328):
    Data request for <#P0MM:ocn_surf_flux_diag.psl> failed.

08:48:00 DEBUG: log (logs.py line 328):
    Data request for <#P67M:ocn_surf_flux_diag.sfcWind> failed.

08:48:00 DEBUG: log (logs.py line 328):
    Data request for <#PbQE:ocn_surf_flux_diag.huss> failed.

08:48:00 DEBUG: log (logs.py line 328):
    Data request for <#PhgY:ocn_surf_flux_diag.hfls> failed.

08:48:00 DEBUG: log (logs.py line 328):
    Data request for <#Pmv0:ocn_surf_flux_diag.pr> failed.

08:48:00 DEBUG: log (logs.py line 328):
    Data request for <#OLP2:NCAR_CESM2_hist_r1i1p1f1.ocn_surf_flux_diag> failed.

08:48:00 DEBUG: log (logs.py line 328):
    Writing file /home/joedhsu/mdtf/wkdir/MDTF_NCAR_CESM2_hist_r1i1p1f1_2000_2009/config_save.json

08:48:00 INFO: log (logs.py line 328):
    <#OeF2:NCAR_CESM2_hist_r1i1p1f1>: Creating '/home/joedhsu/mdtf/wkdir/MDTF_NCAR_CESM2_hist_r1i1p1f1_2000_2009.tar'.
wrongkindofdoctor commented 2 years ago

@chiaweh2 Great news! I have not added the metadata fix to the develop branch yet, so I'll put in a PR for it.

wrongkindofdoctor commented 2 years ago

@chiaweh2 The develop branch now has the calendar logic modification that will allow your POD to run with the NCAR data.

chiaweh2 commented 2 years ago

@wrongkindofdoctor Awesome! I merged the develop branch with my current branch and works great with the NCAR CESM2 data. Should I do a PR on my branch?

wrongkindofdoctor commented 2 years ago

@chiaweh2 Yes, go ahead and submit a PR whenever you're ready