alliedvision / VimbaPython

Old Allied Vision Vimba Python API. The successor to this API is VmbPy
BSD 2-Clause "Simplified" License
93 stars 40 forks source link

Recurrent IndexError: pop from empty list #4

Closed stefannae closed 4 years ago

stefannae commented 4 years ago

This issue is reproducible running the synchronous_grab.py or asynchronous_grab.py example with an Alvium USB camera.

Traceback (most recent call last):
  File "_ctypes/callbacks.c", line 232, in 'calling callback function'
  File "/home/user/VimbaPython/vimba/feature.py", line 315, in __feature_cb_wrapper
    raise e
  File "/home/user/VimbaPython/vimba/feature.py", line 307, in __feature_cb_wrapper
    handler(self)
  File "/home/user/VimbaPython/vimba/vimba.py", line 537, in __cam_cb_wrapper
    cam = [c for c in self.__cams if cam_id == c.get_id()].pop()
NiklasKroeger-AlliedVision commented 4 years ago

hi @stefannae

unfortunately I am not able to reproduce the issue you are experiencing. For me the Alvium USB cameras I have available for testing at the moment work as expected with VimbaPython. From the Traceback you posted it appears, that there is some kind of connectivity issue between your camera and the system you are using. Line 537 in vimba.py is only called if a CameraEvent.Missing event is triggered which happens, when a camera is disconnected. Are you able to see the camera if you run the list_cameras.py example?

A quick test you can perform is to start the Vimba Viewer and see, if you can receive frames from your camera with that. If the image you receive freezes or you experience other issues, this is an indicator, that the connection to the camera is not stable or does not have enough bandwidth to stream the data reliably.

For more general troubleshooting my first idea would be to make sure, that the camera is securely connected on both ends. Ideally for the camera side the cable would be secured with a screw-locking USB3 cable. Also please note that long cables can lead to issues with USB3 devices in general. Additionally you could verify, that the camera is not accidentally connected to a USB2 port. If the camera is connected to a USB hub please make sure, that the hub is able to provide enough power to the device and is USB3 compatible.

I hope these tips help you get the camera working. We are glad to see the new API being used.

Best regards, -Niklas.

stefannae commented 4 years ago

@NiklasKroeger-AlliedVision, I can see the camera

Cameras found: 1
/// Camera Name   : Allied Vision 1800 U-500m
/// Model Name    : 1800 U-500m
/// Camera ID     : DEV_1AB22C000D00
/// Serial Number : 002KG
/// Interface ID  : VimbaUSBInterface_0x0

The issue is very consistent, except for the first occurrence (after 28 frames in the async case and 29 in the sync case), it consistently shows up every 39 or 40 frames. It is very close to the default configuration framerate, 38.5.

//////////////////////////////////////////
/// Vimba API Synchronous Grab Example ///
//////////////////////////////////////////

Got Frame(id=0, status=FrameStatus.Complete, buffer=0x7fb28eb2f010)
Got Frame(id=1, status=FrameStatus.Incomplete, buffer=0x5587786797b0)
Got Frame(id=2, status=FrameStatus.Incomplete, buffer=0x558779015df0)
...
Got Frame(id=28, status=FrameStatus.Incomplete, buffer=0x558780d06d90)
Traceback (most recent call last):
---> DETAILS REPORTED IN DESCRIPTION <---
IndexError: pop from empty list
Got Frame(id=29, status=FrameStatus.Incomplete, buffer=0x5587811d50a0)
...
Got Frame(id=67, status=FrameStatus.Incomplete, buffer=0x55878c870500)
Traceback (most recent call last):
---> DETAILS REPORTED IN DESCRIPTION <---
IndexError: pop from empty list
Got Frame(id=68, status=FrameStatus.Incomplete, buffer=0x55878cd3e810)
...
Got Frame(id=105, status=FrameStatus.Incomplete, buffer=0x558797f0b960)
Traceback (most recent call last):
---> DETAILS REPORTED IN DESCRIPTION <---)
IndexError: pop from empty list
Got Frame(id=106, status=FrameStatus.Incomplete, buffer=0x5587983d9c70)
...
///////////////////////////////////////////
/// Vimba API Asynchronous Grab Example ///
///////////////////////////////////////////

Press <enter> to stop Frame acquisition.
Camera(id=DEV_1AB22C000D00) acquired Frame(id=0, status=FrameStatus.Complete, buffer=0x7fa0d00b0010)
...
Camera(id=DEV_1AB22C000D00) acquired Frame(id=27, status=FrameStatus.Complete, buffer=0x7fa094ff2010)
Traceback (most recent call last):
---> DETAILS REPORTED IN DESCRIPTION <---
IndexError: pop from empty list
Camera(id=DEV_1AB22C000D00) acquired Frame(id=28, status=FrameStatus.Complete, buffer=0x7fa094b23010)
...
Camera(id=DEV_1AB22C000D00) acquired Frame(id=66, status=FrameStatus.Complete, buffer=0x7fa0954c1010)
Traceback (most recent call last):
---> DETAILS REPORTED IN DESCRIPTION <---
IndexError: pop from empty list
Camera(id=DEV_1AB22C000D00) acquired Frame(id=67, status=FrameStatus.Complete, buffer=0x7fa094ff2010)
...
Camera(id=DEV_1AB22C000D00) acquired Frame(id=104, status=FrameStatus.Complete, buffer=0x7fa095e5f010)
Traceback (most recent call last):
---> DETAILS REPORTED IN DESCRIPTION <---
IndexError: pop from empty list
Camera(id=DEV_1AB22C000D00) acquired Frame(id=105, status=FrameStatus.Complete, buffer=0x7fa095990010)
...

(This hints at another issue, this time with the Vimba Viewer. In MultiFrame mode with SW Trigger and Image Series Options... set, every so often the image saving loading bar freezes but always at the last frame/image and does not save it, irrespective of frame rate and the number of images set for the series.)

With the Vimba Viewer, the frame count temporarily stops increasing around every 300+ frames, although sometimes more often. In this case, we might have some sort of connectivity issue.

The camera is securely connected, with screw-locking on the camera side. Everything is USB3. The issue pops up with and without a powered USB hub in the middle, and irrespective of (cumulative) cable length, from below 1 m to up to 3 m.

NiklasKroeger-AlliedVision commented 4 years ago

Thank you for the further information. It appears, this definitely looks like our C layer which VimbaPython calls out to triggers unnecessary/false CameraMissing events. We would very much like to investigate this further.

If you are comfortable it would be great to get some more information on your setup. I see you are using a 1800 U-500m as camera and from the traceback it looks like a Linux system. Is this a regular install or a virtual machine? Could you perhaps provide the output of sudo lshw so we can get further information on the hardware of your system like the USB controller. Since this might be sensitive data you can of course remove everything you want to keep private and send it directly to me via email at Niklas.Kroeger@alliedvision.com. That way you don't have to post it publicly on Github.

Another thing that might help us would be a trace log of the synchronous or asynchronous grab example. I provided a new synchronous_grab example where I activated the trace log. If you run this, a lot more output should appear in your terminal, but also a VimbaPython_current-date-and-time_Trace.log file should be created in your working directory. If you could provide this to us we might be able to track down the issue better. Again, you can just mail this to me directly if you are more comfortable with that.

stefannae commented 4 years ago

It is a regular Ubuntu 18.04.4 LTS install. Here is the trace log VimbaPython_2020-04-01_13-55-13_Trace.log. This might be all you need since the camera is removed early on before the acquisition even starts:

2020-04-01 13:55:14,035 | Info     | Removed camera "DEV_1AB22C000D00" from active cameras
stefannae commented 4 years ago

And the error causing the issue is at

2020-04-01 13:55:14,932 | Error    | Caught Exception in handler: Type: <class 'IndexError'>, Value: pop from empty list, raised by: <bound method Vimba.__Impl.__cam_cb_wrapper of <vimba.vimba.Vimba.__Impl object at 0x7fc9 ...
NiklasKroeger-AlliedVision commented 4 years ago

Thank you for the trace log. Unfortunately so far we could not make out, what causes the CameraMissing event to be fired. To me this still seems like some kind of connectivity issue.

The event is triggered by our c library which the python API calls out to. In order to verify that, it would be great, if you could perhaps try to run one of our c examples. These are distributed as part of our Vimba SDK. The asynchronous grab example can be found at /path/to/your/vimba/VimbaC/Examples/AsynchronousGrab. If you experience issues there this clearly shows that there is something unexpected going on in the c library.

stefannae commented 4 years ago

No issues, here is the output

///////////////////////////////////////////
/// Vimba API Asynchronous Grab Example ///
///////////////////////////////////////////

Vimba Version Major: 1 Minor: 8 Patch: 1
Opening camera with ID: DEV_1AB22C000D00
Press <enter> to stop acquisition...
..............................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................
.
Acquisition stopped.

and with frame info

///////////////////////////////////////////
/// Vimba API Asynchronous Grab Example ///
///////////////////////////////////////////

Vimba Version Major: 1 Minor: 8 Patch: 1
Opening camera with ID: DEV_1AB22C000D00
Press <enter> to stop acquisition...
Frame ID:0 Status:Complete Size:2592x1944 Format:0x01080001 FPS:?
Frame ID:1 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.78
Frame ID:2 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.56
Frame ID:3 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.47
Frame ID:4 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.62
Frame ID:5 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.49
Frame ID:6 Status:Complete Size:2592x1944 Format:0x01080001 FPS:37.09
Frame ID:7 Status:Complete Size:2592x1944 Format:0x01080001 FPS:40.32
Frame ID:8 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.46
Frame ID:9 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.46
Frame ID:10 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.68
Frame ID:11 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.44
Frame ID:12 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.50
Frame ID:13 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.55
Frame ID:14 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.46
Frame ID:15 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.66
Frame ID:16 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.64
Frame ID:17 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.41
Frame ID:18 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.60
Frame ID:19 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.55
Frame ID:20 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.58
Frame ID:21 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.52
Frame ID:22 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.59
Frame ID:23 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.50
Frame ID:24 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.57
Frame ID:25 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.68
Frame ID:26 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.50
Frame ID:27 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.48
Frame ID:28 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.65
Frame ID:29 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.43
Frame ID:30 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.54
Frame ID:31 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.60
Frame ID:32 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.60
Frame ID:33 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.62
Frame ID:34 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.32
Frame ID:35 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.60
Frame ID:36 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.64
Frame ID:37 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.59
Frame ID:38 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.36
Frame ID:39 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.60
Frame ID:40 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.60
...
Frame ID:141 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.51
Frame ID:142 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.41
Frame ID:143 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.80
Frame ID:144 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.47
Frame ID:145 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.64
Frame ID:146 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.47
Frame ID:147 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.57
Frame ID:148 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.54
Frame ID:149 Status:Complete Size:2592x1944 Format:0x01080001 FPS:38.67

Frame ID:150 Status:Complete Size:2592x1944 Format:0x01080001 FPS:36.37

Acquisition stopped.
NiklasKroeger-AlliedVision commented 4 years ago

Hi @stefannae

sorry for the delay. We are still investigating the exact cause of this issue. So unfortunately I can't provide a definite solution for you. The good news at least is, that apparently the missing camera event is a misfire and the communication to the device itself seems to remain stable. VimbaPython just throws an error because it's internal list of cameras is now incorrect. So a workaround to get VimbaPython working for you right now would be to ignore Camera Missing events if the device that seems to have disappeared triggers them.

I would like to mention, that the following is not a real solution to the problem. The event should only fire if the camera is actually disappearing, but as a temporary workaround until we have fixed this issue, you can apply the following changes to your VimbaPython installation to be able to use it. We are working on the problem right now and hope to be able to fix it with our next release of Vimba. But I don't want to keep you waiting for that.

With that said. I just hacked together this in order to ignore the two cases where a camera, that disappears even though the internal camera list is already empty (the cause of the IndexError that can be seen here), and the case where a camera appears, even though it is already in the internal camera list. The second case (adding an existing camera) might not even be necessary, but if the camera can appear randomly I figured catching random appearances would be better. I did a quick test-run on a system I could reproduce the error on and it seems to be working okay. But please understand, that I did not test this thoroughly as this is in no way a real solution here. Hopefully it still allows you to get work done with your camera.

diff --git a/vimba/vimba.py b/vimba/vimba.py
index 858e66f..3b9eeb4 100644
--- a/vimba/vimba.py
+++ b/vimba/vimba.py
@@ -527,17 +527,21 @@ class Vimba:
                 cam = discover_camera(cam_id)

                 with self.__cams_lock:
-                    self.__cams.append(cam)
-
-                log.info('Added camera \"{}\" to active cameras'.format(cam_id))
+                    if cam not in self.__cams:
+                        self.__cams.append(cam)
+                        log.info('Added camera \"{}\" to active cameras'.format(cam_id))

             # Existing camera lost. Remove it from active cameras
             elif event == CameraEvent.Missing:
                 with self.__cams_lock:
-                    cam = [c for c in self.__cams if cam_id == c.get_id()].pop()
-                    self.__cams.remove(cam)
-
-                log.info('Removed camera \"{}\" from active cameras'.format(cam_id))
+                    try:
+                        cam = [c for c in self.__cams if cam_id == c.get_id()].pop()
+                        self.__cams.remove(cam)
+                        log.info('Removed camera \"{}\" from active cameras'.format(cam_id))
+                    except (IndexError):
+                        # Temporary workaround due to false CameraEvent.Missing occurences
+                        log.info('Tried to remove \"{}\" from empty cam list'.format(cam_id))
+                        pass

             else:
                 cam = self.get_camera_by_id(cam_id)
stefannae commented 4 years ago

@NiklasKroeger-AlliedVision thanks for looking into it and for the quick solution. We were already working with it in this mode, bypassing the issue.

NiklasKroeger-AlliedVision commented 4 years ago

Well I am glad this workaround can be used for now. We believe we have found the issue in our transport layer. The fix is currently in validation and should be included in the next release of Vimba. I will leave the issue open until then in case other people have the same problem. But once VimbaPython leaves beta this issue should be taken care of. Thank you for reporting it to us!

NiklasKroeger-AlliedVision commented 4 years ago

@stefannae I believe there are some good news for you. A new version of Vimba was just released at https://www.alliedvision.com/en/products/software.html. This includes some changes to our underlying software components as well as the official VimbaPython release. The issue you were experiencing should be fixed with this new release!

To update please download and install the newest Vimba release. This release includes VimbaPython as a new module and you can therefore install it from your Vimba installation directory. You may of course still use the Github release aswell, but you would have to update your checkout since I just pushed version 1.0.0 to this repository and you would otherwise run into trouble when VimbaPython tries to import the VimbaC module.

I am sorry the fix took so long but I hope the issue is resolved now.

stefannae commented 4 years ago

@NiklasKroeger-AlliedVision thanks for the excellent news.

NiklasKroeger-AlliedVision commented 4 years ago

I forgot to close this issue last time, so I will do that now. I hope the new release resolved it for you!