aravis icon indicating copy to clipboard operation
aravis copied to clipboard

Published 20 hours ago • verified publisher icon AravisProject

Genicam data load is too long, need a cache

Open dyoo-dev opened this issue 4 years ago • 5 comments

Describe the bug Hello, I take a single image from a camera with arv_camera_acqusition(). 0.4MP camera takes 350ms, and 1.6MP camera takes over 1sec to take a single image. I think it should be very short. Why is it taking so long time?

Camera description:

  • Manufacturer: LUCID
  • Model: Triton 0.4MP and 1.6MP
  • Interface: ethernet

Platform description:

  • Aravis version: 0.8
  • OS: Ubuntu 18.04 and CentOS 7

dyoo-dev avatar Jul 15 '21 18:07 dyoo-dev

Please attach the output of ARV_DEBUG=all ./tests/arv-acquisition-test

EmmanuelP avatar Jul 21 '21 20:07 EmmanuelP

This is the output. Please take a look. Thanks

[10:32:06.301] ❷ interface> Found 0 USB3Vision device (among 9 USB devices)
[10:32:06.301] ❷ interface> [GvDiscoverSocket::new] Add interface 127.0.0.1
[10:32:06.301] ❷ interface> [GvDiscoverSocket::new] Add interface 192.168.167.132
[10:32:06.301] ❷ interface> [GvDiscoverSocket::new] Add interface 10.0.0.120
[10:32:06.301] ❷ interface> [GvDiscoverSocket::new] Add interface 172.19.0.1
[10:32:06.301] ❷ interface> [GvDiscoverSocket::new] Add interface 172.20.0.1
[10:32:06.301] ❷ interface> [GvDiscoverSocket::new] Add interface 172.17.0.1
[10:32:06.306] ❷ interface> [GvInterface::discovery] Device 'Lucid Vision Labs-TRI004S-C-211800832' found (interface 10.0.0.120) user_id '' - MAC '1c:0f:af:a9:a7:49'
[10:32:06.306] ❷ device> [GvDevice::new] Interface address = 10.0.0.120
[10:32:06.306] ❷ device> [GvDevice::new] Device address = 10.0.0.42
[10:32:06.310] ❷ device> [GvDevice::load_genicam] xml url = 'Local:Lucid_Vision_Labs_TRI004S-C_rev1_0_288aca1993d678e65944c943b7a64cb0.zip;800d9370;f202' at 0x200
[10:32:06.310] ❷ device> [GvDevice::load_genicam] Xml address = 0x800d9370 - size = 0xf202 - Lucid_Vision_Labs_TRI004S-C_rev1_0_288aca1993d678e65944c943b7a64cb0.zip
[10:32:06.984] ❶ device> [GvDevice::read_memory] Ack reception timeout
[10:32:06.984] ❶ device> [GvDevice::read_memory] Ack reception timeout
[10:32:07.486] ❶ device> [GvDevice::read_memory] Ack reception timeout
[10:32:07.486] ❶ device> [GvDevice::read_memory] Ack reception timeout
[10:32:07.801] ❷ device> [GvDevice::load_genicam] Zipped xml data
[10:32:07.802] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'xmlns:mstns'
[10:32:07.804] ❷ dom> [Genicam::create_element] Unknown tag (String)
[10:32:07.804] ❷ dom> [Genicam::create_element] Unknown tag (String)
[10:32:07.804] ❷ dom> [Genicam::create_element] Unknown tag (String)
[10:32:07.804] ❷ dom> [Genicam::create_element] Unknown tag (String)
[10:32:07.804] ❷ dom> [Genicam::create_element] Unknown tag (String)
[10:32:07.804] ❷ dom> [Genicam::create_element] Unknown tag (String)
[10:32:07.804] ❷ dom> [Genicam::create_element] Unknown tag (String)
[10:32:07.804] ❷ dom> [Genicam::create_element] Unknown tag (String)
[10:32:07.804] ❷ dom> [Genicam::create_element] Unknown tag (String)
[10:32:07.804] ❷ dom> [Genicam::create_element] Unknown tag (String)
[10:32:07.818] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.818] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.818] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.818] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.818] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.818] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.819] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.820] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.820] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.820] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.820] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.820] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.820] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.820] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.821] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.821] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.821] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.821] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.821] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.821] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.821] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.821] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.821] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.821] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.821] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.822] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.822] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.822] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.822] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.822] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.822] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.823] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.823] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.823] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.823] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.823] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.823] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.823] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.824] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.824] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.824] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.824] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.824] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.824] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.824] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.824] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.824] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.824] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.824] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.825] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.825] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.825] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.825] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.825] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.825] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.825] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.825] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.826] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.826] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.826] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.826] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.826] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.826] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.826] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.826] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.827] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.827] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.827] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.827] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.827] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.827] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.827] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.827] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.828] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.828] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.828] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.828] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.828] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.829] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.829] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.829] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.829] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.829] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.829] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.829] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.829] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.830] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.830] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.830] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.830] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'Comment'
[10:32:07.832] ❷ genicam> [Gc::set_default_node_data] Add 'DeviceVendorName'
[10:32:07.832] ❷ genicam> [Gc::set_default_node_data] Add 'DeviceModelName'
[10:32:07.832] ❷ genicam> [Gc::set_default_node_data] Add 'DeviceVersion'
[10:32:07.832] ❷ genicam> [Gc::set_default_node_data] Add 'DeviceManufacturerInfo'
[10:32:07.832] ❷ genicam> [Gc::set_default_node_data] Add 'DeviceID'
[10:32:07.832] ❷ genicam> [Gc::set_default_node_data] Add 'GevStreamChannelCount'
[10:32:07.832] ❷ genicam> [Gc::set_default_node_data] Add 'GevTimestampTickFrequency'
[10:32:07.832] ❷ genicam> [Gc::set_default_node_data] Add 'GevSCPSBigEndian'
[10:32:07.832] ❷ genicam> [Gc::set_default_node_data] Add 'GevSCPAddrCalc'
[10:32:07.837] ❷ device> [GvDevice::new] Device endianness = big
[10:32:07.837] ❷ device> [GvDevice::new] Packet resend     = yes
[10:32:07.837] ❷ device> [GvDevice::new] Write memory      = yes
[10:32:07.837] ❷ device> [GvDevice::new] Legacy endianness handling = no
[10:32:07.842] ❷ device> [GvDevice::create_stream] Number of stream channels = 1
[10:32:07.848] ❷ device> [GvStream::stream_new] Packet size = 1400 byte(s)
[10:32:07.855] ❷ stream> [GvStream::stream_new] Destination stream port = 50578
[10:32:07.855] ❷ stream> [GvStream::stream_new] Source stream port = 49154
[10:32:07.855] ❷ stream-thread> [GvStream::stream_thread] Packet timeout = 40 ms
[10:32:07.855] ❷ stream-thread> [GvStream::stream_thread] Frame retention = 200 ms
[10:32:07.855] ❷ stream> [GvStream::loop] Standard socket method
[10:32:07.910] ❷ stream>   bins  ;Buffer r
       0;       0
-------------
>=  2000;       0
<      0;       0
min     ;     n/a
max     ;     n/a
last max
at:     ;       0
Counter =        0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_completed_buffers    = 1
[10:32:07.910] ❷ stream> [GvStream::finalize] n_failures             = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_timeouts             = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_aborteds             = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_underruns            = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_missing_frames       = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_size_mismatch_errors = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_received_packets     = 288
[10:32:07.910] ❷ stream> [GvStream::finalize] n_missing_packets      = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_error_packets        = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_ignored_packets      = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_resend_requests      = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_resent_packets       = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_resend_ratio_reached = 0
[10:32:07.910] ❷ stream> [GvStream::finalize] n_duplicated_packets   = 0
[10:32:07.910] ❷ stream> [Stream::finalize] Flush 0 buffer[s] in input queue
[10:32:07.910] ❷ stream> [Stream::finalize] Flush 0 buffer[s] in output queue
Image successfully acquired

dyoo-dev avatar Jul 22 '21 14:07 dyoo-dev

Most of the time is spent loading the Genicam data from the device (1.5s). A cache would help a lot in this example.

[10:32:06.310] ❷ device> [GvDevice::load_genicam] xml url = 'Local:Lucid_Vision_Labs_TRI004S-C_rev1_0_288aca1993d678e65944c943b7a64cb0.zip;800d9370;f202' at 0x200
...
[10:32:07.802] ❷ dom> [GcFeature::set_attribute] Unknown attribute 'xmlns:mstns'

EmmanuelP avatar Jul 26 '21 17:07 EmmanuelP

@EmmanuelP Thank you for your reply. Can you explain more about the cache?

Also, I got the following logs sometimes. Usually, the snapshot takes 500ms, but whenever I got this, the snapshot took over 1 sec. Why do I have these messages?

[10:32:06.984] ❶ device> [GvDevice::read_memory] Ack reception timeout
[10:32:06.984] ❶ device> [GvDevice::read_memory] Ack reception timeout
[10:32:07.486] ❶ device> [GvDevice::read_memory] Ack reception timeout
[10:32:07.486] ❶ device> [GvDevice::read_memory] Ack reception timeout

dyoo-dev avatar Jul 27 '21 13:07 dyoo-dev

@EmmanuelP Thank you for your reply. Can you explain more about the cache?

It could be possible to store the retrieved genicam data in a dedicated directory, and use this cached data the next time aravis connects to the camera. But it is not implemented yet.

Also, I got the following logs sometimes. Usually, the snapshot takes 500ms, but whenever I got this, the snapshot took over 1 sec. Why do I have these messages?

There are some packet lost during data transmission, and the default time-out is a bit large (500ms). Unfortunately there is no setting for this value, except one at compilation time, when you select the fast-heartbeat option.

EmmanuelP avatar Jul 27 '21 15:07 EmmanuelP