BUG - MAG L1D jobs failing and duplicate runs

[alastairtree]

Description of the issue

The MAG L1D processing seems to have issues, for example Dec 11th there are no L1D files despite us having data. The job failure logs show a couple of issues:

• L1D Jobs seems to be running more than once, starting at the same time for same duration. Some jobs do the upload while the duplicate jobs shows skipped uploads
• errors relating to the spin data not being available that then run later - is L1D running too soon?
• Multiple versions for L1D files where there does not need to be so many versions

Sample of the errors:

/usr/local/lib/python3.12/site-packages/xarray/namedarray/core.py:261: UserWarning: Duplicate dimension names present: dimensions {'dim0'} appear more than once in dims=('dim0', 'dim0'). We do not yet support duplicate dimension names, but we do allow initial construction of the object. We recommend you rename the dims immediately to become distinct, as most xarray functionality is likely to fail silently if you do not. To rename the dimensions you will need to set the ``.dims`` attribute of each variable, ``e.g. var.dims=('x0', 'x1')``.
  self._dims = self._parse_dimensions(dims)
/usr/local/lib/python3.12/site-packages/imap_processing/spice/spin.py:210: SettingWithCopyWarning: 
A value is trying to be set on a copy of a slice from a DataFrame.
Try using .loc[row_indexer,col_indexer] = value instead
See the caveats in the documentation: https://pandas.pydata.org/pandas-docs/stable/user_guide/indexing.html#returning-a-view-versus-a-copy
  out_df["sc_spin_phase"] = spin_phases

2025-12-12 20:49:49 - WARNING:cdflib.logging:ISTP Compliance Warning: range is listed as the DEPEND_0 for variable URFTOORFO, but the dimensions do not match.
2025-12-12 20:49:49 - WARNING:cdflib.logging:ISTP Compliance Warning: range is listed as the DEPEND_0 for variable URFTOORFI, but the dimensions do not match.
2025-12-12 20:49:49 - WARNING:cdflib.logging:Warning: Variable valid_start_datetime listed DEPEND_0 as , but no variable by that name was found.
2025-12-12 20:49:49 - WARNING:cdflib.logging:Warning: Variable gradiometer_factor listed DEPEND_0 as , but no variable by that name was found.
/usr/local/lib/python3.12/site-packages/xarray/namedarray/core.py:261: UserWarning: Duplicate dimension names present: dimensions {'dim0'} appear more than once in dims=('dim0', 'dim0'). We do not yet support duplicate dimension names, but we do allow initial construction of the object. We recommend you rename the dims immediately to become distinct, as most xarray functionality is likely to fail silently if you do not. To rename the dimensions you will need to set the ``.dims`` attribute of each variable, ``e.g. var.dims=('x0', 'x1')``.
  self._dims = self._parse_dimensions(dims)
2025-12-12 20:49:49 - WARNING:cdflib.logging:Warning: Variable spin_average_application_factor listed DEPEND_0 as , but no variable by that name was found.
2025-12-12 20:49:49 - WARNING:cdflib.logging:Warning: Variable number_of_spins listed DEPEND_0 as , but no variable by that name was found.
2025-12-12 20:49:49 - WARNING:cdflib.logging:Warning: Variable quality_flag_threshold listed DEPEND_0 as , but no variable by that name was found.
2025-12-12 20:49:49 - WARNING:cdflib.logging:Warning: Variable URFTOORFO listed DEPEND_0 as range, but they have different dimension lengths.
2025-12-12 20:49:49 - WARNING:cdflib.logging:Warning: Variable URFTOORFI listed DEPEND_0 as range, but they have different dimension lengths.

File "/usr/local/lib/python3.12/site-packages/imap_processing/spice/spin.py", line 170, in interpolate_spin_data
    raise ValueError(
ValueError: Query times, [5.03107205e+08 5.03107206e+08 5.03107206e+08 ... 5.03193604e+08
 5.03193604e+08 5.03193605e+08] are outside of the spin data range, (np.float64(503086046.34021), np.float64(503156536.025827)).

Duplicate example

Days where we are missing L1D data:
2025-12-10
2025-12-11
2025-12-14 and onwards

Please can we have data for the missing days reprocessed?

Going forwards, while we wait for a proper long term fix, should we just request reprocessing for missing days? Could this be automated somehow?

Steps to reproduce the issue

No response

Expected behavior (What should happen)

No response

Actual behavior (What does happen)

No response

Code Snippet:

Code

Additional notes, affected areas, and suggested fixes

No response

[maxinelasp]

This is caused by a few different problems.

1. Some of the runs are timing out. I will open a PR to raise the timeout limit. Normally, it takes about 1.5 hours, and the timeout is at 2 hours. If it takes much longer than 2 hours, this probably needs some optimization somewhere, but it's possible that it's already close to succeeding at 2 hours.
2. The duplicate runs are due to a race condition while reprocessing. I will route L1D reprocessing jobs to a delay queue which adds a 15 minute delay, which should mitigate that issue.
3. The spin phase issue is more complicated, but I have been working on diagnosing and fixing this issue.

Long term:
For now, manually having us reprocess should work (especially once I stabilize this and make it more reliable.) If we are still seeing problems after all these fixes, the SDC can discuss some kind of smart retry system.

[greglucas]

2 hours seems like a long time for a job to me on a time-series based instrument. We should look into profiling this to see why it is taking so long as I'd expect this to be closer to seconds to minutes time scales for the computations. In burst mode we should be getting about 11M (86400 * 128 = ~11M) points/day * 4 directions or so and maybe a few other variables. If we can put these all into numpy arrays, we should be able to process very quickly.

[maxinelasp]

After some very quick initial testing, here are some off the bat results:

• Slowest part is rotating between different frames - the call to rotate_frame takes an hour(!) for all the calls
• As far as mag-specific algorithm code, looks like the steps which do matrix rotations from the calibration file or from computed matrices are pretty slow - those are np.apply_along_axis calls which aren't exactly the fastest numpy calls, so presumably there's an easy swap there. However, looks like the cumtime in all apply_along_axis calls is only 170s so that's definitely not the main issue.
• The runs that take over 3 hours in batch are taking just over an hour locally - maybe beefing up the compute will also help? Additionally, the runs that finish in batch in 1.5 hours are taking 1 hour locally. That means, even though some runs take more than 2x the time in batch, when running locally I am not seeing that issue. Presumably there is some parallelization happening locally that can't happen in batch which could also contribute to some of the issues...

Here's some of the results to illustrate this:

================================================================================
MAG-SPECIFIC FUNCTIONS (sorted by cumulative time)
================================================================================
         6225970280 function calls (6200224946 primitive calls) in 4146.096 seconds

   Ordered by: cumulative time
   List reduced from 2390 to 19 due to restriction <'.*mag.*'>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000 4027.696 4027.696 /Users/maha7656/Documents/code/imap/imap_processing/imap_processing/mag/l1d/mag_l1d.py:12(mag_l1d)
       12    0.170    0.014 3848.814  320.735 /Users/maha7656/Documents/code/imap/imap_processing/imap_processing/mag/l1d/mag_l1d_data.py:271(rotate_frame)
        2    0.054    0.027 1149.154  574.577 /Users/maha7656/Documents/code/imap/imap_processing/imap_processing/mag/l1d/mag_l1d_data.py:161(__post_init__)
        2    0.278    0.139  170.357   85.179 /Users/maha7656/Documents/code/imap/imap_processing/imap_processing/mag/l1d/mag_l1d_data.py:321(_calibrate_and_offset_vectors)
        4    0.000    0.000  110.460   27.615 /Users/maha7656/Documents/code/imap/imap_processing/imap_processing/mag/l2/mag_l2_data.py:347(apply_calibration)
 22932098   45.633    0.000   77.119    0.000 /Users/maha7656/Documents/code/imap/imap_processing/imap_processing/mag/l1b/mag_l1b.py:330(calibrate_vector)
 22932098   24.639    0.000   28.230    0.000 /Users/maha7656/Documents/code/imap/imap_processing/imap_processing/mag/l1d/mag_l1d_data.py:380(apply_calibration_offset_single_vector)
        4    5.778    1.444    5.904    1.476 /Users/maha7656/Documents/code/imap/imap_processing/imap_processing/mag/l1d/mag_l1d_data.py:583(apply_spin_offsets)

... snipped here ...

[greglucas]

Slowest part is rotating between different frames - the call to rotate_frame takes an hour(!) for all the calls

@subagonsouth thoughts here on any vectorization capability?

[subagonsouth]

Slowest part is rotating between different frames - the call to rotate_frame takes an hour(!) for all the calls

@subagonsouth thoughts here on any vectorization capability?

I don't know that there is much that can be done regarding vectorization of the underlying SPICE calls. The piece that cannot be truly vectorized is any call to spiceypy.pxform() which is the function that gets the rotation matrix to transform from one frame to another at a givent time. I do see some opportunity for optimization on how all of the various transforms are done. I suggest taking advantage of the fact that several of the transforms are fixed transforms.

For example, rotating from IMAP_MAG_O or IMAP_MAG_I to IMAP_SPACECRAFT will never change with time so a single rotation matrix can be gotten from spice and then you can leverage numpy broadcasting to transform all vectors at all times to the spacecraft frame. geometry.frame_transform will do this for you if you only pass a single ET time for transforms that you know are fixed in time.

It may also reduce the number of SPICE calls under the hood to rotate to J2000 once and then from there, to IMAP_DPS, IMAP_GSE, IMAP_GSM, and IMAP_RTN. IMAP_DPS will be static for a single Pointing, so if the data all belongs to one Pointing, you could just use the first time in the call to geometry.frame_transform. Unfortunately, the others, GSE, GSM, and RTN are dynamic frames so I don't think that there is a way to avoid the looped calls to spiceypy.pxform().

What is the time resolution of all this data that is being transformed?