bluesky / area-detector-handlers

https://pypi.org/project/area-detector-handlers
Other
1 stars 11 forks source link

tifffile can no longer read (at least some) AD TIFF files #20

Closed danielballan closed 4 years ago

danielballan commented 4 years ago

Example:

In [1]: import tifffile                                                                                                                                                                       

In [2]: fn = '/XF11ID/data/2020/08/25/f448221a-8f02-4a97-903a_000000.tiff'                                                                                                                    

In [3]: tifffile.TiffFile(fn)                                                                                                                                                                 
---------------------------------------------------------------------------
ValueError                                Traceback (most recent call last)
<ipython-input-3-3c6068d96329> in <module>
----> 1 tifffile.TiffFile(fn)

/opt/conda_envs/collection-2019-3.0-chx/lib/python3.7/site-packages/tifffile/tifffile.py in __init__(self, arg, name, offset, size, multifile, movie, **kwargs)
   1785 
   1786             # file handle is at offset to offset to first page
-> 1787             self.pages = TiffPages(self)
   1788 
   1789             if self.is_lsm and (self.filehandle.size >= 2**32 or

/opt/conda_envs/collection-2019-3.0-chx/lib/python3.7/site-packages/tifffile/tifffile.py in __init__(self, parent)
   2845         # always read and cache first page
   2846         fh.seek(offset)
-> 2847         page = TiffPage(parent, index=0)
   2848         self.pages.append(page)
   2849         self._keyframe = page

/opt/conda_envs/collection-2019-3.0-chx/lib/python3.7/site-packages/tifffile/tifffile.py in __init__(self, parent, index, keyframe)
   3171             self.andor_tags
   3172         elif self.is_epics:
-> 3173             self.epics_tags
   3174 
   3175         if self.is_lsm or (self.index and self.parent.is_lsm):

/opt/conda_envs/collection-2019-3.0-chx/lib/python3.7/site-packages/tifffile/tifffile.py in __get__(self, instance, owner)
    611             return self
    612         try:
--> 613             value = self.func(instance)
    614         except AttributeError as e:
    615             raise RuntimeError(e)

/opt/conda_envs/collection-2019-3.0-chx/lib/python3.7/site-packages/tifffile/tifffile.py in epics_tags(self)
   3795             if code == 65000:
   3796                 result['timeStamp'] = datetime.datetime.fromtimestamp(
-> 3797                     float(value))
   3798             elif code == 65001:
   3799                 result['uniqueID'] = int(value)

ValueError: year 357964404 is out of range
MikeHart85 commented 4 years ago

Discovered that it's possible to load old tiff files, for example from a month ago:

import tifffile
fn = 'XF11ID/data/2020/07/15/a1036c29-28a6-4c8d-b842_00000.tiff'
tifffile.TiffFile(fn)

This is with the latest collection-2020-2.0rc7-1 environment.

tacaswell commented 4 years ago

The value that is going in is 1.12962033697567e+16, the current epoch time is 1.598385e+09 which makes me think that a) AD is writing down timestamps in nanoseconds from the EPICS epoch and ~that the version of tifffile in 2019-3.0 is new enough to try to support reading these tags, but has a bug where it does not account for the non-standard epoch~

tacaswell commented 4 years ago

No, I am wrong https://github.com/cgohlke/tifffile/blame/master/tifffile/tifffile.py#L5770 that support has been there for two years.

tacaswell commented 4 years ago

My new guess is that the version of AD has changed at it is writing down the wrong timestamp, I think we need to pull in the CHX POC and sort out if this is a bug or setting in the IOC.

mrakitin commented 4 years ago

I think @gwbischof observed it before at RSoXS. Do you remember what was the reason?

Can it be that we need a newer version than 0.15 (2020.x.y due to the versioning scheme change)? That's what we deployed:

  - tifffile=0.15.1=py37heb32a55_2
mrakitin commented 4 years ago

What about a newest conda env? The demo code uses old collection env: collection-2019-3.0-chx.

tacaswell commented 4 years ago

@mrakitin The code in tifffile has not changed in ~2 years and the same code opens older tiffs, very strongly suspect that this is on the IOC side.

mrakitin commented 4 years ago

OK, that's weird. What's the version deployed to 2019-3.0? Maybe it's older there?

danielballan commented 4 years ago

We confirmed that it does not work in that environment either, so currently CHX is currently unable to read TIFFs in either their “old” or “new” environments if they are generated by their current Area Detector IOC.

prjemian commented 4 years ago

@MarkRivers: Could anything have changed recently with the AreaDetector TiffWriter plugin to cause read problems here?

MarkRivers commented 4 years ago

You can look at the commit history for NDFileTIFF.cpp here. https://github.com/areaDetector/ADCore/commits/master/ADApp/pluginSrc/NDFileTIFF.cpp

I don't see anything that looks suspicious to me.

Here are things I would suggest for testing:

MarkRivers commented 4 years ago
/opt/conda_envs/collection-2019-3.0-chx/lib/python3.7/site-packages/tifffile/tifffile.py in epics_tags(self)
   3795             if code == 65000:
   3796                 result['timeStamp'] = datetime.datetime.fromtimestamp(
-> 3797                     float(value))
   3798             elif code == 65001:
   3799                 result['uniqueID'] = int(value)

ValueError: year 357964404 is out of range

The timestamp at TIFF tag 65000 is an EPICS timestamp, not a Posix timestamp. The means that the epoch is January 1, 1990, not January 1, 1970. Does your Python code correctly handle that?

MarkRivers commented 4 years ago

I think I understand the problem. Your code assumes that the TIFF tag at 65000 is a Posix timestamp. In fact it is the NDArray.timeStamp field, which can come from the detector itself, and it can represent the time since the detector was powered on, etc.

Look at the documentation for NDFileTIFF here: https://areadetector.github.io/master/ADCore/NDFileTIFF.html.

Your TIFF reader should not be using TIFF tag 65000, it should be using the TIFF tags 65002 and 65003. Those are guaranteed to be the EPICS time in seconds (65002) and nanoseconds (65003) past the EPICS epoch of January 1, 1990. To convert to the Posix epoch you should first subtract this constant defined in epicsTime.h from the seconds value.

#define POSIX_TIME_AT_EPICS_EPOCH 631152000u

Now you can create a Python float by taking seconds + nanoseconds/1e9. Then pass that float to datetime.datetime.fromtimestamp()

danielballan commented 4 years ago

Thanks, @MarkRivers. I emailed you a TIFF between your first reply and your subsequent ones, but your explanation is very plausible. This might be a regression in tifffile. Will dig in tomorrow and report back here. Thanks.

MarkRivers commented 4 years ago

Here is tiffinfo run on the TIFF file @danielballan sent me:

corvette:~/scratch>tiffinfo f448221a-8f02-4a97-903a_000000.tiff
TIFFReadDirectory: Warning, Unknown field with tag 65000 (0xfde8) encountered.
TIFFReadDirectory: Warning, Unknown field with tag 65001 (0xfde9) encountered.
TIFFReadDirectory: Warning, Unknown field with tag 65002 (0xfdea) encountered.
TIFFReadDirectory: Warning, Unknown field with tag 65003 (0xfdeb) encountered.
TIFFReadDirectory: Warning, Unknown field with tag 65010 (0xfdf2) encountered.
TIFFReadDirectory: Warning, Unknown field with tag 65011 (0xfdf3) encountered.
TIFF Directory at offset 0x4c9328 (5018408)
  Image Width: 2448 Image Length: 2050
  Bits/Sample: 8
  Sample Format: unsigned integer
  Compression Scheme: None
  Photometric Interpretation: min-is-black
  Samples/Pixel: 1
  Rows/Strip: 2050
  Planar Configuration: single image plane
  Make: Unknown
  Model: Unknown
  Software: EPICS areaDetector
  Tag 65000: 11296203369756700.000000
  Tag 65001: 42639
  Tag 65002: 967229484
  Tag 65003: 416275913
  Tag 65010: BayerPattern:0
  Tag 65011: ColorMode:0

The tag at 65000 is clearly not a Posix or EPICS timestamp, it is much too large. But the tags at 65002 and 65003 look like a reasonable EPICS timestamp. I think if you use the algorithm I outlined in my previous post you will get a reasonable datetime value.

What kind of detector is this? I would like to know how it got such a large NDArray.timeStamp field.

MarkRivers commented 4 years ago

If I take the number of seconds in tag 65002 and convert to years I get

>>> 967229484/60/60./24./365
30.67064573820396

So the timestamp is 30.67 years after the EPICS epoch of Jan. 1, 1990, which is 2020 + 0.67 years, which makes sense.

MarkRivers commented 4 years ago

Note that this cannot be a new problem, it is showing up because this detector is returning an NDArray.timestamp that is very far from being a valid Posix timestamp. This could have been happening all along with certain detectors.

MarkRivers commented 4 years ago

I said:

To convert to the Posix epoch you should first subtract this constant defined in epicsTime.h from the seconds value.

That is wrong, you need to add that constant to convert from EPICS to Posix timestamps, since Posix starts 20 years earlier.

cgohlke commented 4 years ago

tifffile-2020.8.25 no longer converts EPICS timeStamp to datetime object. The previous implementation was based on a wrong/confusing comment in an older NDArray.h.

danielballan commented 4 years ago

Thanks for the fast fix, @cgohlke. Confirmed that the image under discussion here works with the new release.

In [1]: import tifffile                                                                                                                                                                       

In [2]: tifffile.__version__                                                                                                                                                                  
Out[2]: '2020.8.25'

In [3]: tf = tifffile.TiffFile('/home/dallan/Downloads/f448221a-8f02-4a97-903a_000000.tiff') 

21 will close this by putting a minimum version requirement on our tifffile dependency.

Thanks also to @MarkRivers, @prjemian. It's great to work within this helpful community.

danielballan commented 4 years ago

I would still like to know why we can read some AD-generated TIFFs and not others using the version of tifffile that pre-dates this patch, but I think we have all the information we need here to work that out.

MarkRivers commented 4 years ago

I would still like to know why we can read some AD-generated TIFFs and not others using the version of tifffile that pre-dates this patch, but I think we have all the information we need here to work that out.

I believe the reason is that most TIFF files have "reasonable" values of the timestamp in tag 65000, while some do not. The value of that tag is the NDArray.timeStamp member variable. That timestamp is set by the particular AD driver being used. It can come from two sources: 1) The EPICS time at the moment the driver received the image from the camera 2) The camera itself. This is only supported by some cameras and vendor SDKs. The time may be relative to the time the camera was powered on, or some other starting time. This method is clearly more accurate because it is not subject to any delay in reading the image from the hardware and transmitting it to the driver, but the resulting timestamp is not guaranteed to produce a meaningful Posix time.

If the time comes from the camera (2 above) and If it uses a start time such as when the camera was powered on, that should still not cause an error in datetime.fromtimestamp(), it should just result in a time that is very close to the Posix epoch.

However, in this case that tag at 65000 is 11296203369756700.000000 = 1.23e16. That is 358 million years in the future! That causes datetime.fromtimestamp() to throw an error.

That is why I asked what driver produced that TIFF file. It looks to me like perhaps that driver has a bug in how it computes NDArray.timestamp. Please let me know what driver it is and I will see if there is a bug that needs fixing.

MarkRivers commented 4 years ago

I just searched all of the standard areaDetector drivers to see where they assign the NDArray.timeStamp, seeing if I could spot an error. I believe I found one in the ADPcoWin driver. Is that the driver that wrote the TIFF file you sent me?

Here is the code


./ADPcoWin/pcowinApp/src/Pco.cpp:               image->timeStamp = imageTime.secPastEpoch +
./ADPcoWin/pcowinApp/src/Pco.cpp-                               imageTime.nsec / Pco::oneNanosecond;

So it is taking the nanosecond field and dividing by Pco::oneNanosecond. But Pco::oneNanosecond is defined as follows:

Pco.cpp:const double Pco::oneNanosecond = 1e-9;

Clearly this is a programming error, it should be multiplying by Pco::oneNanosecond, not dividing. It is getting a value that is up to 10^18 times too large.

danielballan commented 4 years ago

It's a Prosilica. According to Kaz, the format of the time reported by the detector is configurable, but I could not tell from the annotated screenshots of CSStudio he provided which PVs that might involve. Could it be that it was once configured to give POSIX timestamps and now gives something else (EPICS epoch or time-since-detector-started, etc.) due to some accidental configuration change on our side?

danielballan commented 4 years ago

Seems likely he meant PSTimestampType which per https://cars9.uchicago.edu/software/epics/prosilicaDoc.html can be:

danielballan commented 4 years ago

My understanding now is:

MarkRivers commented 4 years ago

@danielballan the documentation areaDetector has changed to ReST and is located here: https://areadetector.github.io/master/ADProsilica/ADProsilica.html

The PSTimeStampType documentation says this:


Controls the type of timestamp in the timeStamp field of each NDArray. Choices are:

The POSIX and EPICS timestamps are calculated as follows: when the timer is reset the current POSIX or EPICS time is stored, and the internal camera timer is reset. The timestamps are then computed by adding the camera ticks (converted to seconds) to the stored POSIX or EPICS time. Thus, the relative times of each frame are accurately controlled by the internal camera clock. The accuracy of the absolute time is determined by the accuracy of the time of day clock in the IOC computer.

The IOC timestamp is simply the time returned by epicsTimeGetCurrent(), and does not use the camera tick clock at all.


The IOC timestamp type has existed for a long time, but was missing from the documentation until I added it this morning.

So the POSIX and EPICS types actually use the camera tick clock, whereas the IOC type does not.

afluerasu commented 4 years ago

Thanks all for this amazing investigative work. I'm really impressed by how well and efficient this community works.

MarkRivers commented 4 years ago

I am trying to understand how the NDArray.timeStamp got a value of 11296203369756700.0 = 1.13e16. It seems that it could only get that large if the PSTimestampType was NativeTicks.

I have looked at several Prosilica cameras and their GenICam feature called GevTimestampTickFrequency is 1e9 (1 GHz). At that tick frequency the counter would reach 1.13e16 in 131 days. So this is the likely explanation for the large number: NativeTicks was selected and the camera had not been power-cycled or had the clock reset for that long.

danielballan commented 4 years ago

Confirmed that the current setting of the IOC that produced that example image is NativeTicks.

dallan@xf11id-ws1:~$ caget XF:11IDA-BI{Bpm:1-Cam:1}cam1:PSTimestampType
XF:11IDA-BI{Bpm:1-Cam:1}cam1:PSTimestampType NativeTicks

I could not find a way to query the uptime of a given IOC, but the process running time for the relevant softioc process is 384 days, so it seems possible that the IOC has been running for 131 days.

dallan@xf11idb-ioc1:~$ ps -p 7994 -o etime
    ELAPSED
384-00:58:59
danielballan commented 4 years ago

Uptime (thanks to a hint from @prjemian on another thread):

dallan@xf11id-ws1:~$ caget XF:11IDA-BI{Bpm:1-Cam:1}:UPTIME
XF:11IDA-BI{Bpm:1-Cam:1}:UPTIME 400 days, 21:27:20