TheImagingSource / tiscamera

The Linux SDK for The Imaging Source cameras.
https://www.theimagingsource.com
Apache License 2.0
299 stars 148 forks source link

Property Set commands are not propagated to camera via USB. #561

Open c1arocque opened 1 month ago

c1arocque commented 1 month ago

Hello

I’m using a 72BUC02-ML in a personal 8mm film telecine project with the Python TIS() script. The application occasionally looses property set and software trigger commands. I have traces demonstrating that the function calls to tiscamera are executing and that no GStreamer errors are being raised. USB traffic capture (Wireshark) shows the missing commands are not being passed to the camera.

Camera configuration: BGRx, 2592 x 1944, frame rate == 5, trigger mode == set, all auto functions are disabled.

TISCamera built from github source this spring.

Linux laptop, 32 MB ram, M2 SSD, Ubuntu Studio 22.04, Python 3.

My application (script) captures a sequence of 5 exposures for each S8mm frame. The set of frame images are merged in a separate (from TIS()) process.

The film transport PCBA provides a hardware trigger for each frame.

Callback Function Outline. If the callback is due to hardware trigger

The first image of a new frame

Pull and Discard image
TriggerSoftware
exit

Else Pull and Store image in exposure set array Endif

If this is the last exposure of the set Set exposure (first in sequence) Pass set of frames to the merge process else Set exposure (next) TriggerSoftware endif exit

The hardware trigger always generates a frame and executes the callback. I can see TIS()/GST() polling the camera interface prior to receiving a hardware triggered frame. How does TIS() know when to POLL? Does it use an estimate from a known camera (hardware) frame buffer size and the declared frame rate? I don’t see the same polling sequence when a software trigger is executed.

The setexposure and triggersoftware commands are occasionally not transmitted to the camera. When this occurs, the next hardware trigger event allows the completion of my exposure set. Of course the transport has advanced to the next frame and the exposure set is a composite of two frames.

It appears that the two missing commands are blocked and/or dropped. I have enabled logging for GST but there is no obvious indication of a root cause.

Please advise how I can resolve my issue.

Regards

Chris LaRocque

TIS-Stefan commented 1 month ago

Hello Chris

I never had the situation you describe, which does not mean, it can happen. Is it possible to send a small script, which I can use to reproduce the situation on my computer? However, if the situation is caused v4l2, then I am afraid, I can not help.

Stefan

c1arocque commented 1 month ago

Thanks Stefan

I'll put something together and test that it still presents the problem.

Regards

Chris

On Thu, Oct 17, 2024 at 5:41 AM TIS-Stefan @.***> wrote:

Hello Chris

I never had the situation you describe, which does not mean, it can happen. Is it possible to send a small script, which I can use to reproduce the situation on my computer? However, if the situation is caused v4l2, then I am afraid, I can not help.

Stefan

— Reply to this email directly, view it on GitHub https://github.com/TheImagingSource/tiscamera/issues/561#issuecomment-2419053451, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEDIN3PNJ5TVK74MSX4JKSTZ36A23AVCNFSM6AAAAABQBQZSBSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDIMJZGA2TGNBVGE . You are receiving this because you authored the thread.Message ID: @.***>

c1arocque commented 1 month ago

Hello Again Stephan

Thank you again for your help. After thinking about it I just decided to send my app as is.

Attached archive contains the modified tis.py (minor mods to the streamer configuration: lines 86 & 88 "sync = False", and line 102 "max_buffers, 12"), my app. a USB capture, and associated debug info.

Unzip and create a folder "Raw" in the same location to store the images.

You can run from the cmd line as follows:

"python3 test_telecine_capture_bug.py -g 0.80 -o ./Raw"

Use hardware trigger to drive the camera at 10 second intervals.

The image display has a timestamp (duration of acq for the image set). You'll see that the timestamp is longer than the hardware trigger interval when the exposure and soft trigger commands aren't sent to the camera.

Regards

Chris LaRocque test_telecine_bug.tar.gz https://drive.google.com/file/d/1f4ijvshhndeuTp2WOqkpOPn8ho2wZt0o/view?usp=drive_web

On Thu, Oct 17, 2024 at 5:41 AM TIS-Stefan @.***> wrote:

Hello Chris

I never had the situation you describe, which does not mean, it can happen. Is it possible to send a small script, which I can use to reproduce the situation on my computer? However, if the situation is caused v4l2, then I am afraid, I can not help.

Stefan

— Reply to this email directly, view it on GitHub https://github.com/TheImagingSource/tiscamera/issues/561#issuecomment-2419053451, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEDIN3PNJ5TVK74MSX4JKSTZ36A23AVCNFSM6AAAAABQBQZSBSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDIMJZGA2TGNBVGE . You are receiving this because you authored the thread.Message ID: @.***>

TIS-Stefan commented 1 month ago

Hello

I needed to reduce you program to the relevant parts, by removing all OpenCV / ImageIO etc stuff. Also I removed the multithreading part, because I am not sure, how v4l2 will handle this. I took me some time to understand, what you are doing. The general idea of this HDR capture is quite good. The reduced sample it this:

trigger-callback-softwaretrigger.zip

I simply looked on the live video and checked, whether the image brightness changes as wanted. This is always the case. Thus, I suppose, there is somewhat in the multithreading you use. Keep your code as simple as possible, then the you have less side effects.

Somewhat tricky was to figure out how to get the exposure times in the correct sequence, so the hardware trigger, which is the first trigger for a new frame creates an image with the first exposure time the exposure times array. Thus, there is some double code in the callback:

def on_new_image(tis, userdata: CustomData):
    """
    Callback function, which will be called by the TIS class
    :param tis: the camera TIS class, that calls this callback
    :param userdata: This is a class with user data, filled by this call.
    :return:
    """
    # Avoid being called, while the callback is busy
    if userdata.busy is True:
        return

    userdata.busy = True

    # Here we have the image with last set exposure time
    print(f"Current exposure {userdata.camera.get_property('ExposureTime')}")

    userdata.imagecount += 1  # Next image, next exposure time
    l = len(userdata.exposurelist)
    if userdata.imagecount < l:
        print(
            f"New exposure : {l}  {userdata.imagecount} {userdata.exposurelist[userdata.imagecount]}"
        )
        userdata.camera.set_property(
            "ExposureTime", userdata.exposurelist[userdata.imagecount]
        )
        tis.execute_command("TriggerSoftware")  # Send a software trigger
    else:
        userdata.imagecount = 0
        print(
            f"New exposure : {l}  {userdata.imagecount} {userdata.exposurelist[userdata.imagecount]}"
        )
        userdata.camera.set_property(
            "ExposureTime", userdata.exposurelist[userdata.imagecount]
        )

    userdata.busy = False

Please try the sample I posted above.

Stefan

c1arocque commented 1 month ago

Thanks for the advice Stefan

I'll look at the sample and explore multiprocessing effects on V4l2.

Regards

Chris

On Mon, Oct 21, 2024 at 7:16 AM TIS-Stefan @.***> wrote:

Hello

I needed to reduce you program to the relevant parts, by removing all OpenCV / ImageIO etc stuff. Also I removed the multithreading part, because I am not sure, how v4l2 will handle this. I took me some time to understand, what you are doing. The general idea of this HDR capture is quite good. The reduced sample it this:

trigger-callback-softwaretrigger.zip https://github.com/user-attachments/files/17459728/trigger-callback-softwaretrigger.zip

I simply looked on the live video and checked, whether the image brightness changes as wanted. This is always the case. Thus, I suppose, there is somewhat in the multithreading you use. Keep your code as simple as possible, then the you have less side effects.

Somewhat tricky was to figure out how to get the exposure times in the correct sequence, so the hardware trigger, which is the first trigger for a new frame creates an image with the first exposure time the exposure times array. Thus, there is some double code in the callback:

def on_new_image(tis, userdata: CustomData): """ Callback function, which will be called by the TIS class :param tis: the camera TIS class, that calls this callback :param userdata: This is a class with user data, filled by this call. :return: """

Avoid being called, while the callback is busy

if userdata.busy is True:
    return

userdata.busy = True

# Here we have the image with last set exposure time
print(f"Current exposure {userdata.camera.get_property('ExposureTime')}")

userdata.imagecount += 1  # Next image, next exposure time
l = len(userdata.exposurelist)
if userdata.imagecount < l:
    print(
        f"New exposure : {l}  {userdata.imagecount} {userdata.exposurelist[userdata.imagecount]}"
    )
    userdata.camera.set_property(
        "ExposureTime", userdata.exposurelist[userdata.imagecount]
    )
    tis.execute_command("TriggerSoftware")  # Send a software trigger
else:
    userdata.imagecount = 0
    print(
        f"New exposure : {l}  {userdata.imagecount} {userdata.exposurelist[userdata.imagecount]}"
    )
    userdata.camera.set_property(
        "ExposureTime", userdata.exposurelist[userdata.imagecount]
    )

userdata.busy = False

Please try the sample I posted above.

Stefan

— Reply to this email directly, view it on GitHub https://github.com/TheImagingSource/tiscamera/issues/561#issuecomment-2426380207, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEDIN3PTHF6VYLGY3FJ44EDZ4TPATAVCNFSM6AAAAABQBQZSBSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDIMRWGM4DAMRQG4 . You are receiving this because you authored the thread.Message ID: @.***>

c1arocque commented 1 month ago

Hello Stefan

I observed the reported behavior using your code and the max image size for the camera. Wireshark captures that a software trigger is sent and the image is received on USB, but the GStreamer new_sample event doesn't fire. You should be able to reproduce by sending repeated hardware triggers at 10 second intervals and watching that each elicits 5 soft triggers. The issue has occurred in as few as 1 HW trigger (5 soft triggers) and as many as 20 HW triggers.

I've been looking at gst and v4l2 to see if similar issues have been reported but haven't found one yet. I'm also considering how to work around the issue by querying the GST buffers.

Thanks again for the assistance.

Regards

Chris

On Mon, Oct 21, 2024 at 7:16 AM TIS-Stefan @.***> wrote:

Hello

I needed to reduce you program to the relevant parts, by removing all OpenCV / ImageIO etc stuff. Also I removed the multithreading part, because I am not sure, how v4l2 will handle this. I took me some time to understand, what you are doing. The general idea of this HDR capture is quite good. The reduced sample it this:

trigger-callback-softwaretrigger.zip https://github.com/user-attachments/files/17459728/trigger-callback-softwaretrigger.zip

I simply looked on the live video and checked, whether the image brightness changes as wanted. This is always the case. Thus, I suppose, there is somewhat in the multithreading you use. Keep your code as simple as possible, then the you have less side effects.

Somewhat tricky was to figure out how to get the exposure times in the correct sequence, so the hardware trigger, which is the first trigger for a new frame creates an image with the first exposure time the exposure times array. Thus, there is some double code in the callback:

def on_new_image(tis, userdata: CustomData): """ Callback function, which will be called by the TIS class :param tis: the camera TIS class, that calls this callback :param userdata: This is a class with user data, filled by this call. :return: """

Avoid being called, while the callback is busy

if userdata.busy is True:
    return

userdata.busy = True

# Here we have the image with last set exposure time
print(f"Current exposure {userdata.camera.get_property('ExposureTime')}")

userdata.imagecount += 1  # Next image, next exposure time
l = len(userdata.exposurelist)
if userdata.imagecount < l:
    print(
        f"New exposure : {l}  {userdata.imagecount} {userdata.exposurelist[userdata.imagecount]}"
    )
    userdata.camera.set_property(
        "ExposureTime", userdata.exposurelist[userdata.imagecount]
    )
    tis.execute_command("TriggerSoftware")  # Send a software trigger
else:
    userdata.imagecount = 0
    print(
        f"New exposure : {l}  {userdata.imagecount} {userdata.exposurelist[userdata.imagecount]}"
    )
    userdata.camera.set_property(
        "ExposureTime", userdata.exposurelist[userdata.imagecount]
    )

userdata.busy = False

Please try the sample I posted above.

Stefan

— Reply to this email directly, view it on GitHub https://github.com/TheImagingSource/tiscamera/issues/561#issuecomment-2426380207, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEDIN3PTHF6VYLGY3FJ44EDZ4TPATAVCNFSM6AAAAABQBQZSBSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDIMRWGM4DAMRQG4 . You are receiving this because you authored the thread.Message ID: @.***>

TIS-Stefan commented 1 month ago

Hello Chris

In this situation would guess the image data transfer is incomplete, so the frame is discarded. Please try a lower frame rate and check, whether the image data transfer is more reliable. The loss of packages in the computer can be caused by CPU idle states or by high CPU load, which prevents the USB controller to save all data into memory.

c1arocque commented 3 weeks ago

Hi Stefan

Thanks for the advice. I'm now at ~5600 consecutive frames without error. Identified and corrected two issues. 1, added code to identity bad frames in the callback and re-trigger. 2, saw that the class used for transferring the frame set for processing occasionally failed to capture the framelist before I zeroed it in anticipation of the next set. This was handled by explicitly copying the frame set rather than implicitly in the class constructor.

I'm curious about the apparent contradiction of camera frame rate reduction reducing missed software trigger commands. Can you expound/ clarify?

Thank you for your advice and assistance.

Regards

Chris

On Tue, Oct 29, 2024, 05:23 TIS-Stefan @.***> wrote:

Hello Chris

In this situation would guess the image data transfer is incomplete, so the frame is discarded. Please try a lower frame rate and check, whether the image data transfer is more reliable. The loss of packages in the computer can be caused by CPU idle states or by high CPU load, which prevents the USB controller to save all data into memory.

— Reply to this email directly, view it on GitHub https://github.com/TheImagingSource/tiscamera/issues/561#issuecomment-2443673843, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEDIN3LDSHWPHR7P52TN7QTZ55HYDAVCNFSM6AAAAABQBQZSBSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDINBTGY3TGOBUGM . You are receiving this because you authored the thread.Message ID: @.***>

TIS-Stefan commented 3 weeks ago

Hello Chris

I'm curious about the apparent contradiction of camera frame rate reduction reducing missed software trigger commands. Can you expound/ clarify?

Reducing the frame rate reduces the bandwidth usage on the USB bus and creates longer times between image packets created by the camera. Thus, the PC's USB controller has more time to get the image data from the camera. The camera itself has only a little memory for image data in a ring buffer and if image data packets are not picked up in time, they are overwritten. This leads to a smaller than expected image buffers. tiscamera checks for the image buffer size and discards incomplete images. Therefore, sending a trigger to camera starts a new image and the image data is prepared to be picked up by the computer, but if the image is incomplete, it is dropped.

You can see the source code also in the "v4ldevice.cpp" ("v4l2device.cpp") standard sample, where you have

struct v4l2_buffer buf;

When reading frames you can check something like this:

int read_frame (void)
{
    CLEAR(buf);

    buf.type = V4L2_BUF_TYPE_VIDEO_CAPTURE;
    buf.memory = V4L2_MEMORY_MMAP;

    if (-1 == xioctl(fd, VIDIOC_DQBUF, &buf))
    {
        switch (errno)
        {
            case EAGAIN:
                return 0;

            case EIO:
                /* Could ignore EIO, see spec. */

                /* fall through */

            default:
                errno_exit("VIDIOC_DQBUF");
        }
    }

    assert(buf.index < n_buffers);
    if( _test == 0 )
    {
        _test = 1;
        //printf("Allocated buffer size : %d\n", buf.length );
    }

    // Check for complete images.
    if( buf.length !=  buf.bytesused)
    {
        //printf("Incomplete buffer: Expected: %d, received %d\n",  buf.length,  buf.bytesused );
        incompleteframecount++;
        snaperror = 2;
    }

    if (-1 == xioctl(fd, VIDIOC_QBUF, &buf))
        errno_exit("VIDIOC_QBUF");

    return 1;
}

That is a snippet from a sample I wrote a few years ago for checking frame drops. You will find similar code somewhere in the tiscamera repository.

In worst case, this leads to getting no images. In Windows, this situation can be caused by CPU Idle States and too high CPU load. In Linux, I saw this only on weak computer like Raspberry PI 3 and below. The simplest operations like copying a buffer from v4l2 buffer into another memory location leads to frame drops.

Newer camera models like DFK 32UR0521 have much more memory for image data packets, thus this issue is less probably. USB cameras like the 38U series have 128MB of RAM for images, so they can store the images until they are picked up completely.

I hope, this clarifies, what happens, as far as I understand this.

Stefan