unit-tests-regressions.cpp
Go to the documentation of this file.
1 // License: Apache 2.0. See LICENSE file in root directory.
2 // Copyright(c) 2020 Intel Corporation. All Rights Reserved.
3 
5 // Regressions tests against the known issues //
7 
8 #include <cmath>
9 #include "unit-tests-common.h"
10 #include "../include/librealsense2/rs_advanced_mode.hpp"
11 #include <librealsense2/hpp/rs_types.hpp>
12 #include <librealsense2/hpp/rs_frame.hpp>
13 #include <iostream>
14 #include <chrono>
15 #include <ctime>
16 #include <algorithm>
17 #include <librealsense2/rsutil.h>
18 
19 using namespace rs2;
20 
21 TEST_CASE("DSO-14512", "[live]")
22 {
23  {
24  rs2::log_to_file(RS2_LOG_SEVERITY_DEBUG,"lrs_log.txt");
25  //rs2::log_to_console(RS2_LOG_SEVERITY_DEBUG);
26  rs2::context ctx;
27  if (make_context(SECTION_FROM_TEST_NAME, &ctx))
28  {
29  for (size_t iter = 0; iter < 10; iter++)
30  {
31  std::vector<rs2::device> list;
32  REQUIRE_NOTHROW(list = ctx.query_devices());
33  REQUIRE(list.size());
34 
35  auto dev = list[0];
36  CAPTURE(dev.get_info(RS2_CAMERA_INFO_NAME));
37  disable_sensitive_options_for(dev);
38 
39  std::mutex m;
40  int fps = is_usb3(dev) ? 30 : 15; // In USB2 Mode the devices will switch to lower FPS rates
41 
42  for (auto i = 0; i < 1000; i++)
43  {
44  std::map<std::string, size_t> frames_per_stream{};
45  std::map<std::string, size_t> frames_indx_per_stream{};
46  std::vector<std::string> drop_descriptions;
47 
48  auto profiles = configure_all_supported_streams(dev, 640, 480, fps);
49  size_t drops_count=0;
50 
51  for (auto s : profiles.first)
52  {
53  REQUIRE_NOTHROW(s.start([&m, &frames_per_stream,&frames_indx_per_stream,&drops_count,&drop_descriptions](rs2::frame f)
54  {
55  std::lock_guard<std::mutex> lock(m);
56  auto stream_name = f.get_profile().stream_name();
57  auto fn = f.get_frame_number();
58 
59  if (frames_per_stream[stream_name])
60  {
61  auto prev_fn = frames_indx_per_stream[stream_name];
62  if ((fn = prev_fn) != 1)
63  {
64  drops_count++;
65  std::stringstream s;
66  s << "Frame drop was recognized for " << stream_name<< " jumped from " << prev_fn << " to " << fn;
67  drop_descriptions.emplace_back(s.str().c_str());
68  }
69  }
70  ++frames_per_stream[stream_name];
71  frames_indx_per_stream[stream_name] = fn;
72  }));
73  }
74 
75  std::this_thread::sleep_for(std::chrono::seconds(60));
76  // Stop & flush all active sensors. The separation is intended to semi-confirm the FPS
77  for (auto s : profiles.first)
78  REQUIRE_NOTHROW(s.stop());
79  for (auto s : profiles.first)
80  REQUIRE_NOTHROW(s.close());
81 
82  // Verify frames arrived for all the profiles specified
83  std::stringstream active_profiles, streams_arrived;
84  active_profiles << "Profiles requested : " << profiles.second.size() << std::endl;
85  for (auto& pf : profiles.second)
86  active_profiles << pf << std::endl;
87  streams_arrived << "Streams recorded : " << frames_per_stream.size() << std::endl;
88  for (auto& frec : frames_per_stream)
89  streams_arrived << frec.first << ": frames = " << frec.second << std::endl;
90 
91  CAPTURE(active_profiles.str().c_str());
92  CAPTURE(streams_arrived.str().c_str());
93  REQUIRE(profiles.second.size() == frames_per_stream.size());
94  std::stringstream s;
95  s << "Streaming cycle " << i << " iteration " << iter << " completed,\n"
96  << active_profiles.str() << std::endl << streams_arrived.str() << std::endl;
97  WARN(s.str().c_str());
98 
99  if (drops_count)
100  {
101  std::stringstream s;
102  for (auto& str : drop_descriptions)
103  {
104  s << str << std::endl;
105  }
106  WARN("\n\n\n!!!!!!!!!!!!!!!!!!!!!!!!!!! " << drops_count << " Drop were identified !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n\n");
107  WARN(s.str().c_str());
108  REQUIRE(false);
109  }
110  }
111 
112  if (dev.is<rs400::advanced_mode>())
113  {
114  auto advanced = dev.as<rs400::advanced_mode>();
115  if (advanced.is_enabled())
116  {
117  std::cout << "Iteration " << iter << " ended, resetting device..." << std::endl;
118  advanced.hardware_reset();
119  std::this_thread::sleep_for(std::chrono::seconds(3));
120  }
121  }
122  else
123  {
124  FAIL("Device doesn't support AdvancedMode API");
125  }
126  }
127  }
128  }
129 }
130 
131 
132 TEST_CASE("Frame Drops", "[live]"){
133  {
134  rs2::context ctx;
135  std::condition_variable cv;
136  std::mutex m;
137 
138  if (make_context(SECTION_FROM_TEST_NAME, &ctx))
139  {
140  //rs2::log_to_console(RS2_LOG_SEVERITY_DEBUG);
141  rs2::log_to_file(RS2_LOG_SEVERITY_DEBUG,"lrs_frame_drops_repro.txt");
142 
143  for (size_t iter = 0; iter < 1000; iter++)
144  {
145  std::vector<rs2::device> list;
146  REQUIRE_NOTHROW(list = ctx.query_devices(RS2_PRODUCT_LINE_ANY));
147  REQUIRE(list.size());
148 
149  auto dev = list[0];
150  bool is_l500_device = false;
151  if (dev.supports(RS2_CAMERA_INFO_PRODUCT_LINE) &&
152  std::string(dev.get_info(RS2_CAMERA_INFO_PRODUCT_LINE)) == "L500")
153  {
154  is_l500_device = true;
155  }
156 
157  CAPTURE(dev.get_info(RS2_CAMERA_INFO_NAME));
158  disable_sensitive_options_for(dev);
159 
160  std::mutex m;
161  size_t drops_count=0;
162  bool all_streams = true;
163  int fps = is_usb3(dev) ? 60 : 15; // In USB2 Mode the devices will switch to lower FPS rates
164  if (is_l500_device)
165  fps = 30;
166  float interval_msec = 1000.f / fps;
167 
168  for (auto i = 0; i < 200; i++)
169  {
170  std::map<std::string, size_t> frames_per_stream{};
171  std::map<std::string, size_t> last_frame_per_stream{};
172  std::map<std::string, double> last_frame_ts_per_stream{};
173  std::map<std::string, rs2_timestamp_domain> last_ts_domain_per_stream{};
174  std::vector<std::string> drop_descriptions;
175  bool iter_finished =false;
176 
177  int width = is_l500_device ? 640 : 848;
178  int height = 480;
179  auto profiles = configure_all_supported_streams(dev, width, height, fps);
180  //for l500 - auto profiles = configure_all_supported_streams(dev, 640, 480, fps);
181  drops_count=0;
182 
183  auto start_time = std::chrono::high_resolution_clock::now();
184  std::stringstream ss;
185  ss << "Iteration " << i << " started, time = " << std::dec << start_time.time_since_epoch().count() << std::endl;
186  std::string syscl = "echo \"timecheck: $(date +%s.%N) = $(date +%FT%T,%N)\" | sudo tee /dev/kmsg";
187  auto r = system(syscl.c_str());
188  ss << "sys call result = " << r;
189  rs2::log(RS2_LOG_SEVERITY_INFO,ss.str().c_str());
190  std::cout << ss.str().c_str() << std::endl;
191  for (auto s : profiles.first)
192  {
193  REQUIRE_NOTHROW(s.start([&m, &frames_per_stream,&last_frame_per_stream,&last_frame_ts_per_stream,&last_ts_domain_per_stream,&drops_count,
194  &drop_descriptions,&cv,&all_streams,&iter_finished,start_time,profiles,interval_msec,syscl](rs2::frame f)
195  {
196  auto time_elapsed = std::chrono::duration<double, std::milli>(std::chrono::high_resolution_clock::now() - start_time);
197  auto stream_name = f.get_profile().stream_name();
198  auto fn = f.get_frame_number();
199  auto ts = f.get_timestamp();
200  auto ts_dom = f.get_frame_timestamp_domain();
201 
202  if (frames_per_stream[stream_name])
203  {
204  auto prev_fn = last_frame_per_stream[stream_name];
205  auto prev_ts = last_frame_ts_per_stream[stream_name];
206  auto prev_ts_dom = last_ts_domain_per_stream[stream_name];
207  auto delta_t = ts - prev_ts;
208  auto min_delay = interval_msec*3.5;
209  auto max_delay = interval_msec*20;
210 
211  auto arrival_time = std::chrono::duration<double, std::milli>(std::chrono::high_resolution_clock::now() - start_time);
212  // Skip events during the first 2 second
213  if (time_elapsed.count() > 2000)
214  {
215  if (RS2_FORMAT_MOTION_XYZ32F != f.get_profile().format())
216  {
217  if (
218  ((delta_t >= min_delay) && (RS2_TIMESTAMP_DOMAIN_SYSTEM_TIME !=ts_dom) && (ts_dom ==prev_ts_dom)))
219  {
220  if ((fn - prev_fn) > 1)
221  drops_count++;
222  std::stringstream s;
223  s << "Frame drop was recognized for " << stream_name << " jump from fn " << prev_fn << " to fn " << fn
224  << " from " << std::fixed << std::setprecision(3) << prev_ts << " to "
225  << ts << " while expected ts = " << (prev_ts + interval_msec)
226  << ", ts domain " << ts_dom
227  << " time elapsed: " << time_elapsed.count()/1000.f << " sec, host time: "
228  << std::chrono::high_resolution_clock::now().time_since_epoch().count();
229  if (f.supports_frame_metadata(RS2_FRAME_METADATA_FRAME_TIMESTAMP))
230  s << " hw ts: " << f.get_frame_metadata(RS2_FRAME_METADATA_FRAME_TIMESTAMP) << " = 0x"
231  << std::hex << f.get_frame_metadata(RS2_FRAME_METADATA_FRAME_TIMESTAMP) << std::dec;
232  WARN(s.str().c_str());
233  if ((delta_t < max_delay) || (fabs(fn - prev_fn)< 20)) // Skip inconsistent frame numbers due to intermittent metadata
234  {
235  std::cout << "Frame interval = " << delta_t << ", max = " << max_delay << std::endl;
236  std::cout << "fn = " << fn << ", prev_fn = " << prev_fn << std::endl;
237  system(syscl.c_str());
238  exit(1);
239  }
240  drop_descriptions.emplace_back(s.str().c_str());
241  }
242  }
243 // if (profiles.second.size() != frames_per_stream.size()) // Some streams failed to start
244 // {
245 // all_streams = false;
246 // }
247  }
248 
249  // Status prints
250  auto sec_now = int(arrival_time.count()) / 1000;
251  if (sec_now && (sec_now != (int(time_elapsed.count())/ 1000)) )
252  std::cout << "Test runs for " << int(arrival_time.count()) / 1000 << " seconds" << std::endl;
253  // Every 10th second print number of frames arrived
254  if ((int(arrival_time.count()) / 10000) != (int(time_elapsed.count())/ 10000) )
255  {
256  std::stringstream s;
257  s << "Frames arrived: ";
258  for (const auto& entry : frames_per_stream)
259  s << entry.first << " : " << entry.second << ", ";
260  s << std::endl;
261  std::cout << s.str().c_str();
262  }
263 
264  // Stop test iteration after 20 sec
265  if (arrival_time.count() > 20000)
266  {
267  std::lock_guard<std::mutex> lock(m);
268  iter_finished = true;
269  cv.notify_all();
270  }
271  time_elapsed = arrival_time;
272  }
273  ++frames_per_stream[stream_name];
274  last_frame_per_stream[stream_name] = fn;
275  last_frame_ts_per_stream[stream_name] = ts;
276  {
277  std::lock_guard<std::mutex> lock(m);
278  if (drops_count || (!all_streams))
279  cv.notify_all();
280  }
281  }));
282  }
283 
284  // block till error is reproduced
285  {
286  std::unique_lock<std::mutex> lk(m);
287  cv.wait(lk, [&drops_count,&all_streams,&iter_finished]{return (drops_count>0 || (!all_streams) || iter_finished);});
288  //std::this_thread::sleep_for(std::chrono::milliseconds(200)); // add some sleep to record additional errors, if any
289  }
290  std::cout << "Drops = " << drops_count << ", All streams valid = " << int(all_streams) << " iter completed = " << int(iter_finished) << std::endl;
291  // Stop & flush all active sensors. The separation is intended to semi-confirm the FPS
292  for (auto s : profiles.first)
293  REQUIRE_NOTHROW(s.stop());
294  for (auto s : profiles.first)
295  REQUIRE_NOTHROW(s.close());
296 
297  // Verify frames arrived for all the profiles specified
298  std::stringstream active_profiles, streams_arrived;
299  active_profiles << "Profiles requested : " << profiles.second.size() << std::endl;
300  for (auto& pf : profiles.second)
301  active_profiles << pf << std::endl;
302  streams_arrived << "Streams recorded : " << frames_per_stream.size() << std::endl;
303  for (auto& frec : frames_per_stream)
304  streams_arrived << frec.first << ": frames = " << frec.second << std::endl;
305 
306  CAPTURE(active_profiles.str().c_str());
307  CAPTURE(streams_arrived.str().c_str());
308 
309  std::stringstream s;
310  s << "Streaming cycle " << i << " iteration " << iter << " completed,\n"
311  << active_profiles.str() << std::endl << streams_arrived.str() << std::endl;
312  WARN(s.str().c_str());
313 
314  if (drops_count)
315  {
316  std::stringstream s;
317  for (auto& str : drop_descriptions)
318  {
319  s << str << std::endl;
320  }
321  WARN("\n!!! " << drops_count << " Drop were identified !!!\n");
322  WARN(s.str().c_str());
323  }
324 
325  REQUIRE(profiles.second.size() == frames_per_stream.size());
326  //REQUIRE( drops_count == 0);
327  REQUIRE( all_streams);
328  }
329 
330  if (dev.is<rs400::advanced_mode>())
331  {
332  auto advanced = dev.as<rs400::advanced_mode>();
333  if (advanced.is_enabled())
334  {
335  std::cout << "Iteration " << iter << " ended, resetting device..." << std::endl;
336  advanced.hardware_reset();
337  std::this_thread::sleep_for(std::chrono::seconds(3));
338  }
339  }
340  else
341  {
342  if(!is_l500_device)
343  FAIL("Device doesn't support AdvancedMode API");
344  }
345  }
346  }
347  }
348 }
349 
350 
351 TEST_CASE("DSO-15050", "[live]")
352 {
353  {
354  rs2::log_to_file(RS2_LOG_SEVERITY_DEBUG, "lrs_log.txt");
355  //rs2::log_to_console(RS2_LOG_SEVERITY_DEBUG);
356  rs2::context ctx;
357  if (make_context(SECTION_FROM_TEST_NAME, &ctx))
358  {
359  for (size_t iter = 0; iter < 10000; iter++)
360  {
361  std::vector<rs2::device> list;
362  REQUIRE_NOTHROW(list = ctx.query_devices());
363  REQUIRE(list.size());
364 
365  auto dev = std::make_shared<device>(list.front());
366 
367  disable_sensitive_options_for(*dev);
368  CAPTURE(dev->get_info(RS2_CAMERA_INFO_NAME));
369  std::string serial;
370  REQUIRE_NOTHROW(serial = dev->get_info(RS2_CAMERA_INFO_SERIAL_NUMBER));
371 
372  // Precausion
373  for (auto&& sensor : dev->query_sensors())
374  {
375  if (sensor.supports(RS2_OPTION_GLOBAL_TIME_ENABLED))
376  sensor.set_option(RS2_OPTION_GLOBAL_TIME_ENABLED, 0.f);
377  }
378 
379  std::mutex m;
380  int fps = is_usb3(*dev) ? 30 : 6; // In USB2 Mode the devices will switch to lower FPS rates
381 
382  for (auto i = 0; i < 1; i++)
383  {
384  std::map<std::string, size_t> frames_per_stream{};
385  std::map<std::string, size_t> frames_indx_per_stream{};
386  std::vector<std::string> drop_descriptions;
387 
388  auto profiles = configure_all_supported_streams(*dev, 1280, 720, fps);
389  size_t drops_count = 0;
390 
391  for (auto s : profiles.first)
392  {
393  REQUIRE_NOTHROW(s.start([&m, &frames_per_stream, &frames_indx_per_stream, &drops_count, &drop_descriptions](rs2::frame f)
394  {
395  std::lock_guard<std::mutex> lock(m);
396  auto stream_name = f.get_profile().stream_name();
397  auto fn = f.get_frame_number();
398 
399  if (frames_per_stream[stream_name])
400  {
401  auto prev_fn = frames_indx_per_stream[stream_name];
402  if ((fn = prev_fn) != 1)
403  {
404  drops_count++;
405  std::stringstream s;
406  s << "Frame drop was recognized for " << stream_name << " jumped from " << prev_fn << " to " << fn;
407  drop_descriptions.emplace_back(s.str().c_str());
408  }
409  }
410  ++frames_per_stream[stream_name];
411  frames_indx_per_stream[stream_name] = fn;
412  }));
413  }
414 
415  std::this_thread::sleep_for(std::chrono::seconds(2));
416  // Stop & flush all active sensors. The separation is intended to semi-confirm the FPS
417  for (auto s : profiles.first)
418  REQUIRE_NOTHROW(s.stop());
419  for (auto s : profiles.first)
420  REQUIRE_NOTHROW(s.close());
421 
422  // Verify frames arrived for all the profiles specified
423  std::stringstream active_profiles, streams_arrived;
424  active_profiles << "Profiles requested : " << profiles.second.size() << std::endl;
425  for (auto& pf : profiles.second)
426  active_profiles << pf << std::endl;
427  streams_arrived << "Streams recorded : " << frames_per_stream.size() << std::endl;
428  for (auto& frec : frames_per_stream)
429  streams_arrived << frec.first << ": frames = " << frec.second << std::endl;
430 
431  CAPTURE(active_profiles.str().c_str());
432  CAPTURE(streams_arrived.str().c_str());
433  REQUIRE(profiles.second.size() == frames_per_stream.size());
434  std::stringstream s;
435  s << "Streaming cycle " << i << " iteration " << iter << " completed,\n"
436  << active_profiles.str() << std::endl << streams_arrived.str() << std::endl;
437  WARN(s.str().c_str());
438 
439  if (drops_count)
440  {
441  std::stringstream s;
442  for (auto& str : drop_descriptions)
443  {
444  s << str << std::endl;
445  }
446  WARN("\n\n\n!!!!!!!!!!!!!!!!!!!!!!!!!!! " << drops_count << " Drop were identified !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n\n");
447  WARN(s.str().c_str());
448  //REQUIRE(false);
449  }
450  }
451 
452  //forcing hardware reset to simulate device disconnection
453  do_with_waiting_for_camera_connection(ctx, dev, serial, [&]()
454  {
455  dev->hardware_reset();
456  std::cout << "Iteration " << iter << " ended, resetting device..." << std::endl;
457  });
458  }
459  }
460  }
461 }
RS2_CAMERA_INFO_PRODUCT_LINE
Definition: rs_sensor.h:33
opencv_pointcloud_viewer.now
now
Definition: opencv_pointcloud_viewer.py:302
s
GLdouble s
Definition: glad/glad/glad.h:2442
m
const GLfloat * m
Definition: glext.h:6814
RS2_CAMERA_INFO_SERIAL_NUMBER
Definition: rs_sensor.h:24
configure_all_supported_streams
std::vector< profile > configure_all_supported_streams(rs2::sensor &sensor, int width=640, int height=480, int fps=60)
Definition: unit-tests-common.h:101
TEST_CASE
TEST_CASE("DSO-14512","[live]")
Definition: unit-tests-regressions.cpp:21
rs2::context::query_devices
device_list query_devices() const
Definition: rs_context.hpp:112
rs2::log
void log(rs2_log_severity severity, const char *message)
Definition: rs.hpp:149
rspy.file.system
system
Definition: file.py:10
rs2
Definition: cah-model.h:10
string
GLsizei const GLchar *const * string
Definition: glad/glad/glad.h:2862
RS2_CAMERA_INFO_NAME
Definition: rs_sensor.h:23
FAIL
#define FAIL(...)
Definition: catch.hpp:17440
RS2_LOG_SEVERITY_DEBUG
Definition: rs_types.h:154
f
GLdouble f
Definition: glad/glad/glad.h:1518
read_bag_example.str
str
Definition: read_bag_example.py:21
RS2_OPTION_GLOBAL_TIME_ENABLED
Definition: rs_option.h:77
rs_frame.hpp
Catch::cout
std::ostream & cout()
r
GLdouble GLdouble r
Definition: glad/glad/glad.h:1854
WARN
#define WARN(msg)
Definition: catch.hpp:17431
CAPTURE
#define CAPTURE(...)
Definition: catch.hpp:17432
REQUIRE
REQUIRE(n_callbacks==1)
height
GLint GLsizei GLsizei height
Definition: glad/glad/glad.h:1398
cv
static std::condition_variable cv
Definition: unit-tests-common.h:613
SECTION_FROM_TEST_NAME
#define SECTION_FROM_TEST_NAME
Definition: unit-tests-common.h:196
t265_stereo.profiles
profiles
Definition: t265_stereo.py:139
rs2::log_to_file
void log_to_file(rs2_log_severity min_severity, const char *file_path=nullptr)
Definition: rs.hpp:26
rs2::sensor::supports
bool supports(rs2_camera_info info) const
Definition: rs_sensor.hpp:125
make_context
bool make_context(const char *id, rs2::context *ctx, std::string min_api_version="0.0.0")
Definition: unit-tests-common.h:317
RS2_PRODUCT_LINE_ANY
#define RS2_PRODUCT_LINE_ANY
Definition: rs_context.h:91
RS2_LOG_SEVERITY_INFO
Definition: rs_types.h:155
rs400::advanced_mode
Definition: rs_advanced_mode.hpp:14
do_with_waiting_for_camera_connection
std::shared_ptr< rs2::device > do_with_waiting_for_camera_connection(rs2::context ctx, std::shared_ptr< rs2::device > dev, std::string serial, std::function< void()> operation)
Definition: unit-tests-common.h:804
convert_to_bag.fps
fps
Definition: convert_to_bag.py:27
REQUIRE_NOTHROW
REQUIRE_NOTHROW(rs2_log(RS2_LOG_SEVERITY_INFO,"Log message using rs2_log()", nullptr))
i
int i
Definition: rs-pcl-color.cpp:54
disable_sensitive_options_for
void disable_sensitive_options_for(rs2::sensor &sen)
Definition: unit-tests-common.h:205
is_usb3
bool is_usb3(const rs2::device &dev)
Definition: unit-tests-common.h:248
rs2::options::set_option
void set_option(rs2_option option, float value) const
Definition: rs_options.hpp:99
rs_types.hpp
width
GLint GLsizei width
Definition: glad/glad/glad.h:1398

librealsense2
Author(s): Sergey Dorodnicov , Doron Hirshberg , Mark Horn , Reagan Lopez , Itay Carpis
autogenerated on Mon May 3 2021 02:50:13