njcuk9999 / apero-drs

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

Errors after EXTALL: mysql.connector.errors.DatabaseError, slightly different than #717 (0.7.286) #718

Open larnoldgithub opened 1 year ago

larnoldgithub commented 1 year ago

slightly different log than previous reported issue #717, but likely the same problem with MySQL


15:43:43.956- |PROC| 15:43:43.974-@!|PROC| W[40-503-00019]: Error found for ID='50270' 15:43:43.990-@!|PROC| apero_extract_spirou.py 19BQ10-Nov12 2457191o_pp.fits --crunfile=run_EXTALL_only.ini --program=EXTALL[50270] --recipe_kind=extract-ALL --shortname=EXTALL --parallel=True 15:43:44.007- |PROC| 15:43:44.024- |PROC| Unexpected error occurred in run '50270'

Database Error: 20:07:15.647-**|DatabaseError|E[00-002-00032] <class 'mysql.connector.errors.DatabaseError'>: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

     Command: INSERT INTO log_offline_db VALUES("apero_extract_spirou", "EXTALL", "red", "recipe", "extract-ALL", "EXTALL[50270]", "PID-00016939441156608770-34K9", "2023-09-05 20:01:55.661", "1693944115.661", "APEROG-PID-00016934391638252470-QNB4_apero_processing_group", 2, 0, "num=0 fiber=C ", "/data/spirou4/apero-data/offline/tmp", "/data/spirou4/apero-data/offline/reduced", "19BQ10-Nov12", "/data/spirou4/apero-data/offline/msg/processing/APEROG-PID-00016934391638252470-QNB4_apero_processing_group/19BQ10-Nov12/APEROL-PID-00016939441156608770-34K9_apero_extract_spirou.log", "/data/spirou4/apero-data/offline/plot/19BQ10-Nov12/pid-00016939441156608770-34k9_apero_extract_spirou_1", "apero_extract_spirou.py 19BQ10-Nov12 2457191o_pp.fits --quicklook=False --badcorr=True --backsub=True --combine=False --combine_method=sum --darkcorr=True --fiber=ALL --flipimage=both --fluxunits=e- --plot=0 --resize=True --leakcorr=True --thermal=True --force_ref_wave=False --no_in_qc=False --program=EXTALL[50270] --recipe_kind=extract-ALL --parallel=True --shortname=EXTALL --crunfile=run_EXTALL_only.ini --nosave=False ", "obs_dir=19BQ10-Nov12 || files[1]=/data/spirou4/apero-data/offline/tmp/19BQ10-Nov12/2457191o_pp.fits [DRS_PP]", "--quicklook=False || --badcorr=True || --backsub=True || --combine=False || --combine_method=sum || --objname=None || --dprtype=None || --darkcorr=True || --fiber=ALL || --flipimage=both || --fluxunits=e- || --plot=0 || --resize=True || --leakcorr=True || --thermal=True || --force_ref_wave=False || --no_in_qc=False", "--xhelp=None || --debug=None || --listing=None || --listingall=None || --version=None || --info=None || --program=EXTALL[50270] || --recipe_kind=extract-ALL || --parallel=True || --shortname=EXTALL || --idebug=None || --ref=None || --crunfile=run_EXTALL_only.ini || --quiet=None || --nosave=False || --force_indir=None || --force_outdir=None", "2023-09-05 20:01:55.661", NULL, 1, 1, "image=NaN [image is all NaN] PASSED ||", "image||", "NaN||", "image is all NaN||", "1||", NULL, 1, 69, "IN_PARALLEL|RUNNING|ENDED|FORCE_REFWAVE|USER_FIBERS|QUICKLOOK|EXP_FPLINE", 1, "10.895233154296875", "35.187294006347656", "98.2339096069336", "0.0", "0.0", "0.0", "53.2", "75.3", 28, "2023-09-05 20:03:29.976", "2023-09-05 20:04:23.325")

    path: /h/spdrs/.apero/apero_at_localhost

    Function: apero.base.drs_db.py.Database.execute()

15:43:44.099- |PROC| Traceback (most recent call last): File "/apero/apero-drs/apero/base/drs_db.py", line 1943, in execute result = self._execute(cursor, command, fetch=fetch) File "/apero/apero-drs/apero/base/drs_db.py", line 2061, in _execute cursor = _mysql_exectue(cursor, command) File "/apero/apero-drs/apero/base/drs_db.py", line 3107, in _mysql_exectue cursor.execute(command) File "/conda/miniconda3/envs/apero-env/lib/python3.9/site-packages/mysql/connector/cursor.py", line 569, in execute self._handle_result(self._connection.cmd_query(stmt)) File "/conda/miniconda3/envs/apero-env/lib/python3.9/site-packages/mysql/connector/connection.py", line 598, in cmd_query result = self._handle_result(self._send_cmd(ServerCmd.QUERY, query)) File "/conda/miniconda3/envs/apero-env/lib/python3.9/site-packages/mysql/connector/connection.py", line 486, in _handle_result raise errors.get_exception(packet) mysql.connector.errors.DatabaseError: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/apero/apero-drs/apero/core/utils/drs_startup.py", line 432, in run llmain = func(recipe, params) File "/apero/apero-drs/apero/recipes/spirou/apero_extract_spirou.py", line 399, in main log2.update_flags(EXP_FPLINE=False) File "/apero/apero-drs/apero/core/utils/drs_utils.py", line 647, in update_flags self.write_logfile() File "/apero/apero-drs/apero/core/utils/drs_utils.py", line 525, in write_logfile self.logdbm.add_entries(recipe=inst.name, sname=inst.sname, File "/apero/apero-drs/apero/core/core/drs_database.py", line 2699, in add_entries self.database.add_row(values) File "/apero/apero-drs/apero/base/drs_db.py", line 679, in add_row self.execute(command, fetch=False) File "/apero/apero-drs/apero/base/drs_db.py", line 1963, in execute raise drs_base.base_error(ecode, emsg, 'error', args=eargs, apero.base.drs_db.DatabaseError: Database Error: 20:06:25.518-**|DatabaseError|E[00-002-00032] <class 'mysql.connector.errors.DatabaseError'>: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction Command: INSERT INTO log_offline_db VALUES("apero_extract_spirou", "EXTALL", "red", "recipe", "extract-ALL", "EXTALL[50270]", "PID-00016939441156608770-34K9", "2023-09-05 20:01:55.661", "1693944115.661", "APEROG-PID-00016934391638252470-QNB4_apero_processing_group", 2, 3, "num=0 fiber=B ", "/data/spirou4/apero-data/offline/tmp", "/data/spirou4/apero-data/offline/reduced", "19BQ10-Nov12", "/data/spirou4/apero-data/offline/msg/processing/APEROG-PID-00016934391638252470-QNB4_apero_processing_group/19BQ10-Nov12/APEROL-PID-00016939441156608770-34K9_apero_extract_spirou.log", "/data/spirou4/apero-data/offline/plot/19BQ10-Nov12/pid-00016939441156608770-34k9_apero_extract_spirou_1", "apero_extract_spirou.py 19BQ10-Nov12 2457191o_pp.fits --quicklook=False --badcorr=True --backsub=True --combine=False --combine_method=sum --darkcorr=True --fiber=ALL --flipimage=both --fluxunits=e- --plot=0 --resize=True --leakcorr=True --thermal=True --force_ref_wave=False --no_in_qc=False --program=EXTALL[50270] --recipe_kind=extract-ALL --parallel=True --shortname=EXTALL --crunfile=run_EXTALL_only.ini --nosave=False ", "obs_dir=19BQ10-Nov12 || files[1]=/data/spirou4/apero-data/offline/tmp/19BQ10-Nov12/2457191o_pp.fits [DRS_PP]", "--quicklook=False || --badcorr=True || --backsub=True || --combine=False || --combine_method=sum || --objname=None || --dprtype=None || --darkcorr=True || --fiber=ALL || --flipimage=both || --fluxunits=e- || --plot=0 || --resize=True || --leakcorr=True || --thermal=True || --force_ref_wave=False || --no_in_qc=False", "--xhelp=None || --debug=None || --listing=None || --listingall=None || --version=None || --info=None || --program=EXTALL[50270] || --recipe_kind=extract-ALL || --parallel=True || --shortname=EXTALL || --idebug=None || --ref=None || --crunfile=run_EXTALL_only.ini || --quiet=None || --nosave=False || --force_indir=None || --force_outdir=None", "2023-09-05 20:01:55.661", NULL, 1, 1, "image=NaN [image is all NaN] PASSED ||", "image||", "NaN||", "image is all NaN||", "1||", NULL, 0, 3, "IN_PARALLEL|RUNNING|ENDED|FORCE_REFWAVE|USER_FIBERS|QUICKLOOK|EXP_FPLINE", 1, "10.895233154296875", "-1.0", "98.2339096069336", "0.0", "-1.0", "0.0", "53.2", "-1.0", 28, "2023-09-05 20:05:06.688", NULL) path: /h/spdrs/.apero/apero_at_localhost Function: apero.base.drs_db.py.Database.execute()

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/apero/apero-drs/apero/base/drs_db.py", line 1943, in execute result = self._execute(cursor, command, fetch=fetch) File "/apero/apero-drs/apero/base/drs_db.py", line 2061, in _execute cursor = _mysql_exectue(cursor, command) File "/apero/apero-drs/apero/base/drs_db.py", line 3107, in _mysql_exectue cursor.execute(command) File "/conda/miniconda3/envs/apero-env/lib/python3.9/site-packages/mysql/connector/cursor.py", line 569, in execute self._handle_result(self._connection.cmd_query(stmt)) File "/conda/miniconda3/envs/apero-env/lib/python3.9/site-packages/mysql/connector/connection.py", line 598, in cmd_query result = self._handle_result(self._send_cmd(ServerCmd.QUERY, query)) File "/conda/miniconda3/envs/apero-env/lib/python3.9/site-packages/mysql/connector/connection.py", line 486, in _handle_result raise errors.get_exception(packet) mysql.connector.errors.DatabaseError: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/apero/apero-drs/apero/tools/module/processing/drs_processing.py", line 2368, in _linear_process ll_item = modulemain(kwargs) File "/apero/apero-drs/apero/core/utils/drs_recipe.py", line 980, in main return self.module.get().main(kwargs) File "/apero/apero-drs/apero/recipes/spirou/apero_extract_spirou.py", line 83, in main llmain, success = drs_startup.run(main, recipe, params) File "/apero/apero-drs/apero/core/utils/drs_startup.py", line 478, in run recipe.log.add_error('DatabaseError Exit', '') File "/apero/apero-drs/apero/core/utils/drs_utils.py", line 448, in add_error self.write_logfile() File "/apero/apero-drs/apero/core/utils/drs_utils.py", line 525, in write_logfile self.logdbm.add_entries(recipe=inst.name, sname=inst.sname, File "/apero/apero-drs/apero/core/core/drs_database.py", line 2699, in add_entries self.database.add_row(values) File "/apero/apero-drs/apero/base/drs_db.py", line 679, in add_row self.execute(command, fetch=False) File "/apero/apero-drs/apero/base/drs_db.py", line 1963, in execute raise drs_base.base_error(ecode, emsg, 'error', args=eargs, apero.base.drs_db.DatabaseError: Database Error: 20:07:15.647-**|DatabaseError|E[00-002-00032] <class 'mysql.connector.errors.DatabaseError'>: 1205 (HY000): Lock wait timeout exceeded; try restarting transaction Command: INSERT INTO log_offline_db VALUES("apero_extract_spirou", "EXTALL", "red", "recipe", "extract-ALL", "EXTALL[50270]", "PID-00016939441156608770-34K9", "2023-09-05 20:01:55.661", "1693944115.661", "APEROG-PID-00016934391638252470-QNB4_apero_processing_group", 2, 0, "num=0 fiber=C ", "/data/spirou4/apero-data/offline/tmp", "/data/spirou4/apero-data/offline/reduced", "19BQ10-Nov12", "/data/spirou4/apero-data/offline/msg/processing/APEROG-PID-00016934391638252470-QNB4_apero_processing_group/19BQ10-Nov12/APEROL-PID-00016939441156608770-34K9_apero_extract_spirou.log", "/data/spirou4/apero-data/offline/plot/19BQ10-Nov12/pid-00016939441156608770-34k9_apero_extract_spirou_1", "apero_extract_spirou.py 19BQ10-Nov12 2457191o_pp.fits --quicklook=False --badcorr=True --backsub=True --combine=False --combine_method=sum --darkcorr=True --fiber=ALL --flipimage=both --fluxunits=e- --plot=0 --resize=True --leakcorr=True --thermal=True --force_ref_wave=False --no_in_qc=False --program=EXTALL[50270] --recipe_kind=extract-ALL --parallel=True --shortname=EXTALL --crunfile=run_EXTALL_only.ini --nosave=False ", "obs_dir=19BQ10-Nov12 || files[1]=/data/spirou4/apero-data/offline/tmp/19BQ10-Nov12/2457191o_pp.fits [DRS_PP]", "--quicklook=False || --badcorr=True || --backsub=True || --combine=False || --combine_method=sum || --objname=None || --dprtype=None || --darkcorr=True || --fiber=ALL || --flipimage=both || --fluxunits=e- || --plot=0 || --resize=True || --leakcorr=True || --thermal=True || --force_ref_wave=False || --no_in_qc=False", "--xhelp=None || --debug=None || --listing=None || --listingall=None || --version=None || --info=None || --program=EXTALL[50270] || --recipe_kind=extract-ALL || --parallel=True || --shortname=EXTALL || --idebug=None || --ref=None || --crunfile=run_EXTALL_only.ini || --quiet=None || --nosave=False || --force_indir=None || --force_outdir=None", "2023-09-05 20:01:55.661", NULL, 1, 1, "image=NaN [image is all NaN] PASSED ||", "image||", "NaN||", "image is all NaN||", "1||", NULL, 1, 69, "IN_PARALLEL|RUNNING|ENDED|FORCE_REFWAVE|USER_FIBERS|QUICKLOOK|EXP_FPLINE", 1, "10.895233154296875", "35.187294006347656", "98.2339096069336", "0.0", "0.0", "0.0", "53.2", "75.3", 28, "2023-09-05 20:03:29.976", "2023-09-05 20:04:23.325") path: /h/spdrs/.apero/apero_at_localhost Function: apero.base.drs_db.py.Database.execute()

15:43:44.127- |PROC| 15:43:44.144- |PROC| ***

njcuk9999 commented 1 year ago

Probably the same thing as #717 we should keep discussion there.

larnoldgithub commented 1 year ago

Issue #717 or #718 occured for 62 files. Reprocessing them afterwards has been ok, no errors.