View Issue Details

IDProjectCategoryView StatusLast Update
0032870Open CASCADEOCCT:Application Frameworkpublic2022-04-10 10:49
Reporterkgv Assigned Tompv  
PrioritynormalSeverityminor 
Status verifiedResolutionfixed 
Product Version7.6.0 
Target Version7.7.0 
Summary0032870: Tests - bugs/caf/bug31918_1 is unstable
DescriptionTest case bugs/caf/bug31918_1 is unstable and fails from time to time with error like this:
Quater of document open time 2738.95 mcs
Error : loading of quater of the document content too slow relatively to the whole document load
...
Four quaters of document open time 4780.25 mcs
Quater of document without arrays open time 2521 mcs
Half of document arrays open time 2352 mcs


Test case has two problems:
set quater_time [lindex [time {
  Open ${docname} D2 -read0:2
  Close D2
} 20] 0]
puts "Quater of document open time $quater_time mcs"

# Check that open of quater of the document is at least twice faster than open of whole.
if { [expr $quater_time * 2] > $whole_time } {
  puts "Error : loading of quater of the document content too slow relatively to the whole document load"
}

- Compared values look too small (a couple of milliseconds) to be measured reliably (2ms vs. 4ms).
- `time` Tcl command is used for measurements instead of `dchrono`, which means that test compares **elapsed time** - an unreliable measure within multiple concurrent tests execution.

http://occt-tests/IR-2022-03-11-OCCT/Windows-64-VC14/bugs/caf/bug31918_1.html
Steps To Reproducebugs caf bug31918_1
TagsNo tags attached.
Test case numberbugs/caf/bug31918_1

Relationships

child of 0031918 closedbugmaster Application Framework - New binary format for fast reading part of OCAF document 

Activities

mpv

2022-03-14 09:57

developer   ~0107271

Dear KGV,

As you can see, the second argument of calling "time" is 20, it takes average of time of opening documents among 20. So, technically it is not "2ms vs. 4ms" but "40ms vs. 80ms".

What is your proposal how to improve this test? What do you think, is it worth to increase the test execution time, how much?

I have an idea to make measurement of each value several times and take the minimal one (the one, less affected by parallel threads). From your experience of writing tests, would it be helpful in this case?

kgv

2022-03-14 10:24

developer   ~0107272

Last edited: 2022-03-14 10:24

@mpv

First of all what bothers me is that `time` measures elapsed time, not CPU time, which makes it very dependent on execution environment.
Using CPU time from `dchrono` should make test more reliable.

As for duration - 2ms (and even 20ms) is a pretty small number. Increasing a duration in 10x times might make sense.

git

2022-03-14 18:04

administrator   ~0107285

Branch CR32870 has been created by mpv.

SHA-1: 96505bea0986ec71dd22148758393c66f605b6d0


Detailed log of new commits:

Author: mpv
Date: Mon Mar 14 18:03:59 2022 +0300

    0032870: Tests - bugs/caf/bug31918_1 is unstable
    
    Improved the test stability: created 10 iterations of measurements and take the minimum to
    minimize the affect of other processes and threads; increased the compare range of
    the quarter and the whole of the document load.

mpv

2022-03-14 18:06

developer   ~0107286

It seems the test case is improved and become work more stable.

smoskvin

2022-03-19 10:20

administrator   ~0107360

Combination -
OCCT branch : IR-2022-03-18
master SHA - e720157864e4bb408d607298610b464977491228
49e51745631c52b6c452c65adae4d6dfa21a1b1e
Products branch : IR-2022-03-18 SHA - 6db9c4d2fd384d381f9025284eac8b04e33ac8e8
was compiled on Linux, MacOS and Windows platforms and tested in optimize mode.

Number of compiler warnings:
No new/fixed warnings

Regressions/Differences/Improvements:
No regressions/differences

CPU differences:
Debian80-64:
OCCT
Total CPU difference: 18487.460000000385 / 18395.730000000258 [+0.50%]
Products
Total CPU difference: 11709.300000000132 / 11708.150000000112 [+0.01%]
Windows-64-VC14:
OCCT
Total CPU difference: 20412.546875 / 20350.609375 [+0.30%]
Products
Total CPU difference: 13181.25 / 13154.5625 [+0.20%]


Image differences :
No differences that require special attention

Memory differences :
No differences that require special attention

git

2022-04-04 21:22

administrator   ~0107609

Branch CR32870 has been deleted by kgv.

SHA-1: 96505bea0986ec71dd22148758393c66f605b6d0

kgv

2022-04-06 09:52

developer   ~0107654

Test case is still unstable on Jenkins.

git

2022-04-06 11:08

administrator   ~0107659

Branch CR32870_1 has been created by mpv.

SHA-1: 5444e993f5b0169f2274483f6f5063f3d2a728a4


Detailed log of new commits:

Author: mpv
Date: Wed Apr 6 11:08:20 2022 +0300

    0032870: Tests - bugs/caf/bug31918_1 is unstable
    
    # Make the compared values more stable.

mpv

2022-04-07 15:01

developer   ~0107709

Additionally fixed in CR32870_1. Updated comparison coeffs to make test one more stable.
http://jenkins-test-occt.nnov.opencascade.com/job/CR32870_1-master-MPV-OCCT-Debian80-64-opt-test-compare/2/
http://jenkins-test-occt.nnov.opencascade.com//view/CR32870_1-master-MPV/view/COMPARE/job/CR32870_1-master-MPV-OCCT-Windows-64-VC14-opt-test-compare/
http://jenkins-test-occt.nnov.opencascade.com/job/CR32870_1-master-MPV-Products-Windows-64-VC14-opt-test-compare/2/
http://jenkins-test-occt.nnov.opencascade.com/job/CR32870_1-master-MPV-Products-Debian80-64-opt-test-compare/1/

smoskvin

2022-04-09 09:50

administrator   ~0107791

Combination -
OCCT branch : IR-2022-04-08
master SHA - 7021de2fe7a69d4c788ccf43b8b096dbcc8597c8
49e51745631c52b6c452c65adae4d6dfa21a1b1e
Products branch : IR-2022-04-08 SHA - e16d959d441765c483049307ba7293173532103a
was compiled on Linux, MacOS and Windows platforms and tested in optimize mode.

Number of compiler warnings:
No new/fixed warnings

Regressions/Differences/Improvements:
No regressions/differences

CPU differences:
Debian80-64:
OCCT
Total CPU difference: 18452.87000000039 / 18490.94000000032 [-0.21%]
Products
Total CPU difference: 11761.310000000152 / 11719.920000000124 [+0.35%]
Windows-64-VC14:
OCCT
Total CPU difference: 20539.828125 / 20552.71875 [-0.06%]
Products
Total CPU difference: 13248.21875 / 13242.609375 [+0.04%]


Image differences :
No differences that require special attention

Memory differences :
No differences that require special attention

git

2022-04-10 10:49

administrator   ~0107822

Branch CR32870_1 has been deleted by mnt.

SHA-1: 5444e993f5b0169f2274483f6f5063f3d2a728a4

Related Changesets

occt: master 7573a45d

2022-03-14 18:03:59

mpv


Committer: smoskvin Details Diff
0032870: Tests - bugs/caf/bug31918_1 is unstable

Improved the test stability: created 10 iterations of measurements and take the minimum to
minimize the affect of other processes and threads; increased the compare range of
the quarter and the whole of the document load.
Affected Issues
0032870
mod - tests/bugs/caf/bug31918_1 Diff File

occt: master 1fff4ad5

2022-04-06 11:08:20

mpv


Committer: smoskvin Details Diff
0032870: Tests - bugs/caf/bug31918_1 is unstable

# Make the compared values more stable.
Affected Issues
0032870
mod - tests/bugs/caf/bug31918_1 Diff File

Issue History

Date Modified Username Field Change
2022-03-12 15:09 kgv New Issue
2022-03-12 15:09 kgv Assigned To => mpv
2022-03-12 15:10 kgv Description Updated
2022-03-12 15:10 kgv Test case number => bugs/caf/bug31918_1
2022-03-12 15:11 kgv Relationship added child of 0031918
2022-03-12 15:11 kgv Product Version 7.7.0 => 7.6.0
2022-03-12 15:11 kgv Description Updated
2022-03-14 09:57 mpv Note Added: 0107271
2022-03-14 10:24 kgv Note Added: 0107272
2022-03-14 10:24 kgv Note Edited: 0107272
2022-03-14 18:04 git Note Added: 0107285
2022-03-14 18:06 mpv Assigned To mpv => kgv
2022-03-14 18:06 mpv Status new => resolved
2022-03-14 18:06 mpv Steps to Reproduce Updated
2022-03-14 18:06 mpv Note Added: 0107286
2022-03-14 18:14 kgv Assigned To kgv => bugmaster
2022-03-14 18:14 kgv Status resolved => reviewed
2022-03-19 10:20 smoskvin Status reviewed => tested
2022-03-19 10:20 smoskvin Note Added: 0107360
2022-03-19 16:35 smoskvin Changeset attached => occt master 7573a45d
2022-03-19 16:35 mpv Assigned To bugmaster => mpv
2022-03-19 16:35 mpv Status tested => verified
2022-03-19 16:35 mpv Resolution open => fixed
2022-04-04 21:22 git Note Added: 0107609
2022-04-06 09:52 kgv Status verified => feedback
2022-04-06 09:52 kgv Resolution fixed => reopened
2022-04-06 09:52 kgv Note Added: 0107654
2022-04-06 09:52 kgv Status feedback => assigned
2022-04-06 11:08 git Note Added: 0107659
2022-04-07 15:01 mpv Assigned To mpv => kgv
2022-04-07 15:01 mpv Status assigned => resolved
2022-04-07 15:01 mpv Note Added: 0107709
2022-04-07 15:54 kgv Assigned To kgv => bugmaster
2022-04-07 15:54 kgv Status resolved => reviewed
2022-04-09 09:50 smoskvin Status reviewed => tested
2022-04-09 09:50 smoskvin Note Added: 0107791
2022-04-10 10:42 smoskvin Changeset attached => occt master 1fff4ad5
2022-04-10 10:42 mpv Assigned To bugmaster => mpv
2022-04-10 10:42 mpv Status tested => verified
2022-04-10 10:42 mpv Resolution reopened => fixed
2022-04-10 10:49 git Note Added: 0107822