Repository: nipy/heudiconv

Issue:
heudiconv failure with false report of successful conversion
<!-- DO NOT DELETE THIS! 
This template is used to facilitate issue resolution.
All text in <!-> tags will not be displayed.
-->

### Summary
<!-- If you are having conversion troubles, please share as much
relevant information as possible. This includes, but is not limited to:
- log of conversion
- heuristic
-->

When running the following command:

```
heudiconv -c dcm2niix --bids \
    -o /home/zhark/BIDS -g accession_number -f reproin -l \  Duchaine/Duchaine/1087_RO1pilot --files \
/inbox/DICOM/2023/04/02/A005734 -ss 02
```

I get the following error message before it finishes, which is somewhat not good --- BUT if I run reproin study-show after that, it reports that the accession/session is done! and converted as if there wasn't an error, which is more not good --- AND because it pukes before updating git/datalad, most of the files DO get written into the target folders (including into .heudiconv and sourcedata), while they DO NOT get tracked in git..

So, here is the output for the error (to be solved with some future effort..)
```
....
INFO: Adding "IntendedFor" to the fieldmaps in /home/zhark/BIDS/Duchaine/Duchaine/1087_RO1pilot/sub-sid002645/ses-02.
Traceback (most recent call last):
  File "/usr/bin/heudiconv", line 33, in <module>
    sys.exit(load_entry_point('heudiconv==0.11.6', 'console_scripts', 'heudiconv')())
  File "/usr/lib/python3/dist-packages/heudiconv/cli/run.py", line 24, in main
    workflow(**kwargs)
  File "/usr/lib/python3/dist-packages/heudiconv/main.py", line 379, in workflow
    prep_conversion(sid,
  File "/usr/lib/python3/dist-packages/heudiconv/convert.py", line 209, in prep_conversion
    convert(cinfo,
  File "/usr/lib/python3/dist-packages/heudiconv/convert.py", line 587, in convert
    populate_intended_for(session_path, **populate_intended_for_opts)
  File "/usr/lib/python3/dist-packages/heudiconv/bids.py", line 912, in populate_intended_for
    selected_fmaps[json_file] = select_fmap_from_compatible_groups(
  File "/usr/lib/python3/dist-packages/heudiconv/bids.py", line 830, in select_fmap_from_compatible_groups
    json_acq_time = datetime.strptime(
  File "/usr/lib/python3.9/_strptime.py", line 568, in _strptime_datetime
    tt, fraction, gmtoff_fraction = _strptime(data_string, format)
  File "/usr/lib/python3.9/_strptime.py", line 349, in _strptime
    raise ValueError("time data %r does not match format %r" %
ValueError: time data '2023-04-02T11:47:09' does not match format '%Y-%m-%dT%H:%M:%S.%f'
```

Here is the tail end of
~/proj/reproin/bin/reproin study-show Duchaine/Duchaine/1087_RO1pilot:

```
# /inbox/DICOM/2023/03/27/A005717 done  sid002637 session=day1  !!! was converted into sid002637/ses-02
# /inbox/DICOM/2023/04/01/A005732 done  sid002645 session=day1  !!! was converted into sid002645/ses-01
# /inbox/DICOM/2023/04/02/A005734 done  sid002645 session=day1  !!! was converted into sid002645/ses-02
```

And here is git status report:

```
zhark@rolando:/home/zhark/BIDS/Duchaine/Duchaine/1087_RO1pilot$ git status
On branch master
Untracked files:
  (use "git add <file>..." to include in what will be committed)
	.heudiconv/sid002645/ses-02/
	sourcedata/sub-sid002645/ses-02/
	sub-sid002645/ses-02/
```

nothing added to commit but untracked files present (use "git add" to track)


So we should try to fix reproin (?) so that study-show does not falsely report successful conversion when such a break happens.

RE the time format error: It looks like python _strptime.py doesn't appreciate "000000" for milisecs?
It looks like because the Acquisition time for this run just happened to be exactly on the second 11:47:9.000000, some parser made it into  2023-04-02T11:47:09 instead of 2023-04-02T11:47:09.0

or something...

func/sub-sid002645_ses-02_task-voice_run-03_bold.json:  "AcquisitionTime": "11:47:9.000000",

FROM Yarik:

wow -- congrats, you were lucky enough to hit such an unlucky time point
and detect a bug.  My bet it is due to a bug in a very ugly and ad-hoc
https://github.com/dbic/heudiconv/blob/HEAD/heudiconv/utils.py#L190

but there is a check that we save/load for identical value so not sure
yet if it is the one exactly to blame here.  Would need to look into it.

Please file a heudiconv issue, may be with above note from myself


Discussion:

Patch:
diff --git a/heudiconv/bids.py b/heudiconv/bids.py
index b3ff42c..f068c5a 100644
--- a/heudiconv/bids.py
+++ b/heudiconv/bids.py
@@ -6,7 +6,6 @@ __docformat__ = "numpy"
 
 from collections import OrderedDict
 import csv
-from datetime import datetime
 import errno
 from glob import glob
 import hashlib
@@ -32,6 +31,7 @@ from .utils import (
     remove_suffix,
     save_json,
     set_readonly,
+    strptime_micr,
     update_json,
 )
 
@@ -369,7 +369,9 @@ def tuneup_bids_json_files(json_files: list[str]) -> None:
                 set_readonly(json_phasediffname)
 
 
-def add_participant_record(studydir: str, subject: str, age: str | None, sex: str | None) -> None:
+def add_participant_record(
+    studydir: str, subject: str, age: str | None, sex: str | None
+) -> None:
     participants_tsv = op.join(studydir, "participants.tsv")
     participant_id = "sub-%s" % subject
 
@@ -945,17 +947,17 @@ def select_fmap_from_compatible_groups(
             k for k, v in acq_times_fmaps.items() if v == first_acq_time
         ][0]
     elif criterion == "Closest":
-        json_acq_time = datetime.strptime(
+        json_acq_time = strptime_micr(
             acq_times[
                 # remove session folder and '.json', add '.nii.gz':
                 remove_suffix(remove_prefix(json_file, sess_folder + op.sep), ".json")
                 + ".nii.gz"
             ],
-            "%Y-%m-%dT%H:%M:%S.%f",
+            "%Y-%m-%dT%H:%M:%S[.%f]",
         )
         # differences in acquisition time (abs value):
         diff_fmaps_acq_times = {
-            k: abs(datetime.strptime(v, "%Y-%m-%dT%H:%M:%S.%f") - json_acq_time)
+            k: abs(strptime_micr(v, "%Y-%m-%dT%H:%M:%S[.%f]") - json_acq_time)
             for k, v in acq_times_fmaps.items()
         }
         min_diff_acq_times = sorted(diff_fmaps_acq_times.values())[0]
diff --git a/heudiconv/dicoms.py b/heudiconv/dicoms.py
index 42a79af..ef51086 100644
--- a/heudiconv/dicoms.py
+++ b/heudiconv/dicoms.py
@@ -15,7 +15,14 @@ import warnings
 
 import pydicom as dcm
 
-from .utils import SeqInfo, TempDirs, get_typed_attr, load_json, set_readonly
+from .utils import (
+    SeqInfo,
+    TempDirs,
+    get_typed_attr,
+    load_json,
+    set_readonly,
+    strptime_micr,
+)
 
 if TYPE_CHECKING:
     if sys.version_info >= (3, 8):
@@ -481,16 +488,16 @@ def get_datetime_from_dcm(dcm_data: dcm.FileDataset) -> Optional[datetime.dateti
     acq_date = dcm_data.get("AcquisitionDate")
     acq_time = dcm_data.get("AcquisitionTime")
     if not (acq_date is None or acq_time is None):
-        return datetime.datetime.strptime(acq_date + acq_time, "%Y%m%d%H%M%S.%f")
+        return strptime_micr(acq_date + acq_time, "%Y%m%d%H%M%S[.%f]")
 
     acq_dt = dcm_data.get("AcquisitionDateTime")
     if acq_dt is not None:
-        return datetime.datetime.strptime(acq_dt, "%Y%m%d%H%M%S.%f")
+        return strptime_micr(acq_dt, "%Y%m%d%H%M%S[.%f]")
 
     series_date = dcm_data.get("SeriesDate")
     series_time = dcm_data.get("SeriesTime")
     if not (series_date is None or series_time is None):
-        return datetime.datetime.strptime(series_date + series_time, "%Y%m%d%H%M%S.%f")
+        return strptime_micr(series_date + series_time, "%Y%m%d%H%M%S[.%f]")
     return None
 
 
diff --git a/heudiconv/utils.py b/heudiconv/utils.py
index 1c3b450..9f98826 100644
--- a/heudiconv/utils.py
+++ b/heudiconv/utils.py
@@ -666,6 +666,27 @@ def get_datetime(date: str, time: str, *, microseconds: bool = True) -> str:
     return datetime_str
 
 
+def strptime_micr(date_string: str, fmt: str) -> datetime:
+    r"""
+    Decorate strptime while supporting optional [.%f] in the format at the end
+
+    Parameters
+    ----------
+    date_string: str
+      Date string to parse
+    fmt: str
+      Format string. If it ends with [.%f], we keep it if date_string ends with
+      '.\d+' regex and not if it does not.
+    """
+
+    optional_micr = "[.%f]"
+    if fmt.endswith(optional_micr):
+        fmt = fmt[: -len(optional_micr)]
+        if re.search(r"\.\d+$", date_string):
+            fmt += ".%f"
+    return datetime.strptime(date_string, fmt)
+
+
 def remove_suffix(s: str, suf: str) -> str:
     """
     Remove suffix from the end of the string


Test patch:
diff --git a/heudiconv/tests/test_utils.py b/heudiconv/tests/test_utils.py
index a1d94ad..064f50c 100644
--- a/heudiconv/tests/test_utils.py
+++ b/heudiconv/tests/test_utils.py
@@ -1,5 +1,6 @@
 from __future__ import annotations
 
+from datetime import datetime
 import json
 from json.decoder import JSONDecodeError
 import os
@@ -21,6 +22,7 @@ from heudiconv.utils import (
     remove_prefix,
     remove_suffix,
     save_json,
+    strptime_micr,
     update_json,
 )
 
@@ -168,6 +170,24 @@ def test_get_datetime() -> None:
     )
 
 
+@pytest.mark.parametrize(
+    "dt, fmt",
+    [
+        ("20230310190100", "%Y%m%d%H%M%S"),
+        ("2023-04-02T11:47:09", "%Y-%m-%dT%H:%M:%S"),
+    ],
+)
+def test_strptime_micr(dt: str, fmt: str) -> None:
+    target = datetime.strptime(dt, fmt)
+    assert strptime_micr(dt, fmt) == target
+    assert strptime_micr(dt, fmt + "[.%f]") == target
+    assert strptime_micr(dt + ".0", fmt + "[.%f]") == target
+    assert strptime_micr(dt + ".000000", fmt + "[.%f]") == target
+    assert strptime_micr(dt + ".1", fmt + "[.%f]") == datetime.strptime(
+        dt + ".1", fmt + ".%f"
+    )
+
+
 def test_remove_suffix() -> None:
     """
     Test utils.remove_suffix()