njcuk9999 / apero-drs

A PipelinE to Reduce Observations - The DRS for SPIRou (CFHT)
MIT License
12 stars 1 forks source link

0.7.290 minidata2 errors: fit of the blaze fitting, likely triggering a cascade of other errors. #781

Open larnoldgithub opened 2 months ago

larnoldgithub commented 2 months ago

Hi @njcuk9999 Here are the errors at the end of the processing - below there is also the full log of ....apero_flat_spirou.log of 2020-11-01

@clairem789 did your test with the .290 end with no errors ?


04:42:29.702-  |PROC|Errors:
04:42:29.707-  |PROC| ***************************************************************************
04:42:29.712-  |PROC|
04:42:29.718-  |PROC|
04:42:29.723-  |PROC| ***************************************************************************
04:42:29.728-@!|PROC|W[40-503-00019]: Error found for ID='1223'
04:42:29.733-@!|PROC|   apero_flat_spirou.py 2020-11-01 2539860f_pp.fits 2539861f_pp.fits 2539862f_pp.fits 2539863f_pp.fits 2539864f_pp.fits 2539865f_pp.fits 2539866f_pp.fits 2539867f_pp.fits 2539868f_pp.fits 2539869f_pp.fits 2539870f_pp.fits 2539871f_pp.fits 2539872f_pp.fits 2539873f_pp.fits 2539874f_pp.fits 2540063f_pp.fits 2540064f_pp.fits 2540065f_pp.fits 2540066f_pp.fits 2540067f_pp.fits 2540068f_pp.fits 2540069f_pp.fits 2540070f_pp.fits 2540071f_pp.fits 2540072f_pp.fits 2540073f_pp.fits 2540074f_pp.fits 2540075f_pp.fits 2540076f_pp.fits 2540077f_pp.fits --crunfile=mini_run2.ini --program=FF[01223] --recipe_kind=calib-night --shortname=FF --parallel=True
04:42:29.737-  |PROC| ***************************************************************************
04:42:29.742-  |PROC|
 E[40-015-00009]: Error fitting sinc to blaze. Order = 45 Fiber = A Iteration =
    -1
 Guess: amp=191774.0009571721 period=7034.0 lin=1205.0 slope=0 quad=0 (cube=0)
     Lower: amp=0 period=0.0 lin=0.0 slope=-inf quad=-inf (cube=-1e-20) 
 Upper: amp=287661.00143575814 period=inf lin=4087 slope=inf quad=inf
    (cube=1e-20)
 Error <class 'RuntimeError'>: Optimal parameters not found: Number of calls to
    function has reached maxfev = 1200.
     Function = science.extract.extraction.py.calculate_blaze_flat_sinc()
04:42:29.750-  |PROC|
04:42:29.755-  |PROC|
04:42:29.759-  |PROC| ***************************************************************************
04:42:29.764-  |PROC|
04:42:29.769-  |PROC| ***************************************************************************
04:42:29.774-@!|PROC|W[40-503-00019]: Error found for ID='1236'
04:42:29.779-@!|PROC|   apero_thermal_spirou.py 2020-11-01 2539856d_pp.fits 2539857d_pp.fits 2540059d_pp.fits 2540060d_pp.fits --crunfile=mini_run2.ini --program=THERM_I[01236] --recipe_kind=calib-night-I --shortname=THERM_I --parallel=True
04:42:29.784-  |PROC| ***************************************************************************
04:42:29.788-  |PROC|
 E[01-001-00012]: Read Error: File 'AE95B579E0d_pp_e2dsff_AB.fits' could not be
    found in directory '/apero-data/test_helu/red/2020-11-01'.
     function = io.drs_fits.py.readfits()
04:42:29.794-  |PROC|
04:42:29.799-  |PROC|
04:42:29.804-  |PROC| ***************************************************************************
04:42:29.809-  |PROC|
04:42:29.814-  |PROC| ***************************************************************************
04:42:29.819-@!|PROC|W[40-503-00019]: Error found for ID='1249'
04:42:29.824-@!|PROC|   apero_wave_night_spirou.py 2020-11-01 --hcfiles 2539884c_pp.fits 2539885c_pp.fits 2540087c_pp.fits 2540088c_pp.fits --fpfiles 2539877a_pp.fits 2539878a_pp.fits 2539879a_pp.fits 2539880a_pp.fits 2539881a_pp.fits 2540080a_pp.fits 2540081a_pp.fits 2540082a_pp.fits 2540083a_pp.fits 2540084a_pp.fits --crunfile=mini_run2.ini --program=WAVE[01249] --recipe_kind=calib-night --shortname=WAVE --parallel=True
04:42:29.829-  |PROC| ***************************************************************************
04:42:29.833-  |PROC|
 E[01-001-00012]: Read Error: File '71BD70FC89c_pp_e2dsff_AB.fits' could not be
    found in directory '/apero-data/test_helu/red/2020-11-01'.
     function = io.drs_fits.py.readfits()
04:42:29.839-  |PROC|
04:42:29.844-  |PROC|
04:42:29.849-  |PROC| ***************************************************************************
04:42:29.854-  |PROC|
04:42:29.859-  |PROC| ***************************************************************************
04:42:29.864-@!|PROC|W[40-503-00019]: Error found for ID='1262'
04:42:29.869-@!|PROC|   apero_thermal_spirou.py 2020-11-01 2539858d_pp.fits 2539859d_pp.fits 2540061d_pp.fits 2540062d_pp.fits --crunfile=mini_run2.ini --program=THERM_T[01262] --recipe_kind=calib-night-T --shortname=THERM_T --parallel=True
04:42:29.874-  |PROC| ***************************************************************************
04:42:29.879-  |PROC|
 E[01-001-00012]: Read Error: File 'B586EB043Dd_pp_e2dsff_AB.fits' could not be
    found in directory '/apero-data/test_helu/red/2020-11-01'.
     function = io.drs_fits.py.readfits()
04:42:29.885-  |PROC|
04:42:29.890-  |PROC|
04:42:29.895-  |PROC| ***************************************************************************
04:42:29.900-  |PROC|
04:42:29.905-  |PROC| ***************************************************************************
04:42:29.910-@!|PROC|W[40-503-00019]: Error found for ID='1263'
04:42:29.915-@!|PROC|   apero_extract_spirou.py 2020-11-01 2540058o_pp.fits --crunfile=mini_run2.ini --program=EXTTELL[01263] --recipe_kind=extract-hotstar --shortname=EXTTELL --parallel=True
04:42:29.919-  |PROC| ***************************************************************************
04:42:29.924-  |PROC|
 E[09-002-00004]: Calibration file (WAVE) was selected as the calibration file
    but is not within desired limits (25.254440838056325>7.0 days)
    ObsTime: 2020-11-01 15:51:21.910
    CalibTime:2020-10-07 09:44:58.221
    File: /apero-data/test_helu/calib/82FDCC3E96a_pp_e2dsff_C_wave_night_C.fits 
     Function: science.calib.gen_calib.py.calib_delta_time_check()
04:42:29.931-  |PROC|
04:42:29.936-  |PROC|
04:42:29.940-  |PROC| ***************************************************************************
04:42:29.945-  |PROC|
04:42:29.950-  |PROC| ***************************************************************************
04:42:29.955-@!|PROC|W[40-503-00019]: Error found for ID='1264'
04:42:29.960-@!|PROC|   apero_extract_spirou.py 2020-11-01 2540057o_pp.fits --crunfile=mini_run2.ini --program=EXTTELL[01264] --recipe_kind=extract-hotstar --shortname=EXTTELL --parallel=True
04:42:29.965-  |PROC| ***************************************************************************
04:42:29.969-  |PROC|
 E[09-002-00004]: Calibration file (WAVE) was selected as the calibration file
    but is not within desired limits (25.25211791791662>7.0 days)
    ObsTime: 2020-11-01 15:48:01.209
    CalibTime:2020-10-07 09:44:58.221
    File: /apero-data/test_helu/calib/82FDCC3E96a_pp_e2dsff_C_wave_night_C.fits 
     Function: science.calib.gen_calib.py.calib_delta_time_check()
04:42:29.976-  |PROC|
04:42:29.981-  |PROC|
04:42:29.986-  |PROC| ***************************************************************************
04:42:29.991-  |PROC|
04:42:29.996-  |PROC| ***************************************************************************
04:42:30.001-@!|PROC|W[40-503-00019]: Error found for ID='1265'
04:42:30.005-@!|PROC|   apero_extract_spirou.py 2020-11-01 2540040o_pp.fits --crunfile=mini_run2.ini --program=EXTTELL[01265] --recipe_kind=extract-hotstar --shortname=EXTTELL --parallel=True
04:42:30.010-  |PROC| ***************************************************************************
04:42:30.015-  |PROC|
 E[09-002-00004]: Calibration file (WAVE) was selected as the calibration file
    but is not within desired limits (25.199935651471606>7.0 days)
    ObsTime: 2020-11-01 14:32:52.662
    CalibTime:2020-10-07 09:44:58.221
    File: /apero-data/test_helu/calib/82FDCC3E96a_pp_e2dsff_C_wave_night_C.fits 
     Function: science.calib.gen_calib.py.calib_delta_time_check()
04:42:30.022-  |PROC|
04:42:30.027-  |PROC|
04:42:30.032-  |PROC| ***************************************************************************
04:42:30.036-  |PROC|
04:42:30.041-  |PROC| ***************************************************************************
04:42:30.046-@!|PROC|W[40-503-00019]: Error found for ID='1266'
04:42:30.051-@!|PROC|   apero_extract_spirou.py 2020-11-01 2539999o_pp.fits --crunfile=mini_run2.ini --program=EXTTELL[01266] --recipe_kind=extract-hotstar --shortname=EXTTELL --parallel=True
04:42:30.056-  |PROC| ***************************************************************************
04:42:30.061-  |PROC|
 E[09-002-00004]: Calibration file (WAVE) was selected as the calibration file
    but is not within desired limits (25.058922247313603>7.0 days)
    ObsTime: 2020-11-01 11:09:49.104
    CalibTime:2020-10-07 09:44:58.221
    File: /apero-data/test_helu/calib/82FDCC3E96a_pp_e2dsff_C_wave_night_C.fits 
     Function: science.calib.gen_calib.py.calib_delta_time_check()
04:42:30.067-  |PROC|
04:42:30.072-  |PROC|
04:42:30.077-  |PROC| ***************************************************************************
04:42:30.082-  |PROC|
04:42:30.087-  |PROC| ***************************************************************************
04:42:30.092-@!|PROC|W[40-503-00019]: Error found for ID='1267'
04:42:30.097-@!|PROC|   apero_extract_spirou.py 2020-11-01 2539918o_pp.fits --crunfile=mini_run2.ini --program=EXTTELL[01267] --recipe_kind=extract-hotstar --shortname=EXTTELL --parallel=True
04:42:30.101-  |PROC| ***************************************************************************
04:42:30.106-  |PROC|
 E[09-002-00004]: Calibration file (WAVE) was selected as the calibration file
    but is not within desired limits (24.817991627176525>7.0 days)
    ObsTime: 2020-11-01 05:22:52.698
    CalibTime:2020-10-07 09:44:58.221
    File: /apero-data/test_helu/calib/82FDCC3E96a_pp_e2dsff_C_wave_night_C.fits 
     Function: science.calib.gen_calib.py.calib_delta_time_check()
04:42:30.113-  |PROC|
04:42:30.117-  |PROC|
04:42:30.122-  |PROC| ***************************************************************************
04:42:30.127-  |PROC|
04:42:30.132-  |PROC| ***************************************************************************
04:42:30.137-@!|PROC|W[40-503-00019]: Error found for ID='1309'
04:42:30.141-@!|PROC|   apero_extract_spirou.py 2020-11-01 2539897o_pp.fits --crunfile=mini_run2.ini --program=EXTOBJ[01309] --recipe_kind=extract-science --shortname=EXTOBJ --parallel=True
04:42:30.146-  |PROC| ***************************************************************************
04:42:30.151-  |PROC|
 E[09-002-00004]: Calibration file (WAVE) was selected as the calibration file
    but is not within desired limits (24.78299669268017>7.0 days)
    ObsTime: 2020-11-01 04:32:29.136
    CalibTime:2020-10-07 09:44:58.221
    File: /apero-data/test_helu/calib/82FDCC3E96a_pp_e2dsff_C_wave_night_C.fits 
     Function: science.calib.gen_calib.py.calib_delta_time_check()
04:42:30.158-  |PROC|
04:42:30.163-  |PROC|
04:42:30.167-  |PROC| ***************************************************************************
04:42:30.172-  |PROC|
04:42:30.177-  |PROC| ***************************************************************************
04:42:30.182-@!|PROC|W[40-503-00019]: Error found for ID='1310'
04:42:30.187-@!|PROC|   apero_extract_spirou.py 2020-11-01 2539896o_pp.fits --crunfile=mini_run2.ini --program=EXTOBJ[01310] --recipe_kind=extract-science --shortname=EXTOBJ --parallel=True
04:42:30.192-  |PROC| ***************************************************************************
04:42:30.197-  |PROC|
 E[09-002-00004]: Calibration file (WAVE) was selected as the calibration file
    but is not within desired limits (24.78202999268251>7.0 days)
    ObsTime: 2020-11-01 04:31:05.613
    CalibTime:2020-10-07 09:44:58.221
    File: /apero-data/test_helu/calib/82FDCC3E96a_pp_e2dsff_C_wave_night_C.fits 
     Function: science.calib.gen_calib.py.calib_delta_time_check()
04:42:30.204-  |PROC|
04:42:30.209-  |PROC|
04:42:30.214-  |PROC| ***************************************************************************
04:42:30.218-  |PROC|
04:42:30.223-  |PROC| ***************************************************************************
04:42:30.228-@!|PROC|W[40-503-00019]: Error found for ID='1311'
04:42:30.234-@!|PROC|   apero_extract_spirou.py 2020-11-01 2539895o_pp.fits --crunfile=mini_run2.ini --program=EXTOBJ[01311] --recipe_kind=extract-science --shortname=EXTOBJ --parallel=True
04:42:30.239-  |PROC| ***************************************************************************
04:42:30.244-  |PROC|
 E[09-002-00004]: Calibration file (WAVE) was selected as the calibration file
    but is not within desired limits (24.781061892681464>7.0 days)
    ObsTime: 2020-11-01 04:29:41.969
    CalibTime:2020-10-07 09:44:58.221
    File: /apero-data/test_helu/calib/82FDCC3E96a_pp_e2dsff_C_wave_night_C.fits 
     Function: science.calib.gen_calib.py.calib_delta_time_check()
04:42:30.251-  |PROC|
04:42:30.256-  |PROC|
04:42:30.260-  |PROC| ***************************************************************************
04:42:30.265-  |PROC|
04:42:30.270-  |PROC| ***************************************************************************
04:42:30.275-@!|PROC|W[40-503-00019]: Error found for ID='1312'
04:42:30.280-@!|PROC|   apero_extract_spirou.py 2020-11-01 2539894o_pp.fits --crunfile=mini_run2.ini --program=EXTOBJ[01312] --recipe_kind=extract-science --shortname=EXTOBJ --parallel=True
04:42:30.285-  |PROC| ***************************************************************************
04:42:30.290-  |PROC|
 E[09-002-00004]: Calibration file (WAVE) was selected as the calibration file
    but is not within desired limits (24.78009389268118>7.0 days)
    ObsTime: 2020-11-01 04:28:18.334
    CalibTime:2020-10-07 09:44:58.221
    File: /apero-data/test_helu/calib/82FDCC3E96a_pp_e2dsff_C_wave_night_C.fits 
     Function: science.calib.gen_calib.py.calib_delta_time_check()
04:42:30.297-  |PROC|
04:42:30.302-  |PROC|
04:42:30.306-  |PROC| ***************************************************************************
04:42:30.311-  |PROC|
04:42:30.316-  |PROC| ***************************************************************************
04:42:30.321-@!|PROC|W[40-503-00019]: Error found for ID='1785'
04:42:30.326-@!|PROC|   apero_postprocess_spirou.py 2020-11-01 2539897o_pp.fits --crunfile=mini_run2.ini --program=SCIPOST[01785] --recipe_kind=post-science --shortname=SCIPOST --parallel=True
04:42:30.331-  |PROC| ***************************************************************************
04:42:30.336-  |PROC|
 E[00-090-00005]: No entries found for extension 1 (EXT_AB) 
 Condition = KW_IDENTIFIER="2539897o" AND BLOCK_KIND="red" AND
    KW_OUTPUT="EXT_E2DS_FF" AND KW_FIBER="AB"
     Function = drs_file.py.DrsInputFile.process_links()
 E[00-090-00005]: No entries found for extension 1 (S1D_W) 
     Condition = KW_IDENTIFIER="2539897o" AND BLOCK_KIND="red" 
     Function = drs_file.py.DrsInputFile.process_links()
 E[00-090-00010]: 2 error(s) occurred for apero_postprocess_spirou
04:42:30.343-  |PROC|
04:42:30.348-  |PROC|
04:42:30.353-  |PROC| ***************************************************************************
04:42:30.358-  |PROC|
04:42:30.362-  |PROC| ***************************************************************************
04:42:30.367-@!|PROC|W[40-503-00019]: Error found for ID='1786'
04:42:30.373-@!|PROC|   apero_postprocess_spirou.py 2020-11-01 2539896o_pp.fits --crunfile=mini_run2.ini --program=SCIPOST[01786] --recipe_kind=post-science --shortname=SCIPOST --parallel=True
04:42:30.378-  |PROC| ***************************************************************************
04:42:30.384-  |PROC|
 E[00-090-00005]: No entries found for extension 1 (EXT_AB) 
 Condition = KW_IDENTIFIER="2539896o" AND BLOCK_KIND="red" AND
    KW_OUTPUT="EXT_E2DS_FF" AND KW_FIBER="AB"
     Function = drs_file.py.DrsInputFile.process_links()
 E[00-090-00005]: No entries found for extension 1 (S1D_W) 
     Condition = KW_IDENTIFIER="2539896o" AND BLOCK_KIND="red" 
     Function = drs_file.py.DrsInputFile.process_links()
 E[00-090-00010]: 2 error(s) occurred for apero_postprocess_spirou
04:42:30.391-  |PROC|
04:42:30.397-  |PROC|
04:42:30.402-  |PROC| ***************************************************************************
04:42:30.407-  |PROC|
04:42:30.413-  |PROC| ***************************************************************************
04:42:30.418-@!|PROC|W[40-503-00019]: Error found for ID='1787'
04:42:30.423-@!|PROC|   apero_postprocess_spirou.py 2020-11-01 2539895o_pp.fits --crunfile=mini_run2.ini --program=SCIPOST[01787] --recipe_kind=post-science --shortname=SCIPOST --parallel=True
04:42:30.429-  |PROC| ***************************************************************************
04:42:30.434-  |PROC|
 E[00-090-00005]: No entries found for extension 1 (EXT_AB) 
 Condition = KW_IDENTIFIER="2539895o" AND BLOCK_KIND="red" AND
    KW_OUTPUT="EXT_E2DS_FF" AND KW_FIBER="AB"
     Function = drs_file.py.DrsInputFile.process_links()
 E[00-090-00005]: No entries found for extension 1 (S1D_W) 
     Condition = KW_IDENTIFIER="2539895o" AND BLOCK_KIND="red" 
     Function = drs_file.py.DrsInputFile.process_links()
 E[00-090-00010]: 2 error(s) occurred for apero_postprocess_spirou
04:42:30.442-  |PROC|
04:42:30.448-  |PROC|
04:42:30.453-  |PROC| ***************************************************************************
04:42:30.458-  |PROC|
04:42:30.464-  |PROC| ***************************************************************************
04:42:30.469-@!|PROC|W[40-503-00019]: Error found for ID='1788'
04:42:30.475-@!|PROC|   apero_postprocess_spirou.py 2020-11-01 2539894o_pp.fits --crunfile=mini_run2.ini --program=SCIPOST[01788] --recipe_kind=post-science --shortname=SCIPOST --parallel=True
04:42:30.480-  |PROC| ***************************************************************************
04:42:30.486-  |PROC|
 E[00-090-00005]: No entries found for extension 1 (EXT_AB) 
 Condition = KW_IDENTIFIER="2539894o" AND BLOCK_KIND="red" AND
    KW_OUTPUT="EXT_E2DS_FF" AND KW_FIBER="AB"
     Function = drs_file.py.DrsInputFile.process_links()
 E[00-090-00005]: No entries found for extension 1 (S1D_W) 
     Condition = KW_IDENTIFIER="2539894o" AND BLOCK_KIND="red" 
     Function = drs_file.py.DrsInputFile.process_links()
 E[00-090-00010]: 2 error(s) occurred for apero_postprocess_spirou
04:42:30.493-  |PROC|
04:42:30.498-  |PROC|
04:42:30.503-  |PROC| ***************************************************************************
04:42:30.507-  |PROC|
04:42:30.855-**|PROC| ***************************************************************************
04:42:30.860-**|PROC|I[40-003-00001]: Recipe apero_processing has been successfully completed
04:42:30.865-**|PROC| ***************************************************************************```

here is the detail of the routine for the blaze that failed:

```larnold@helu:/h/spdrs/apero-data/test_helu/log/processing/APEROG-PID-00017264506535745700-LG5D_apero_processing_group/2020-11-01$ cat APEROL-PID-00017264588181802810-1QE2_apero_flat_spirou.log
03:53:40.881-  |FF[01223]| ***************************************************************************
03:53:40.888-  |FF[01223]| *
03:53:40.888-  |FF[01223]| *  SPIROU @PID-00017264588181802810-1QE2 (V0.7.290)
03:53:40.889-  |FF[01223]| *         py3.9.20  git:v0.7.290-stable-test
03:53:40.889-  |FF[01223]| *
03:53:40.894-  |FF[01223]| *    Group: APEROG-PID-00017264506535745700-LG5D_apero_processing_group
03:53:40.900-  |FF[01223]| ***************************************************************************
03:53:40.905-**|FF[01223]|I[40-001-00006]: DRS Setup:
03:53:40.911-**|FF[01223]|I[
03:53:40.912-**|FF[01223]|  DRS_ROOT: /opt/apero-drs/apero]: 
03:53:40.912-**|FF[01223]|  DRS_ROOT: /opt/apero-drs/apero
03:53:40.913-**|FF[01223]|  DRS_DATA_RAW: /apero-data/test_helu/raw
03:53:40.913-**|FF[01223]|  DRS_DATA_REDUC: /apero-data/test_helu/red
03:53:40.914-**|FF[01223]|  DRS_DATA_WORKING: /apero-data/test_helu/tmp
03:53:40.914-**|FF[01223]|  DRS_CALIB_DB: /apero-data/test_helu/calib
03:53:40.915-**|FF[01223]|  DRS_TELLU_DB: /apero-data/test_helu/tellu
03:53:40.916-**|FF[01223]|  DRS_DATA_ASSETS: /apero-data/test_helu/asset
03:53:40.916-**|FF[01223]|  DRS_DATA_OUT: /apero-data/test_helu/out
03:53:40.916-**|FF[01223]|  DRS_DATA_MSG: /apero-data/test_helu/log
03:53:40.917-**|FF[01223]|  DRS_DATA_RUN: /apero-data/test_helu/run
03:53:40.917-**|FF[01223]|  DRS_DATA_PLOT: /apero-data/test_helu/plot
03:53:40.917-**|FF[01223]|  DRS_DATA_OTHER: /apero-data/test_helu/other
03:53:40.918-**|FF[01223]|  LBL_PATH: /apero-data/test_helu/lbl
03:53:40.918-**|FF[01223]|  DRS_CONFIG: /opt/apero-drs/config/test_helu/user_config.ini
03:53:40.919-**|FF[01223]|  DRS_CONFIG: /opt/apero-drs/config/test_helu/user_constants.ini
03:53:40.919-**|FF[01223]|  DRS_CONFIG: apero.constants.default.default_config
03:53:40.920-**|FF[01223]|  DRS_CONFIG: apero.constants.default.default_keywords
03:53:40.920-**|FF[01223]|  DRS_CONFIG: config.instruments.spirou.default_config.py
03:53:40.920-**|FF[01223]|  DRS_CONFIG: config.instruments.spirou.default_keywords.py
03:53:40.921-**|FF[01223]|  DRS_CONFIG: core.instruments.default.default_constants.py
03:53:40.921-**|FF[01223]|  DRS_CONFIG: core.instruments.spirou.default_constants.py
03:53:40.922-**|FF[01223]|  DATABASE: MYSQL
03:53:40.922-**|FF[01223]|  DATABASE-calib: spirou@pupus-mysql:calib_test_helu_db
03:53:40.922-**|FF[01223]|  DATABASE-tellu: spirou@pupus-mysql:tellu_test_helu_db
03:53:40.923-**|FF[01223]|  DATABASE-findex: spirou@pupus-mysql:findex_test_helu_db
03:53:40.923-**|FF[01223]|  DATABASE-log: spirou@pupus-mysql:log_test_helu_db
03:53:40.923-**|FF[01223]|  DATABASE-astrom: spirou@pupus-mysql:astrom_test_helu_db
03:53:40.924-**|FF[01223]|  DATABASE-lang: spirou@pupus-mysql:lang_test_helu_db
03:53:40.924-**|FF[01223]|  DATABASE-reject: spirou@pupus-mysql:reject_test_helu_db
03:53:40.925-**|FF[01223]|  PRINT_LEVEL: all
03:53:40.925-**|FF[01223]|  LOG_LEVEL: all
03:53:40.926-**|FF[01223]|  DRS_PLOT: 0
03:53:40.931-  |FF[01223]| ***************************************************************************
03:53:40.938-  |FF[01223]|A[40-001-00010]:  System information
03:53:40.939-  |FF[01223]| ***************************************************************************
03:53:40.939-  |FF[01223]|   Python version = '3.9.20'
03:53:40.940-  |FF[01223]|   Distribution date = 'main, Sep  7 2024, 18:35:26'
03:53:40.940-  |FF[01223]|   Other information = 'GCC 9.4.0'
03:53:40.940-  |FF[01223]|   Path = '/usr/bin/python'
03:53:40.941-  |FF[01223]|   Platform = 'linux'
03:53:40.941-  |FF[01223]| Currently installed python modules:
03:53:40.942-  |FF[01223]|  astropy: 5.3  (req==5.3)
03:53:40.942-  |FF[01223]|  astroquery: 0.4.6  (req==0.4.6)
03:53:40.943-  |FF[01223]|  barycorrpy: 0.4.4  (req==0.4.4)
03:53:40.943-  |FF[01223]|  duckdb: 0.8.0  (req==0.8)
03:53:40.944-  |FF[01223]|  matplotlib: 3.7.1  (req==3.7.1)
03:53:40.944-  |FF[01223]|  numba: 0.57.0  (req==0.57.0)
03:53:40.945-  |FF[01223]|  numexpr: 2.8.4  (req==2.8.4)
03:53:40.945-  |FF[01223]|  numpy: 1.24.3  (req==1.24.3)
03:53:40.945-  |FF[01223]|  pandas: 2.0.2  (req==2.0.2)
03:53:40.946-  |FF[01223]|  pandastable: 0.13.1  (req==0.13.1)
03:53:40.947-  |FF[01223]|  psutil: 5.9.4  (req==5.9.4)
03:53:40.947-  |FF[01223]|  scipy: 1.10.0  (req==1.10.0)
03:53:40.948-  |FF[01223]|  tqdm: 4.65.0  (req==4.65.0)
03:53:40.948-  |FF[01223]|  yagmail: 0.15.293  (req==0.15.293)
03:53:40.948-  |FF[01223]|  lbl: 0.63.009 (git+https://github.com/njcuk9999/lbl.git)
03:53:40.949-  |FF[01223]| Raw arguments used:
03:53:40.949-  |FF[01223]|   Arg 1 = 'apero_processing.py'
03:53:40.950-  |FF[01223]| ***************************************************************************
03:53:40.955-**|FF[01223]|I[40-001-00017]: Arguments used:
03:53:40.960-**|FF[01223]|
03:53:40.960-**|FF[01223]|  --OBS_DIR: /apero-data/test_helu/tmp/2020-11-01
03:53:40.961-**|FF[01223]|  --FILES[0]: [DARK_FLAT] 2539860f_pp.fits
03:53:40.961-**|FF[01223]|  --FILES[1]: [DARK_FLAT] 2539861f_pp.fits
03:53:40.962-**|FF[01223]|  --FILES[2]: [DARK_FLAT] 2539862f_pp.fits
03:53:40.962-**|FF[01223]|  --FILES[3]: [DARK_FLAT] 2539863f_pp.fits
03:53:40.963-**|FF[01223]|  --FILES[4]: [DARK_FLAT] 2539864f_pp.fits
03:53:40.963-**|FF[01223]|  --FILES[5]: [FLAT_DARK] 2539865f_pp.fits
03:53:40.963-**|FF[01223]|  --FILES[6]: [FLAT_DARK] 2539866f_pp.fits
03:53:40.964-**|FF[01223]|  --FILES[7]: [FLAT_DARK] 2539867f_pp.fits
03:53:40.964-**|FF[01223]|  --FILES[8]: [FLAT_DARK] 2539868f_pp.fits
03:53:40.965-**|FF[01223]|  --FILES[9]: [FLAT_DARK] 2539869f_pp.fits
03:53:40.965-**|FF[01223]|  --FILES[10]: [FLAT_FLAT] 2539870f_pp.fits
03:53:40.966-**|FF[01223]|  --FILES[11]: [FLAT_FLAT] 2539871f_pp.fits
03:53:40.966-**|FF[01223]|  --FILES[12]: [FLAT_FLAT] 2539872f_pp.fits
03:53:40.967-**|FF[01223]|  --FILES[13]: [FLAT_FLAT] 2539873f_pp.fits
03:53:40.967-**|FF[01223]|  --FILES[14]: [FLAT_FLAT] 2539874f_pp.fits
03:53:40.968-**|FF[01223]|  --FILES[15]: [DARK_FLAT] 2540063f_pp.fits
03:53:40.968-**|FF[01223]|  --FILES[16]: [DARK_FLAT] 2540064f_pp.fits
03:53:40.968-**|FF[01223]|  --FILES[17]: [DARK_FLAT] 2540065f_pp.fits
03:53:40.969-**|FF[01223]|  --FILES[18]: [DARK_FLAT] 2540066f_pp.fits
03:53:40.970-**|FF[01223]|  --FILES[19]: [DARK_FLAT] 2540067f_pp.fits
03:53:40.970-**|FF[01223]|  --FILES[20]: [FLAT_DARK] 2540068f_pp.fits
03:53:40.971-**|FF[01223]|  --FILES[21]: [FLAT_DARK] 2540069f_pp.fits
03:53:40.971-**|FF[01223]|  --FILES[22]: [FLAT_DARK] 2540070f_pp.fits
03:53:40.971-**|FF[01223]|  --FILES[23]: [FLAT_DARK] 2540071f_pp.fits
03:53:40.972-**|FF[01223]|  --FILES[24]: [FLAT_DARK] 2540072f_pp.fits
03:53:40.972-**|FF[01223]|  --FILES[25]: [FLAT_FLAT] 2540073f_pp.fits
03:53:40.972-**|FF[01223]|  --FILES[26]: [FLAT_FLAT] 2540074f_pp.fits
03:53:40.973-**|FF[01223]|  --FILES[27]: [FLAT_FLAT] 2540075f_pp.fits
03:53:40.973-**|FF[01223]|  --FILES[28]: [FLAT_FLAT] 2540076f_pp.fits
03:53:40.973-**|FF[01223]|  --FILES[29]: [FLAT_FLAT] 2540077f_pp.fits
03:53:40.974-**|FF[01223]|  --DATABASE: True
03:53:40.974-**|FF[01223]|  --BADCORR: True
03:53:40.974-**|FF[01223]|  --BACKSUB: True
03:53:40.975-**|FF[01223]|  --COMBINE: True
03:53:40.975-**|FF[01223]|  --DARKCORR: True
03:53:40.976-**|FF[01223]|  --FIBER: ALL
03:53:40.976-**|FF[01223]|  --FLIPIMAGE: both
03:53:40.976-**|FF[01223]|  --FLUXUNITS: e-
03:53:40.977-**|FF[01223]|  --PLOT: 0
03:53:40.977-**|FF[01223]|  --RESIZE: True
03:53:40.978-**|FF[01223]|  --DEBUG: None
03:53:40.978-**|FF[01223]|  --PROGRAM: FF[01223]
03:53:40.978-**|FF[01223]|  --RECIPE_KIND: calib-night
03:53:40.979-**|FF[01223]|  --PARALLEL: True
03:53:40.979-**|FF[01223]|  --SHORTNAME: FF
03:53:40.979-**|FF[01223]|  --IDEBUG: None
03:53:40.980-**|FF[01223]|  --REF: None
03:53:40.980-**|FF[01223]|  --CRUNFILE: mini_run2.ini
03:53:40.980-**|FF[01223]|  --NOSAVE: False
03:53:40.981-**|FF[01223]|  --FORCE_INDIR: None
03:53:40.981-**|FF[01223]|  --FORCE_OUTDIR: None
03:53:40.986-  |FF[01223]| ***************************************************************************
03:53:41.032-  |FF[01223]|A[40-005-10004]: Checking input qc for: files
03:53:41.039-  |FF[01223]|A[40-005-10005]:  All input files files passed QC
03:54:03.223-  |FF[01223]|A[40-999-00004]: Combining files. Math = 'mean'
03:54:05.230-  |FF[01223]|A[40-001-00025]: Writing combined file: /apero-data/test_helu/red/2020-11-01/0824AB920Ff_pp.fits
03:54:05.931-  |FF[01223]| ***************************************************************************
03:54:05.936-  |FF[01223]|A[40-001-00020]: Processing file 1 of 1
03:54:05.941-  |FF[01223]| ***************************************************************************
03:54:06.017-  |FF[01223]|A[40-014-00031]: Reading shape dxmap file: /apero-data/test_helu/calib/3444961B5Da_pp_shapex.fits
03:54:06.115-  |FF[01223]|A[40-014-00032]: Reading shape dymap file: /apero-data/test_helu/calib/3444961B5Da_pp_shapey.fits
03:54:06.159-  |FF[01223]|A[40-005-10003]: Calibration SHAPEL within delta time threshold (0.018998567305970937<7.0 days) 
03:54:06.161-  |FF[01223]|   File: /apero-data/test_helu/calib/EFF1776A90a_pp_shapel.fits
03:54:06.174-  |FF[01223]|A[40-014-00039]: Reading night shape file: /apero-data/test_helu/calib/EFF1776A90a_pp_shapel.fits
03:54:06.230-**|FF[01223]|I[40-014-00038]: Calibrating file: /apero-data/test_helu/red/2020-11-01/0824AB920Ff_pp.fits
03:54:06.349-  |FF[01223]|A[40-011-00011]: Doing dark correction using DARK_FILE: /apero-data/test_helu/calib/2540062d_pp_dark_ref.fits
03:54:06.560-  |FF[01223]|A[40-014-00013]: Image FLAT_FLAT resized from (4096, 4096) to (3100, 4088)
03:54:06.596-  |FF[01223]|A[40-005-10003]: Calibration BADPIX within delta time threshold (0.004838219982048031<7.0 days) 
03:54:06.597-  |FF[01223]|   File: /apero-data/test_helu/calib/D7D1F1D296f_pp_badpixel.fits
03:54:06.659-  |FF[01223]|A[40-012-00008]: Correcting for bad pixels (setting bad pixels to NaN) 
03:54:06.660-  |FF[01223]|   file = /apero-data/test_helu/calib/D7D1F1D296f_pp_badpixel.fits
03:54:06.711-  |FF[01223]|A[40-005-10003]: Calibration BKGRDMAP within delta time threshold (0.004838219982048031<7.0 days) 
03:54:06.712-  |FF[01223]|   File: /apero-data/test_helu/calib/D7D1F1D296f_pp_bmap.fits
03:54:06.718-  |FF[01223]|A[40-012-00010]: Measuring local background using 2D Gaussian Kernel
03:54:07.832-  |FF[01223]|A[40-012-00009]: Correcting for global background using file = /apero-data/test_helu/calib/D7D1F1D296f_pp_bmap.fits
03:54:12.858-  |FF[01223]|A[40-014-00012]: Cleaning FP hot pixels
03:54:12.893-  |FF[01223]|A[40-005-10003]: Calibration BADPIX within delta time threshold (0.004838219982048031<7.0 days) 
03:54:12.900-  |FF[01223]|   File: /apero-data/test_helu/calib/D7D1F1D296f_pp_badpixel.fits
03:54:15.611-**|FF[01223]|I[40-016-00003]: Straightening Order Profile fiber = AB
03:54:37.780-  |FF[01223]|A[40-005-10003]: Calibration ORDER_PROFILE within delta time threshold (1.998705556616187e-08<7.0 days) 
03:54:37.781-  |FF[01223]|   File: /apero-data/test_helu/calib/CAC9BE7219f_pp_order_profile_AB.fits
03:54:38.123-  |FF[01223]|A[40-014-00041]:  Transforming (dxmap=1, dymap=1, trans=1)
03:54:39.983-  |FF[01223]|A[40-013-00024]: Saving order profile to npy file /apero-data/test_helu/red/2020-11-01/EFF1776A90a_pp_shapel_orderps_AB.fits
03:54:40.192-**|FF[01223]|I[40-016-00003]: Straightening Order Profile fiber = A
03:55:11.472-  |FF[01223]|A[40-005-10003]: Calibration ORDER_PROFILE within delta time threshold (1.998705556616187e-08<7.0 days) 
03:55:11.474-  |FF[01223]|   File: /apero-data/test_helu/calib/CAC9BE7219f_pp_order_profile_AB.fits
03:55:11.520-  |FF[01223]|A[40-014-00041]:  Transforming (dxmap=1, dymap=1, trans=1)
03:55:13.370-  |FF[01223]|A[40-013-00024]: Saving order profile to npy file /apero-data/test_helu/red/2020-11-01/EFF1776A90a_pp_shapel_orderps_A.fits
03:55:13.579-**|FF[01223]|I[40-016-00003]: Straightening Order Profile fiber = B
03:55:45.877-  |FF[01223]|A[40-005-10003]: Calibration ORDER_PROFILE within delta time threshold (1.998705556616187e-08<7.0 days) 
03:55:45.879-  |FF[01223]|   File: /apero-data/test_helu/calib/CAC9BE7219f_pp_order_profile_AB.fits
03:55:45.926-  |FF[01223]|A[40-014-00041]:  Transforming (dxmap=1, dymap=1, trans=1)
03:55:47.791-  |FF[01223]|A[40-013-00024]: Saving order profile to npy file /apero-data/test_helu/red/2020-11-01/EFF1776A90a_pp_shapel_orderps_B.fits
03:55:47.994-**|FF[01223]|I[40-016-00003]: Straightening Order Profile fiber = C
03:56:16.251-  |FF[01223]|A[40-005-10003]: Calibration ORDER_PROFILE within delta time threshold (0.0048382400200353<7.0 days) 
03:56:16.252-  |FF[01223]|   File: /apero-data/test_helu/calib/7E17D9AF10f_pp_order_profile_C.fits
03:56:16.634-  |FF[01223]|A[40-014-00041]:  Transforming (dxmap=1, dymap=1, trans=1)
03:56:18.535-  |FF[01223]|A[40-013-00024]: Saving order profile to npy file /apero-data/test_helu/red/2020-11-01/EFF1776A90a_pp_shapel_orderps_C.fits
03:56:18.773-**|FF[01223]|I[40-016-00004]: Straightening Image
03:56:18.778-  |FF[01223]|A[40-014-00041]:  Transforming (dxmap=1, dymap=1, trans=1)
03:56:20.719-  |FF[01223]|A[40-005-10003]: Calibration LOC within delta time threshold (1.998705556616187e-08<7.0 days) 
03:56:20.720-  |FF[01223]|   File: /apero-data/test_helu/calib/CAC9BE7219f_pp_loco_AB.fits
03:56:20.848-  |FF[01223]|A[40-016-00002]: On fiber AB order 0: S/N= 197.8
03:56:20.914-  |FF[01223]|A[40-016-00002]: On fiber AB order 1: S/N= 227.2
03:56:20.980-  |FF[01223]|A[40-016-00002]: On fiber AB order 2: S/N= 256.3
03:56:21.046-  |FF[01223]|A[40-016-00002]: On fiber AB order 3: S/N= 279.3
03:56:21.112-  |FF[01223]|A[40-016-00002]: On fiber AB order 4: S/N= 299.4
03:56:21.178-  |FF[01223]|A[40-016-00002]: On fiber AB order 5: S/N= 316.4
03:56:21.244-  |FF[01223]|A[40-016-00002]: On fiber AB order 6: S/N= 331.5
03:56:21.310-  |FF[01223]|A[40-016-00002]: On fiber AB order 7: S/N= 343.1
03:56:21.382-  |FF[01223]|A[40-016-00002]: On fiber AB order 8: S/N= 354.6
03:56:21.450-  |FF[01223]|A[40-016-00002]: On fiber AB order 9: S/N= 366.0
03:56:21.516-  |FF[01223]|A[40-016-00002]: On fiber AB order 10: S/N= 371.7
03:56:21.591-  |FF[01223]|A[40-016-00002]: On fiber AB order 11: S/N= 379.7
03:56:21.755-  |FF[01223]|A[40-016-00002]: On fiber AB order 12: S/N= 390.4
03:56:21.851-  |FF[01223]|A[40-016-00002]: On fiber AB order 13: S/N= 400.8
03:56:21.940-  |FF[01223]|A[40-016-00002]: On fiber AB order 14: S/N= 411.6
03:56:22.029-  |FF[01223]|A[40-016-00002]: On fiber AB order 15: S/N= 428.8
03:56:22.117-  |FF[01223]|A[40-016-00002]: On fiber AB order 16: S/N= 447.0
03:56:22.195-  |FF[01223]|A[40-016-00002]: On fiber AB order 17: S/N= 464.4
03:56:22.273-  |FF[01223]|A[40-016-00002]: On fiber AB order 18: S/N= 481.5
03:56:22.349-  |FF[01223]|A[40-016-00002]: On fiber AB order 19: S/N= 501.5
03:56:22.421-  |FF[01223]|A[40-016-00002]: On fiber AB order 20: S/N= 523.4
03:56:22.497-  |FF[01223]|A[40-016-00002]: On fiber AB order 21: S/N= 536.0
03:56:22.579-  |FF[01223]|A[40-016-00002]: On fiber AB order 22: S/N= 549.0
03:56:22.657-  |FF[01223]|A[40-016-00002]: On fiber AB order 23: S/N= 559.2
03:56:22.738-  |FF[01223]|A[40-016-00002]: On fiber AB order 24: S/N= 563.4
03:56:22.829-  |FF[01223]|A[40-016-00002]: On fiber AB order 25: S/N= 572.5
03:56:22.913-  |FF[01223]|A[40-016-00002]: On fiber AB order 26: S/N= 592.2
03:56:22.994-  |FF[01223]|A[40-016-00002]: On fiber AB order 27: S/N= 605.7
03:56:23.074-  |FF[01223]|A[40-016-00002]: On fiber AB order 28: S/N= 623.2
03:56:23.158-  |FF[01223]|A[40-016-00002]: On fiber AB order 29: S/N= 637.1
03:56:23.241-  |FF[01223]|A[40-016-00002]: On fiber AB order 30: S/N= 659.7
03:56:23.317-  |FF[01223]|A[40-016-00002]: On fiber AB order 31: S/N= 684.7
03:56:23.396-  |FF[01223]|A[40-016-00002]: On fiber AB order 32: S/N= 708.7
03:56:23.473-  |FF[01223]|A[40-016-00002]: On fiber AB order 33: S/N= 715.2
03:56:23.549-  |FF[01223]|A[40-016-00002]: On fiber AB order 34: S/N= 720.6
03:56:23.625-  |FF[01223]|A[40-016-00002]: On fiber AB order 35: S/N= 733.9
03:56:23.706-  |FF[01223]|A[40-016-00002]: On fiber AB order 36: S/N= 747.1
03:56:23.786-  |FF[01223]|A[40-016-00002]: On fiber AB order 37: S/N= 754.5
03:56:23.865-  |FF[01223]|A[40-016-00002]: On fiber AB order 38: S/N= 763.1
03:56:23.939-  |FF[01223]|A[40-016-00002]: On fiber AB order 39: S/N= 759.8
03:56:24.011-  |FF[01223]|A[40-016-00002]: On fiber AB order 40: S/N= 770.5
03:56:24.086-  |FF[01223]|A[40-016-00002]: On fiber AB order 41: S/N= 783.0
03:56:24.160-  |FF[01223]|A[40-016-00002]: On fiber AB order 42: S/N= 785.1
03:56:24.245-  |FF[01223]|A[40-016-00002]: On fiber AB order 43: S/N= 752.9
03:56:24.339-  |FF[01223]|A[40-016-00002]: On fiber AB order 44: S/N= 695.4
03:56:24.420-  |FF[01223]|A[40-016-00002]: On fiber AB order 45: S/N= 595.3
03:56:24.502-  |FF[01223]|A[40-016-00002]: On fiber AB order 46: S/N= 597.4
03:56:24.577-  |FF[01223]|A[40-016-00002]: On fiber AB order 47: S/N= 522.9
03:56:24.651-  |FF[01223]|A[40-016-00002]: On fiber AB order 48: S/N= 306.0
03:56:24.746-  |FF[01223]|A[40-015-00001]: On fiber AB order 0: S/N= 197.8  - FF rms=0.01 %
03:56:24.782-  |FF[01223]|A[40-015-00001]: On fiber AB order 1: S/N= 227.2  - FF rms=0.01 %
03:56:24.843-  |FF[01223]|A[40-015-00001]: On fiber AB order 2: S/N= 256.3  - FF rms=0.01 %
03:56:24.892-  |FF[01223]|A[40-015-00001]: On fiber AB order 3: S/N= 279.3  - FF rms=0.01 %
03:56:24.943-  |FF[01223]|A[40-015-00001]: On fiber AB order 4: S/N= 299.4  - FF rms=0.01 %
03:56:24.993-  |FF[01223]|A[40-015-00001]: On fiber AB order 5: S/N= 316.4  - FF rms=0.01 %
03:56:25.037-  |FF[01223]|A[40-015-00001]: On fiber AB order 6: S/N= 331.5  - FF rms=0.01 %
03:56:25.082-  |FF[01223]|A[40-015-00001]: On fiber AB order 7: S/N= 343.1  - FF rms=0.01 %
03:56:25.124-  |FF[01223]|A[40-015-00001]: On fiber AB order 8: S/N= 354.6  - FF rms=0.01 %
03:56:25.171-  |FF[01223]|A[40-015-00001]: On fiber AB order 9: S/N= 366.0  - FF rms=0.01 %
03:56:25.216-  |FF[01223]|A[40-015-00001]: On fiber AB order 10: S/N= 371.7  - FF rms=0.01 %
03:56:25.251-  |FF[01223]|A[40-015-00001]: On fiber AB order 11: S/N= 379.7  - FF rms=0.01 %
03:56:25.285-  |FF[01223]|A[40-015-00001]: On fiber AB order 12: S/N= 390.4  - FF rms=0.01 %
03:56:25.329-  |FF[01223]|A[40-015-00001]: On fiber AB order 13: S/N= 400.8  - FF rms=0.01 %
03:56:25.357-  |FF[01223]|A[40-015-00001]: On fiber AB order 14: S/N= 411.6  - FF rms=0.01 %
03:56:25.386-  |FF[01223]|A[40-015-00001]: On fiber AB order 15: S/N= 428.8  - FF rms=0.01 %
03:56:25.446-  |FF[01223]|A[40-015-00001]: On fiber AB order 16: S/N= 447.0  - FF rms=0.01 %
03:56:25.521-  |FF[01223]|A[40-015-00001]: On fiber AB order 17: S/N= 464.4  - FF rms=0.01 %
03:56:25.567-  |FF[01223]|A[40-015-00001]: On fiber AB order 18: S/N= 481.5  - FF rms=0.01 %
03:56:25.599-  |FF[01223]|A[40-015-00001]: On fiber AB order 19: S/N= 501.5  - FF rms=0.01 %
03:56:25.643-  |FF[01223]|A[40-015-00001]: On fiber AB order 20: S/N= 523.4  - FF rms=0.01 %
03:56:25.684-  |FF[01223]|A[40-015-00001]: On fiber AB order 21: S/N= 536.0  - FF rms=0.01 %
03:56:25.733-  |FF[01223]|A[40-015-00001]: On fiber AB order 22: S/N= 549.0  - FF rms=0.01 %
03:56:25.803-  |FF[01223]|A[40-015-00001]: On fiber AB order 23: S/N= 559.2  - FF rms=0.01 %
03:56:25.862-  |FF[01223]|A[40-015-00001]: On fiber AB order 24: S/N= 563.4  - FF rms=0.01 %
03:56:25.944-  |FF[01223]|A[40-015-00001]: On fiber AB order 25: S/N= 572.5  - FF rms=0.01 %
03:56:26.012-  |FF[01223]|A[40-015-00001]: On fiber AB order 26: S/N= 592.2  - FF rms=0.01 %
03:56:26.102-  |FF[01223]|A[40-015-00001]: On fiber AB order 27: S/N= 605.7  - FF rms=0.01 %
03:56:26.150-  |FF[01223]|A[40-015-00001]: On fiber AB order 28: S/N= 623.2  - FF rms=0.01 %
03:56:26.264-  |FF[01223]|A[40-015-00001]: On fiber AB order 29: S/N= 637.1  - FF rms=0.01 %
03:56:26.316-  |FF[01223]|A[40-015-00001]: On fiber AB order 30: S/N= 659.7  - FF rms=0.01 %
03:56:26.411-  |FF[01223]|A[40-015-00001]: On fiber AB order 31: S/N= 684.7  - FF rms=0.01 %
03:56:26.468-  |FF[01223]|A[40-015-00001]: On fiber AB order 32: S/N= 708.7  - FF rms=0.01 %
03:56:26.503-  |FF[01223]|A[40-015-00001]: On fiber AB order 33: S/N= 715.2  - FF rms=0.01 %
03:56:26.576-  |FF[01223]|A[40-015-00001]: On fiber AB order 34: S/N= 720.6  - FF rms=0.01 %
03:56:26.650-  |FF[01223]|A[40-015-00001]: On fiber AB order 35: S/N= 733.9  - FF rms=0.01 %
03:56:26.699-  |FF[01223]|A[40-015-00001]: On fiber AB order 36: S/N= 747.1  - FF rms=0.01 %
03:56:26.727-  |FF[01223]|A[40-015-00001]: On fiber AB order 37: S/N= 754.5  - FF rms=0.01 %
03:56:26.833-  |FF[01223]|A[40-015-00001]: On fiber AB order 38: S/N= 763.1  - FF rms=0.01 %
03:56:26.977-  |FF[01223]|A[40-015-00001]: On fiber AB order 39: S/N= 759.8  - FF rms=0.01 %
03:56:27.035-  |FF[01223]|A[40-015-00001]: On fiber AB order 40: S/N= 770.5  - FF rms=0.01 %
03:56:27.159-  |FF[01223]|A[40-015-00001]: On fiber AB order 41: S/N= 783.0  - FF rms=0.01 %
03:56:27.205-  |FF[01223]|A[40-015-00001]: On fiber AB order 42: S/N= 785.1  - FF rms=0.01 %
03:56:27.290-  |FF[01223]|A[40-015-00001]: On fiber AB order 43: S/N= 752.9  - FF rms=0.01 %
03:56:27.362-  |FF[01223]|A[40-015-00001]: On fiber AB order 44: S/N= 695.4  - FF rms=0.01 %
03:56:27.415-  |FF[01223]|A[40-015-00001]: On fiber AB order 45: S/N= 595.3  - FF rms=0.02 %
03:56:27.465-  |FF[01223]|A[40-015-00001]: On fiber AB order 46: S/N= 597.4  - FF rms=0.01 %
03:56:27.513-  |FF[01223]|A[40-015-00001]: On fiber AB order 47: S/N= 522.9  - FF rms=0.01 %
03:56:27.567-  |FF[01223]|A[40-015-00001]: On fiber AB order 48: S/N= 306.0  - FF rms=0.06 %
03:56:27.593-**|FF[01223]|I[40-005-10001]: QUALITY CONTROL SUCCESSFUL - Well Done -
03:56:27.635-  |FF[01223]|A[40-015-00003]: Saving blaze file: /apero-data/test_helu/red/2020-11-01/0824AB920Ff_pp_blaze_AB.fits
03:56:27.718-  |FF[01223]|A[40-015-00004]: Saving flat file: /apero-data/test_helu/red/2020-11-01/0824AB920Ff_pp_flat_AB.fits
03:56:27.788-  |FF[01223]|A[40-015-00005]: Saving E2DSLL file: /apero-data/test_helu/red/2020-11-01/DEBUG_0824AB920Ff_pp_e2dsll_AB.fits
03:56:28.412-  |FF[01223]|A[40-006-00004]: calibration: Copy to database successful. File = /apero-data/test_helu/calib/0824AB920Ff_pp_blaze_AB.fits
03:56:28.585-  |FF[01223]|A[40-006-00004]: calibration: Copy to database successful. File = /apero-data/test_helu/calib/0824AB920Ff_pp_flat_AB.fits
03:56:28.848-  |FF[01223]|A[40-005-10003]: Calibration LOC within delta time threshold (1.998705556616187e-08<7.0 days) 
03:56:28.848-  |FF[01223]|   File: /apero-data/test_helu/calib/CAC9BE7219f_pp_loco_AB.fits
03:56:28.952-  |FF[01223]|A[40-016-00002]: On fiber A order 0: S/N= 138.7
03:56:29.023-  |FF[01223]|A[40-016-00002]: On fiber A order 1: S/N= 159.6
03:56:29.106-  |FF[01223]|A[40-016-00002]: On fiber A order 2: S/N= 178.8
03:56:29.188-  |FF[01223]|A[40-016-00002]: On fiber A order 3: S/N= 195.3
03:56:29.255-  |FF[01223]|A[40-016-00002]: On fiber A order 4: S/N= 209.0
03:56:29.321-  |FF[01223]|A[40-016-00002]: On fiber A order 5: S/N= 220.8
03:56:29.386-  |FF[01223]|A[40-016-00002]: On fiber A order 6: S/N= 231.1
03:56:29.450-  |FF[01223]|A[40-016-00002]: On fiber A order 7: S/N= 239.3
03:56:29.514-  |FF[01223]|A[40-016-00002]: On fiber A order 8: S/N= 247.5
03:56:29.580-  |FF[01223]|A[40-016-00002]: On fiber A order 9: S/N= 255.4
03:56:29.644-  |FF[01223]|A[40-016-00002]: On fiber A order 10: S/N= 259.9
03:56:29.709-  |FF[01223]|A[40-016-00002]: On fiber A order 11: S/N= 265.8
03:56:29.780-  |FF[01223]|A[40-016-00002]: On fiber A order 12: S/N= 273.2
03:56:29.845-  |FF[01223]|A[40-016-00002]: On fiber A order 13: S/N= 280.5
03:56:29.910-  |FF[01223]|A[40-016-00002]: On fiber A order 14: S/N= 286.7
03:56:29.975-  |FF[01223]|A[40-016-00002]: On fiber A order 15: S/N= 299.8
03:56:30.041-  |FF[01223]|A[40-016-00002]: On fiber A order 16: S/N= 311.4
03:56:30.106-  |FF[01223]|A[40-016-00002]: On fiber A order 17: S/N= 323.7
03:56:30.171-  |FF[01223]|A[40-016-00002]: On fiber A order 18: S/N= 335.5
03:56:30.236-  |FF[01223]|A[40-016-00002]: On fiber A order 19: S/N= 349.1
03:56:30.302-  |FF[01223]|A[40-016-00002]: On fiber A order 20: S/N= 364.3
03:56:30.367-  |FF[01223]|A[40-016-00002]: On fiber A order 21: S/N= 373.6
03:56:30.433-  |FF[01223]|A[40-016-00002]: On fiber A order 22: S/N= 381.0
03:56:30.498-  |FF[01223]|A[40-016-00002]: On fiber A order 23: S/N= 390.5
03:56:30.563-  |FF[01223]|A[40-016-00002]: On fiber A order 24: S/N= 392.3
03:56:30.627-  |FF[01223]|A[40-016-00002]: On fiber A order 25: S/N= 397.8
03:56:30.691-  |FF[01223]|A[40-016-00002]: On fiber A order 26: S/N= 411.4
03:56:30.756-  |FF[01223]|A[40-016-00002]: On fiber A order 27: S/N= 422.9
03:56:30.820-  |FF[01223]|A[40-016-00002]: On fiber A order 28: S/N= 434.3
03:56:30.885-  |FF[01223]|A[40-016-00002]: On fiber A order 29: S/N= 443.5
03:56:30.949-  |FF[01223]|A[40-016-00002]: On fiber A order 30: S/N= 458.1
03:56:31.014-  |FF[01223]|A[40-016-00002]: On fiber A order 31: S/N= 476.2
03:56:31.080-  |FF[01223]|A[40-016-00002]: On fiber A order 32: S/N= 493.4
03:56:31.145-  |FF[01223]|A[40-016-00002]: On fiber A order 33: S/N= 498.6
03:56:31.215-  |FF[01223]|A[40-016-00002]: On fiber A order 34: S/N= 499.6
03:56:31.279-  |FF[01223]|A[40-016-00002]: On fiber A order 35: S/N= 511.4
03:56:31.346-  |FF[01223]|A[40-016-00002]: On fiber A order 36: S/N= 521.6
03:56:31.413-  |FF[01223]|A[40-016-00002]: On fiber A order 37: S/N= 525.2
03:56:31.477-  |FF[01223]|A[40-016-00002]: On fiber A order 38: S/N= 531.8
03:56:31.543-  |FF[01223]|A[40-016-00002]: On fiber A order 39: S/N= 528.9
03:56:31.611-  |FF[01223]|A[40-016-00002]: On fiber A order 40: S/N= 538.3
03:56:31.678-  |FF[01223]|A[40-016-00002]: On fiber A order 41: S/N= 545.7
03:56:31.743-  |FF[01223]|A[40-016-00002]: On fiber A order 42: S/N= 548.1
03:56:31.809-  |FF[01223]|A[40-016-00002]: On fiber A order 43: S/N= 526.6
03:56:31.877-  |FF[01223]|A[40-016-00002]: On fiber A order 44: S/N= 484.0
03:56:31.941-  |FF[01223]|A[40-016-00002]: On fiber A order 45: S/N= 415.6
03:56:32.006-  |FF[01223]|A[40-016-00002]: On fiber A order 46: S/N= 420.1
03:56:32.070-  |FF[01223]|A[40-016-00002]: On fiber A order 47: S/N= 365.8
03:56:32.135-  |FF[01223]|A[40-016-00002]: On fiber A order 48: S/N= 211.6
03:56:32.221-  |FF[01223]|A[40-015-00001]: On fiber A order 0: S/N= 138.7  - FF rms=0.01 %
03:56:32.257-  |FF[01223]|A[40-015-00001]: On fiber A order 1: S/N= 159.6  - FF rms=0.01 %
03:56:32.311-  |FF[01223]|A[40-015-00001]: On fiber A order 2: S/N= 178.8  - FF rms=0.02 %
03:56:32.358-  |FF[01223]|A[40-015-00001]: On fiber A order 3: S/N= 195.3  - FF rms=0.01 %
03:56:32.406-  |FF[01223]|A[40-015-00001]: On fiber A order 4: S/N= 209.0  - FF rms=0.01 %
03:56:32.477-  |FF[01223]|A[40-015-00001]: On fiber A order 5: S/N= 220.8  - FF rms=0.01 %
03:56:32.556-  |FF[01223]|A[40-015-00001]: On fiber A order 6: S/N= 231.1  - FF rms=0.01 %
03:56:32.593-  |FF[01223]|A[40-015-00001]: On fiber A order 7: S/N= 239.3  - FF rms=0.01 %
03:56:32.629-  |FF[01223]|A[40-015-00001]: On fiber A order 8: S/N= 247.5  - FF rms=0.01 %
03:56:32.680-  |FF[01223]|A[40-015-00001]: On fiber A order 9: S/N= 255.4  - FF rms=0.01 %
03:56:32.709-  |FF[01223]|A[40-015-00001]: On fiber A order 10: S/N= 259.9  - FF rms=0.01 %
03:56:32.754-  |FF[01223]|A[40-015-00001]: On fiber A order 11: S/N= 265.8  - FF rms=0.01 %
03:56:32.805-  |FF[01223]|A[40-015-00001]: On fiber A order 12: S/N= 273.2  - FF rms=0.01 %
03:56:32.840-  |FF[01223]|A[40-015-00001]: On fiber A order 13: S/N= 280.5  - FF rms=0.01 %
03:56:32.905-  |FF[01223]|A[40-015-00001]: On fiber A order 14: S/N= 286.7  - FF rms=0.01 %
03:56:32.978-  |FF[01223]|A[40-015-00001]: On fiber A order 15: S/N= 299.8  - FF rms=0.01 %
03:56:33.022-  |FF[01223]|A[40-015-00001]: On fiber A order 16: S/N= 311.4  - FF rms=0.01 %
03:56:33.079-  |FF[01223]|A[40-015-00001]: On fiber A order 17: S/N= 323.7  - FF rms=0.01 %
03:56:33.108-  |FF[01223]|A[40-015-00001]: On fiber A order 18: S/N= 335.5  - FF rms=0.01 %
03:56:33.140-  |FF[01223]|A[40-015-00001]: On fiber A order 19: S/N= 349.1  - FF rms=0.01 %
03:56:33.174-  |FF[01223]|A[40-015-00001]: On fiber A order 20: S/N= 364.3  - FF rms=0.01 %
03:56:33.226-  |FF[01223]|A[40-015-00001]: On fiber A order 21: S/N= 373.6  - FF rms=0.01 %
03:56:33.265-  |FF[01223]|A[40-015-00001]: On fiber A order 22: S/N= 381.0  - FF rms=0.01 %
03:56:33.327-  |FF[01223]|A[40-015-00001]: On fiber A order 23: S/N= 390.5  - FF rms=0.01 %
03:56:33.387-  |FF[01223]|A[40-015-00001]: On fiber A order 24: S/N= 392.3  - FF rms=0.01 %
03:56:33.457-  |FF[01223]|A[40-015-00001]: On fiber A order 25: S/N= 397.8  - FF rms=0.01 %
03:56:33.558-  |FF[01223]|A[40-015-00001]: On fiber A order 26: S/N= 411.4  - FF rms=0.01 %
03:56:33.621-  |FF[01223]|A[40-015-00001]: On fiber A order 27: S/N= 422.9  - FF rms=0.01 %
03:56:33.664-  |FF[01223]|A[40-015-00001]: On fiber A order 28: S/N= 434.3  - FF rms=0.01 %
03:56:33.710-  |FF[01223]|A[40-015-00001]: On fiber A order 29: S/N= 443.5  - FF rms=0.01 %
03:56:33.765-  |FF[01223]|A[40-015-00001]: On fiber A order 30: S/N= 458.1  - FF rms=0.01 %
03:56:33.863-  |FF[01223]|A[40-015-00001]: On fiber A order 31: S/N= 476.2  - FF rms=0.01 %
03:56:33.912-  |FF[01223]|A[40-015-00001]: On fiber A order 32: S/N= 493.4  - FF rms=0.01 %
03:56:33.953-  |FF[01223]|A[40-015-00001]: On fiber A order 33: S/N= 498.6  - FF rms=0.01 %
03:56:33.989-  |FF[01223]|A[40-015-00001]: On fiber A order 34: S/N= 499.6  - FF rms=0.01 %
03:56:34.057-  |FF[01223]|A[40-015-00001]: On fiber A order 35: S/N= 511.4  - FF rms=0.02 %
03:56:34.110-  |FF[01223]|A[40-015-00001]: On fiber A order 36: S/N= 521.6  - FF rms=0.01 %
03:56:34.142-  |FF[01223]|A[40-015-00001]: On fiber A order 37: S/N= 525.2  - FF rms=0.02 %
03:56:34.245-  |FF[01223]|A[40-015-00001]: On fiber A order 38: S/N= 531.8  - FF rms=0.01 %
03:56:34.363-  |FF[01223]|A[40-015-00001]: On fiber A order 39: S/N= 528.9  - FF rms=0.01 %
03:56:34.418-  |FF[01223]|A[40-015-00001]: On fiber A order 40: S/N= 538.3  - FF rms=0.01 %
03:56:34.553-  |FF[01223]|A[40-015-00001]: On fiber A order 41: S/N= 545.7  - FF rms=0.01 %
03:56:34.669-  |FF[01223]|A[40-015-00001]: On fiber A order 42: S/N= 548.1  - FF rms=0.01 %
03:56:34.766-  |FF[01223]|A[40-015-00001]: On fiber A order 43: S/N= 526.6  - FF rms=0.01 %
03:56:34.869-  |FF[01223]|A[40-015-00001]: On fiber A order 44: S/N= 484.0  - FF rms=0.01 %
03:56:37.855-@$|FF[01223]|W[10-015-00001]: Sinc curve fit failed. Trying again. Tries = 0
03:56:40.809-@$|FF[01223]|W[10-015-00001]: Sinc curve fit failed. Trying again. Tries = 1
03:56:43.739-@$|FF[01223]|W[10-015-00001]: Sinc curve fit failed. Trying again. Tries = 2
03:56:46.724-@$|FF[01223]|W[10-015-00001]: Sinc curve fit failed. Trying again. Tries = 3
03:56:49.663-@$|FF[01223]|W[10-015-00001]: Sinc curve fit failed. Trying again. Tries = 4
03:56:49.669-!!|FF[01223]|E[40-015-00009]: Error fitting sinc to blaze. Order = 45 Fiber = A Iteration = -1 
03:56:49.669-!!|FF[01223]|   Guess: amp=191774.0009571721 period=7034.0 lin=1205.0 slope=0 quad=0 (cube=0) 
03:56:49.670-!!|FF[01223]|   Lower: amp=0 period=0.0 lin=0.0 slope=-inf quad=-inf (cube=-1e-20) 
03:56:49.670-!!|FF[01223]|   Upper: amp=287661.00143575814 period=inf lin=4087 slope=inf quad=inf (cube=1e-20) 
03:56:49.671-!!|FF[01223]|   Error <class 'RuntimeError'>: Optimal parameters not found: Number of calls to function has reached maxfev = 1200. 
03:56:49.671-!!|FF[01223]|   Function = science.extract.extraction.py.calculate_blaze_flat_sinc()
03:56:49.678-!!|FF[01223]|Traceback (most recent call last):
03:56:49.679-!!|FF[01223]|  File "/opt/apero-drs/apero/science/calib/flat_blaze.py", line 143, in calculate_blaze_flat_sinc
03:56:49.679-!!|FF[01223]|    popt, pcov = curve_fit(mp.sinc, xpix[keep], e2ds[keep],
03:56:49.680-!!|FF[01223]|  File "/usr/local/lib/python3.9/dist-packages/scipy/optimize/_minpack_py.py", line 874, in curve_fit
03:56:49.681-!!|FF[01223]|    raise RuntimeError("Optimal parameters not found: " + res.message)
03:56:49.684-!!|FF[01223]|RuntimeError: Optimal parameters not found: The maximum number of function evaluations is exceeded.
03:56:49.691-!!|FF[01223]|
03:56:49.698-!!|FF[01223]|During handling of the above exception, another exception occurred:
03:56:49.704-!!|FF[01223]|
03:56:49.704-!!|FF[01223]|Traceback (most recent call last):
03:56:49.705-!!|FF[01223]|  File "/opt/apero-drs/apero/science/calib/flat_blaze.py", line 156, in calculate_blaze_flat_sinc
03:56:49.705-!!|FF[01223]|    popt, pcov = curve_fit(mp.sinc, xpix[keep], e2ds[keep],
03:56:49.706-!!|FF[01223]|  File "/usr/local/lib/python3.9/dist-packages/scipy/optimize/_minpack_py.py", line 864, in curve_fit
03:56:49.706-!!|FF[01223]|    raise RuntimeError("Optimal parameters not found: " + errmsg)
03:56:49.707-!!|FF[01223]|RuntimeError: Optimal parameters not found: Number of calls to function has reached maxfev = 1400.
03:56:49.707-!!|FF[01223]|
03:56:49.708-!!|FF[01223]|During handling of the above exception, another exception occurred:
03:56:49.709-!!|FF[01223]|
03:56:49.709-!!|FF[01223]|Traceback (most recent call last):
03:56:49.709-!!|FF[01223]|  File "/opt/apero-drs/apero/science/calib/flat_blaze.py", line 170, in calculate_blaze_flat_sinc
03:56:49.710-!!|FF[01223]|    popt, pcov = curve_fit(mp.sinc, xpix[keep], e2ds[keep],
03:56:49.710-!!|FF[01223]|  File "/usr/local/lib/python3.9/dist-packages/scipy/optimize/_minpack_py.py", line 864, in curve_fit
03:56:49.711-!!|FF[01223]|    raise RuntimeError("Optimal parameters not found: " + errmsg)
03:56:49.711-!!|FF[01223]|RuntimeError: Optimal parameters not found: Number of calls to function has reached maxfev = 1200.
03:56:49.712-!!|FF[01223]|
03:56:49.713-!!|FF[01223]|During handling of the above exception, another exception occurred:
03:56:49.713-!!|FF[01223]|
03:56:49.713-!!|FF[01223]|Traceback (most recent call last):
03:56:49.714-!!|FF[01223]|  File "/opt/apero-drs/apero/core/utils/drs_startup.py", line 433, in run
03:56:49.714-!!|FF[01223]|    llmain = func(recipe, params)
03:56:49.715-!!|FF[01223]|  File "/opt/apero-drs/apero/recipes/spirou/apero_flat_spirou.py", line 213, in __main__
03:56:49.715-!!|FF[01223]|    eprops = extract.extract_blaze_flat(params, eprops, fiber)
03:56:49.715-!!|FF[01223]|  File "/opt/apero-drs/apero/science/extract/extraction.py", line 237, in extract_blaze_flat
03:56:49.716-!!|FF[01223]|    fout = flat_blaze.calculate_blaze_flat_sinc(params, *fargs)
03:56:49.716-!!|FF[01223]|  File "/opt/apero-drs/apero/science/calib/flat_blaze.py", line 190, in calculate_blaze_flat_sinc
03:56:49.717-!!|FF[01223]|    WLOG(params, 'error', emsg)
03:56:49.717-!!|FF[01223]|  File "/opt/apero-drs/apero/core/core/drs_log.py", line 428, in __call__
03:56:49.718-!!|FF[01223]|    raise drs_exceptions.LogExit(errorstring)
03:56:49.718-!!|FF[01223]|apero.core.core.drs_exceptions.LogExit: E[40-015-00009]: Error fitting sinc to blaze. Order = 45 Fiber = A Iteration = -1 
03:56:49.719-!!|FF[01223]|   Guess: amp=191774.0009571721 period=7034.0 lin=1205.0 slope=0 quad=0 (cube=0) 
03:56:49.719-!!|FF[01223]|   Lower: amp=0 period=0.0 lin=0.0 slope=-inf quad=-inf (cube=-1e-20) 
03:56:49.720-!!|FF[01223]|   Upper: amp=287661.00143575814 period=inf lin=4087 slope=inf quad=inf (cube=1e-20) 
03:56:49.720-!!|FF[01223]|   Error <class 'RuntimeError'>: Optimal parameters not found: Number of calls to function has reached maxfev = 1200. 
03:56:49.721-!!|FF[01223]|   Function = science.extract.extraction.py.calculate_blaze_flat_sinc()
03:56:49.721-!!|FF[01223]|
03:56:49.721-!!|FF[01223]|
03:56:50.019-**|FF[01223]| ***************************************************************************
03:56:50.028-@!|FF[01223]|W[40-003-00005]: Recipe apero_flat_spirou has NOT been successfully completed
03:56:50.038-**|FF[01223]| ***************************************************************************```
clairem789 commented 2 months ago

hi Luc, No I didn't see any error. I also got QCC_ALL == T for all files produced for 0824AB920Ff* (also for fiber A) Not sure how I can help you find out...

njcuk9999 commented 2 months ago

So all these errors are due to the apero_flat error that you posted:

 E[40-015-00009]: Error fitting sinc to blaze. Order = 45 Fiber = A Iteration =
    -1
 Guess: amp=191774.0009571721 period=7034.0 lin=1205.0 slope=0 quad=0 (cube=0)
     Lower: amp=0 period=0.0 lin=0.0 slope=-inf quad=-inf (cube=-1e-20) 
 Upper: amp=287661.00143575814 period=inf lin=4087 slope=inf quad=inf
    (cube=1e-20)
 Error <class 'RuntimeError'>: Optimal parameters not found: Number of calls to
    function has reached maxfev = 1200.

And whats failing is the curve_fit function (which we've all seen fail at some point in different places).... it seems complete non-reproducible:

03:56:49.718-!!|FF[01223]|apero.core.core.drs_exceptions.LogExit: E[40-015-00009]: Error fitting sinc to blaze. Order = 45 Fiber = A Iteration = -1 
03:56:49.719-!!|FF[01223]|   Guess: amp=191774.0009571721 period=7034.0 lin=1205.0 slope=0 quad=0 (cube=0) 
03:56:49.719-!!|FF[01223]|   Lower: amp=0 period=0.0 lin=0.0 slope=-inf quad=-inf (cube=-1e-20) 
03:56:49.720-!!|FF[01223]|   Upper: amp=287661.00143575814 period=inf lin=4087 slope=inf quad=inf (cube=1e-20) 
03:56:49.720-!!|FF[01223]|   Error <class 'RuntimeError'>: Optimal parameters not found: Number of calls to function has reached maxfev = 1200. 
03:56:49.721-!!|FF[01223]|   Function = science.extract.extraction.py.calculate_blaze_flat_sinc()

I did add a loop where it simply tries again, but seems in your case this failed too (several times):

03:56:37.855-@$|FF[01223]|W[10-015-00001]: Sinc curve fit failed. Trying again. Tries = 0
03:56:40.809-@$|FF[01223]|W[10-015-00001]: Sinc curve fit failed. Trying again. Tries = 1
03:56:43.739-@$|FF[01223]|W[10-015-00001]: Sinc curve fit failed. Trying again. Tries = 2
03:56:46.724-@$|FF[01223]|W[10-015-00001]: Sinc curve fit failed. Trying again. Tries = 3
03:56:49.663-@$|FF[01223]|W[10-015-00001]: Sinc curve fit failed. Trying again. Tries = 4
03:56:49.669-!!|FF[01223]|E[40-015-00009]: Error fitting sinc to blaze. Order = 45 Fiber = A Iteration = -1 
03:56:49.669-!!|FF[01223]|   Guess: amp=191774.0009571721 period=7034.0 lin=1205.0 slope=0 quad=0 (cube=0) 
03:56:49.670-!!|FF[01223]|   Lower: amp=0 period=0.0 lin=0.0 slope=-inf quad=-inf (cube=-1e-20) 
03:56:49.670-!!|FF[01223]|   Upper: amp=287661.00143575814 period=inf lin=4087 slope=inf quad=inf (cube=1e-20) 
03:56:49.671-!!|FF[01223]|   Error <class 'RuntimeError'>: Optimal parameters not found: Number of calls to function has reached maxfev = 1200. 
03:56:49.671-!!|FF[01223]|   Function = science.extract.extraction.py.calculate_blaze_flat_sinc()

There's not much I can do to fix this - maybe someone needs to find a new function to replace curve_fit because I haven't changed anything with this function for v0.7.290 or the inputs (no change to pp data and that is all that comes in!).

The line of code is as follows:

from scipy.optimize import curve_fit

# we optimize over pixels that are not NaN (this time with
#    no bounds)
popt, pcov = curve_fit(sinc_func, xpix[keep], e2ds[keep], p0=fit_guess1)

where:

import numpy as np

def sinc_func(x: np.ndarray, amp: float, period: float, lin_center: float,
         slope: float, quad_scale: float = 0.0, cube_scale: float = 0.0,
         peak_cut: float = 0.0) -> np.ndarray:
    """
    Calculates the sinc function with a slope (and position threshold cut)

    y = A * (sin(x)/x)^2 * (1 + C*x)

    x = 2*pi*(X - dx + q2*dx^2 + q3*dx^3) / P

    where X is a position along the x pixel axis. This assumes
    that the blaze follows an airy pattern and that there may be a slope
    to the spectral energy distribution.

    if peak_cut is non-zero:
        y < A * peak_cut = NaN

    :param x: numpy array (1D), the x position vector y (X)
    :param amp: float, the amplitude of the sinc function (A)
    :param period: float, the period of the sinc function (P)
    :param lin_center: float, the linear center of the sinc (dx)
    :param quad_scale: float, the quad scale of the sinc (q2)
    :param cube_scale: float, the cubic scale of the sinc (q3)
    :param slope: the slope of the sinc function (C)
    :param peak_cut: float, if non-zero if the threshold below the maximum
                     amplitude to set to NaNs

    :type x: np.ndarray
    :type amp: float
    :type period: float
    :type lin_center: float
    :type quad_scale: float
    :type cube_scale: float
    :type slope: float
    :type peak_cut: float

    :return: the sinc function (with a slope) and if peak_cut non-zero NaN
             filled before this fraction of the sinc max amplitude
    :rtype: np.ndarray
    """
    # set function name
    # _ = display_func('sinc', __NAME__)
    # Transform the x expressed in pixels into a stretched version
    # expressed in phase. The quadratic terms allows for a variation of
    # dispersion along the other
    deltax = x - lin_center
    cent = deltax + quad_scale * deltax ** 2 + cube_scale * deltax ** 3
    xp = 2 * np.pi * (cent / period)
    # this avoids a division by zero
    if np.min(np.abs(xp) / period) < 1e-9:
        small_x = (np.abs(xp) / period) < 1e-9
        xp[small_x] = 1e-9
    # calculate the sinc function
    yy = amp * (np.sin(xp) / xp) ** 2
    # if we set a peak_cut threshold then values below that fraction of the
    # peak sinc value are set to NaN.
    if peak_cut != 0:
        yy[yy < (peak_cut * amp)] = np.nan
    # multiplicative slope in the SED
    yy *= (1 + slope * (x - lin_center))
    # return the adjusted yy
    return yy

So yep I'm pretty stuck on how to "fix" this, short of someone finding another optimized fitting function as if this fails you can't reduce the data (especially for the "reference" night as it did here).

The only thing I can say @larnoldgithub is to try resetting all of the mini data and re-running.

larnoldgithub commented 2 months ago

I actually got the error twice over the week end, posted the error after the second trial.

I never saw the fitting error before with the minidata2. For the 2 tests this week-end, the installation reset the folders but the run/ and raw/, so I'm not sure resetting and running a third trial will work. Im still going to try!

larnoldgithub commented 2 months ago

I didn't look into the details, but why assinging xp[small_x] = 1e-9 before calculating the sinc rather than just skipping that x value (assinging NaN)? with xp[small_x] forced to 1e-9, we end with 0.01 values for sinc which the fit eventually can't manage?

njcuk9999 commented 2 months ago

I don't believe you can assign a NaN in the curve fit - it leads to a crash. @eartigau wrote this function and as it says I believe it is just to stop the vector xp = 2 * np.pi * (cent / period) having a zero (or negative value) and crashing that way. Note that xp is a vector so the whole vector doesn't get forced to 1e-9 just very small, zero or negative values.

I never saw the fitting error before with the minidata2.

I have never seen it with the minidata or minidata2 either - nothing has changed in that code for a long time so I don't understand why you are having this problem now and that no one else is having the problem.

I'll try to get @eartigau to look into this.

larnoldgithub commented 2 months ago

third test: full reset but asset/ raw/ and run/ error again, exact same.

larnoldgithub commented 2 months ago

if I just run the command

''' apero_flat_spirou.py 2020-11-01 2539860f_pp.fits 2539861f_pp.fits 2539862f_pp.fits 2539863f_pp.fits 2539864f_pp.fits 2539865f_pp.fits 2539866f_pp.fits 2539867f_pp.fits 2539868f_pp.fits 2539869f_pp.fits 2539870f_pp.fits 2539871f_pp.fits 2539872f_pp.fits 2539873f_pp.fits 2539874f_pp.fits 2540063f_pp.fits 2540064f_pp.fits 2540065f_pp.fits 2540066f_pp.fits 2540067f_pp.fits 2540068f_pp.fits 2540069f_pp.fits 2540070f_pp.fits 2540071f_pp.fits 2540072f_pp.fits 2540073f_pp.fits 2540074f_pp.fits 2540075f_pp.fits 2540076f_pp.fits 2540077f_pp.fits --crunfile=mini_run2.ini --program=FF[01223] --recipe_kind=calib-night --shortname=FF --parallel=True''' it works, no errors.

larnoldgithub commented 2 months ago

I'm going to reprocess the minidata2, skipping the PP and calibs processing up to FF. I'm redoing everything after FF. I have reset the lbl/ only for that new test.

njcuk9999 commented 2 months ago

There is no difference to running it in apero_processing or like this so that is very strange.

You can run that one file with plots on (see the --help) to see if the fit is good.

All I can imagine is that it is an edge case that is on your system most the time failing and some times passing but this is bizarre as it should be the same each time.

larnoldgithub commented 2 months ago

the machine is a VM running Ubuntu 24.04 LTS (GNU/Linux 6.8.0-36-generic x86_64)