fix astropy bug #652

cg-laser · 2024-03-08T23:35:55Z

setting the time format to 'isot' results in an error when older nur files are read with a newer version of astropy (I have 5.2.2). I don't know with which version the original nur file was created.

The expected behavior is that order nur files can always be read in. This is high priority as e.g. ARIANNA data is stored as nur files.

Before merging, I will remove the warning message, but I thought I would keep it in for now in case someone wants to investigate the underlying problem. It seems that not setting the format explicitly works just fine.

aj-nielsen · 2024-03-09T02:10:15Z

I looked at the ARIANNA hard drive to try and figure out which version of astropy the file was made with originally (from our root files -> nur file output converter); it looks like it was made with an extremely old version of astropy (2.0.14), with Python 2.7. The old root files also work with astropy 5.1 as-is.

sjoerd-bouma

Haven't looked at this in much detail yet, but possibly this is the same issue as #481, which should have been fixed (or just prevented from occurring in the future?) by #520. If I recall correctly, the issue was that astropy.time.Time objects were serialized directly, but opening an 'old' astropy.time.Time object with a newer version of astropy.time.Time led to compatibility issues after astropy 5.0. Probably @fschlueter recalls the details better than I do, and may be able to weigh in as to why this issue has appeared again (or still).

sjoerd-bouma · 2024-03-09T18:57:55Z

NuRadioReco/modules/io/NuRadioRecoio.py

@@ -49,7 +50,7 @@ def __init__(self, filenames, parse_header=True, parse_detector=True, fail_on_ve
 filenames = [filenames]

 self.__file_scanned = False
- self.logger = logging.getLogger('NuRadioReco.NuRadioRecoio')
+ self.logger = setup_logger('NuRadioReco.NuRadioRecoio')


I think only scripts are meant to call setup_logger, see https://nu-radio.github.io/NuRadioMC/NuRadioReco/pages/nur_modules.html#logging and/or double check with @MijnheerD. So I think l.52 and l.11 should be reverted

Indeed, individual modules should use the getLogger function from the standard logging library. Using the setup_logger() might work, but I have not tested what the result is.

why wouldn't we use the nice new standardized logging? I have experienced no error so far. And I think this is exactly want we want to do to have a uniform formatting of logger outputs and the status level. Or why would you disagree @MijnheerD @sjoerd-bouma ?

This is the new standardized logging. The setup_logger() function is only supposed to format the parent logger, not the individual module loggers. Thanks to the inheritance properties of the loggers, the parent logger is the one who will actually report the logs (in the nice format).

One potential issue that I just thought of, is that the setup_logger() returns a logger which does not further propagate its messages. So I think if you keep l.53 as is, setting a general logging level in the scripts will not work for this module. So I second @sjoerd-bouma suggestion to revert the changes.

sry if I'm slow in understanding how it works. Doesn't it require that the script that imported NuRadioRecoIO initialized a logger with the setup_logger function before the NuRadioRecoIO module initializes its logger?
And I thought if we use the correct naming scheme, i.e., starting the logger name with "NuRadioReco." it will inherit from the correct logger?

Indeed, the inheritance is taken care of by the naming scheme. But the way the logging is currently set up, is such that the parent logger (i.e. the one with the name "NuRadioReco") is the one who actually handles the log messages. All module loggers simply pass on their messages to the parent logger. And it is the latter that the setup_logger() function is supposed to set up.

As the inheritance is something that comes from the standard logging module itself, there is no need to import anything from our own logging library to initialize the module loggers, they can be called using logging.getLogger() . When using the modules in a script, their loggers will link to the parent logger that is expected to be created at the beginning ¹ of the script (using the setup_logger() function).

Footnotes

From my testing the ordering is actually not important, i.e. the NuRadioReco logger can be created after modules are initialized (though this is not recommended). The modules loggers will find the parent logger as long as it is exists. ↩

fschlueter · 2024-03-11T09:22:55Z

Haven't looked at this in much detail yet, but possibly this is the same issue as #481, which should have been fixed (or just prevented from occurring in the future?) by #520. If I recall correctly, the issue was that astropy.time.Time objects were serialized directly, but opening an 'old' astropy.time.Time object with a newer version of astropy.time.Time led to compatibility issues after astropy 5.0. Probably @fschlueter recalls the details better than I do, and may be able to weigh in as to why this issue has appeared again (or still).

@sjoerd-bouma you remember correctly: With #520 we prevent problems for the future by not seralizing astropy.Time objects. Of course those lurk around in older files and we still allow reading them (of course). Nonetheless I am surprised that this issue occurs because it means that the api changed on a very fundamental level... would be good to understand what exactly changed.

Not setting the format should not be an issue. But should does not mean that it does not I guess

fschlueter · 2024-03-11T09:26:16Z

@cg-laser what is the error msg, is it the time format or the way of setting it? Maybe you can share a file with which this issue appears?

aj-nielsen · 2024-03-11T18:15:10Z

@cg-laser what is the error msg, is it the time format or the way of setting it? Maybe you can share a file with which this issue appears?

I know this was a question for Christian but I can answer this, since I brought up the bug/error msg to him. An example file that causes this issue is this file: "Spice_750mDown_Dec30_2018_idl_10dB.nur"

And this was the error message:

`Traceback (most recent call last):
  File "c:\Users\AJN\Documents\Research_Software\SPICE_SIM_2024\20240304_A03_reconstruct_v4.py", line 973, in <module>
    pol_calculator('20240306', 'normal', "upright", "noplot", "direct_and_reflected", "noNoise", 101, 'newidl1', '0123', "corrZA", 100)
  File "c:\Users\AJN\Documents\Research_Software\SPICE_SIM_2024\20240304_A03_reconstruct_v4.py", line 216, in pol_calculator
    input = openfile(files)
            ^^^^^^^^^^^^^^^     
  File "c:\Users\AJN\Documents\Research_Software\SPICE_SIM_2024\20240304_A03_reconstruct_v4.py", line 90, in openfile
    file = NuRadioReco.modules.io.NuRadioRecoio.NuRadioRecoio(filename)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 
  File "C:\Users\AJN\anaconda3\envs\birefringe\Lib\site-packages\NuRadioReco\modules\io\NuRadioRecoio.py", line 80, in __init__
    self.openFile(filenames)
  File "C:\Users\AJN\anaconda3\envs\birefringe\Lib\site-packages\NuRadioReco\modules\io\NuRadioRecoio.py", line 167, in openFile
    self.__scan_files()
  File "C:\Users\AJN\anaconda3\envs\birefringe\Lib\site-packages\NuRadioReco\modules\io\NuRadioRecoio.py", line 222, in __scan_files
    continue_loop, iF, current_byte = self.__scan_files_versioned(self, iF, current_byte)
                                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^                           
  File "C:\Users\AJN\anaconda3\envs\birefringe\Lib\site-packages\NuRadioReco\modules\io\event_parser_factory.py", line 84, in scan_files_2_2
    self._parse_event_header(evt_header)
    
  File "C:\Users\AJN\anaconda3\envs\birefringe\Lib\site-packages\NuRadioReco\modules\io\NuRadioRecoio.py", line 206, in _parse_event_header
    station_time.format = 'isot'
    ^^^^^^^^^^^^^^^^^^^
    self.precision,
    ^^^^^^^^^^^^^^
  File "C:\Users\AJN\anaconda3\envs\birefringe\Lib\site-packages\astropy\time\core.py", line 1782, in __getattr__
    return self.__getattribute__(attr)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\AJN\anaconda3\envs\birefringe\Lib\site-packages\astropy\time\core.py", line 821, in precision
    return self._time.precision
           ^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\AJN\anaconda3\envs\birefringe\Lib\site-packages\astropy\time\formats.py", line 271, in precision
    return self._precision
           ^^^^^^^^^^^^^^^
AttributeError: 'TimeISOT' object has no attribute '_precision'. Did you mean: 'precision'?`

fschlueter · 2024-03-12T09:33:20Z

So I tried to understand a bit better whats going on. I think at some point they replaced the variable precision with _precision but a @property precision to keep the same api. However, this breaks when (de)-seralizing the objects.
A workaround might be this:

                            try:
                                station_time.format = 'isot'
                            except AttributeError:
                                station_time.precision = station_time._time.__dict__["precision"]
                                station_time.format = 'isot'

However, I have not extensively tested it myself. I tested it on the file mentioned above and a newer file which works just with setting the format

cg-laser · 2024-03-15T19:07:29Z

I took into account your comments. @aj-nielsen can you check that you can read the ARIANNA files and that you get the correct event times?

fschlueter · 2024-03-26T12:55:06Z

@aj-nielsen does that work for you?

aj-nielsen · 2024-03-26T21:59:26Z

Yes, this works for me & I can read one of the files, sorry for the delayed response.

fschlueter · 2024-05-28T07:35:11Z

I think that can be merged

fix astropy bug

7428f20

cg-laser requested review from christophwelling, aj-nielsen and sjoerd-bouma March 8, 2024 23:35

sjoerd-bouma reviewed Mar 9, 2024

View reviewed changes

fix

d4769e2

fschlueter approved these changes May 28, 2024

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix astropy bug #652

fix astropy bug #652

cg-laser commented Mar 8, 2024

aj-nielsen commented Mar 9, 2024 •

edited

sjoerd-bouma left a comment

sjoerd-bouma Mar 9, 2024

MijnheerD Mar 11, 2024

cg-laser Mar 11, 2024

MijnheerD Mar 12, 2024

cg-laser Mar 12, 2024

MijnheerD Mar 13, 2024

fschlueter commented Mar 11, 2024

fschlueter commented Mar 11, 2024

aj-nielsen commented Mar 11, 2024 •

edited

fschlueter commented Mar 12, 2024 •

edited

cg-laser commented Mar 15, 2024

fschlueter commented Mar 26, 2024

aj-nielsen commented Mar 26, 2024 •

edited

fschlueter commented May 28, 2024

fix astropy bug #652

Are you sure you want to change the base?

fix astropy bug #652

Conversation

cg-laser commented Mar 8, 2024

aj-nielsen commented Mar 9, 2024 • edited

sjoerd-bouma left a comment

Choose a reason for hiding this comment

sjoerd-bouma Mar 9, 2024

Choose a reason for hiding this comment

MijnheerD Mar 11, 2024

Choose a reason for hiding this comment

cg-laser Mar 11, 2024

Choose a reason for hiding this comment

MijnheerD Mar 12, 2024

Choose a reason for hiding this comment

cg-laser Mar 12, 2024

Choose a reason for hiding this comment

MijnheerD Mar 13, 2024

Choose a reason for hiding this comment

Footnotes

fschlueter commented Mar 11, 2024

fschlueter commented Mar 11, 2024

aj-nielsen commented Mar 11, 2024 • edited

fschlueter commented Mar 12, 2024 • edited

cg-laser commented Mar 15, 2024

fschlueter commented Mar 26, 2024

aj-nielsen commented Mar 26, 2024 • edited

fschlueter commented May 28, 2024

aj-nielsen commented Mar 9, 2024 •

edited

aj-nielsen commented Mar 11, 2024 •

edited

fschlueter commented Mar 12, 2024 •

edited

aj-nielsen commented Mar 26, 2024 •

edited