tests:ges: check_edit_in_frames_with_framerate_mismatch sometimes fails
Over 100 runs it failed 3 times:
valgrind.check.gst-editing-services.check_edit_in_frames_with_framerate_mismatch
**-> Running scenario /builds/thiblahute/gstreamer/subprojects/gst-editing-services/tests/check/scenarios/check_edit_in_frames_with_framerate_mismatch.scenario on pipeline gespipeline0**
Executing `add-clip` at check_edit_in_frames_with_framerate_mismatch.scenario:8 (
- name=clip
- asset-id="time-overlay\,framerate\=120/1"
- layer-priority=0
- type=GESSourceClip
- pattern=blue
- duration=f240
- inpoint=f100
)
⇨ Action `add-clip` at check_edit_in_frames_with_framerate_mismatch.scenario:8 done 'OK' (duration: 0:00:00.375458834)
Executing `set-child-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:9 (
- element-name=clip
- time-mode=time-code
)
⇨ Action `set-child-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:9 done 'OK' (duration: 0:00:00.004387527)
Executing `pause` at check_edit_in_frames_with_framerate_mismatch.scenario:10 ( )
track-element-videorate --> Setting qos to false
track-element-videoconvert --> Setting qos to false
track-element-videoscale --> Setting qos to false
track-element-videoflip --> Setting qos to false
videoconvert1 --> Setting qos to false
timecodestamper0 --> Setting qos to false
Timeline description: `+track video +test-clip blue asset-id="time-overlay, framerate=(fraction)120/1;" tt=GES_TRACK_TYPE_AUDIO+GES_TRACK_TYPE_VIDEO inpoint=833333334 d=8.000000 n=clip p=blue set-halignment left set-pattern blue set-time-mode time-code set-valignment top`
====================
layer 0:
--------
- clip
start=0:00:00.000000000 inpoint=0:00:00.833333334 duration=0:00:08.000000000
conv2 --> Setting qos to false
videobalance --> Setting qos to false
scale --> Setting qos to false
conv --> Setting qos to false
sink --> Setting max-lateness to -1
fakevideosink0 --> Setting max-lateness to -1 ⇨ Action `pause` at check_edit_in_frames_with_framerate_mismatch.scenario:10 done 'ASYNC' (duration: 0:00:04.096611092)
Executing `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:12 (
- sinkpad-caps=video/x-raw
- timecode-frame-number=100
)
0:00:26.695904954 25771 0x5d9ef30 ERROR validate gst-validate-reporter.c:198:gst_validate_report_valist: <check_edit_in_frames_with_framerate_mismatch.scenario> 3130 (critical) : scenario: The execution of an action did not properly happen : Last buffer frame number '0' is different than the expected one: '100'
⇨ Action `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:12 done 'ERROR(reported)' (duration: 0:00:00.079593738)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:14 (
- element-name=clip
- edit-mode=normal
- position=1
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:14 done 'OK' (duration: 0:00:00.014338707)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:16 (
- element-name=clip
- edit-mode=edit_trim
- edge=start
- source-frame=60
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:16 done 'OK' (duration: 0:00:00.018061628)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:17 (
- element-name=clip
- position=0
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:17 done 'OK' (duration: 0:00:00.000592583)
Executing `commit` at check_edit_in_frames_with_framerate_mismatch.scenario:18 ( )
<position: 0:00:00.000000000 duration: 0:00:08.333333335 speed: 1.000000 />
<position: 0:00:00.000000000 duration: 0:00:08.333333335 speed: 1.000000 />
<position: 0:00:00.000000000 duration: 0:00:08.333333335 speed: 1.000000 />
<position: 0:00:00.000000000 duration: 0:00:08.333333335 speed: 1.000000 />
⇨ Action `commit` at check_edit_in_frames_with_framerate_mismatch.scenario:18 done 'ASYNC' (duration: 0:00:01.199901246)
Executing `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:19 (
- sinkpad-caps=video/x-raw
- timecode-frame-number=60
)
⇨ Action `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:19 done 'OK' (duration: 0:00:00.000859271)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:21 (
- element-name=clip
- edit-mode=edit_trim
- edge=start
- source-frame=120
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:21 done 'OK' (duration: 0:00:00.001147271)
Executing `check-ges-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:22 (
- element-name=clip
- start=0.5
)
⇨ Action `check-ges-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:22 done 'OK' (duration: 0:00:00.001492104)
Executing `stop` at check_edit_in_frames_with_framerate_mismatch.scenario:23 ( )
⇨ Action `stop` at check_edit_in_frames_with_framerate_mismatch.scenario:23 done 'OK' (duration: 0:00:00.001867778)
check_edit_in_frames_with_framerate_mismatch.scenario --> State change request NULL, quitting application
issue : FLUSH_START events that are part of the same pipeline 'operation' should have the same seqnum
Detected on <GESVideoTestSource:nlesource1:src>
Detected on <video_nlecomposition0:src>
Description : when events/messages are created from another event/message, they should have their seqnums set to the original event/message seqnum
warning : received an unexpected flush stop event
Detected on <GESVideoTestSource:nlesource1:src>
critical : The execution of an action did not properly happen
Detected on <check_edit_in_frames_with_framerate_mismatch.scenario>
Details : Last buffer frame number '0' is different than the expected one: '100'
dotfile : no dotfile produced as GST_DEBUG_DUMP_DOT_DIR is not set.
**Got criticals. Return value set to 18**:
* critical error Last buffer frame number '0' is different than the expected one: '100'
Issues found: 3
===> Iteration 2
**-> Running scenario /builds/thiblahute/gstreamer/subprojects/gst-editing-services/tests/check/scenarios/check_edit_in_frames_with_framerate_mismatch.scenario on pipeline gespipeline0**
Executing `add-clip` at check_edit_in_frames_with_framerate_mismatch.scenario:8 (
- name=clip
- asset-id="time-overlay\,framerate\=120/1"
- layer-priority=0
- type=GESSourceClip
- pattern=blue
- duration=f240
- inpoint=f100
)
⇨ Action `add-clip` at check_edit_in_frames_with_framerate_mismatch.scenario:8 done 'OK' (duration: 0:00:00.410103840)
Executing `set-child-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:9 (
- element-name=clip
- time-mode=time-code
)
⇨ Action `set-child-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:9 done 'OK' (duration: 0:00:00.004748390)
Executing `pause` at check_edit_in_frames_with_framerate_mismatch.scenario:10 ( )
track-element-videorate --> Setting qos to false
track-element-videoconvert --> Setting qos to false
track-element-videoscale --> Setting qos to false
track-element-videoflip --> Setting qos to false
videoconvert1 --> Setting qos to false
timecodestamper0 --> Setting qos to false
conv2 --> Setting qos to false
videobalance --> Setting qos to false
scale --> Setting qos to false
conv --> Setting qos to false
sink --> Setting max-lateness to -1
fakevideosink0 --> Setting max-lateness to -1
Timeline description: `+track video +test-clip blue asset-id="time-overlay, framerate=(fraction)120/1;" tt=GES_TRACK_TYPE_AUDIO+GES_TRACK_TYPE_VIDEO inpoint=833333334 d=8.000000 n=clip p=blue set-halignment left set-pattern blue set-time-mode time-code set-valignment top`
====================
layer 0:
--------
- clip
start=0:00:00.000000000 inpoint=0:00:00.833333334 duration=0:00:08.000000000
<position: 0:00:00.000000000 duration: 0:00:08.000000001 speed: 1.000000 />
⇨ Action `pause` at check_edit_in_frames_with_framerate_mismatch.scenario:10 done 'ASYNC' (duration: 0:00:03.816909163)
Executing `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:12 (
- sinkpad-caps=video/x-raw
- timecode-frame-number=100
)
0:00:30.047035519 42351 0x5d9ef30 ERROR validate gst-validate-reporter.c:198:gst_validate_report_valist: <check_edit_in_frames_with_framerate_mismatch.scenario> 3130 (critical) : scenario: The execution of an action did not properly happen : Last buffer frame number '0' is different than the expected one: '100'
⇨ Action `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:12 done 'ERROR(reported)' (duration: 0:00:00.030017013)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:14 (
- element-name=clip
- edit-mode=normal
- position=1
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:14 done 'OK' (duration: 0:00:00.021779937)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:16 (
- element-name=clip
- edit-mode=edit_trim
- edge=start
- source-frame=60
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:16 done 'OK' (duration: 0:00:00.013815039)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:17 (
- element-name=clip
- position=0
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:17 done 'OK' (duration: 0:00:00.000996833)
Executing `commit` at check_edit_in_frames_with_framerate_mismatch.scenario:18 ( )
<position: 0:00:00.000000000 duration: 0:00:08.333333335 speed: 1.000000 />
<position: 0:00:00.000000000 duration: 0:00:08.333333335 speed: 1.000000 />
⇨ Action `commit` at check_edit_in_frames_with_framerate_mismatch.scenario:18 done 'ASYNC' (duration: 0:00:00.517977144)
Executing `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:19 (
- sinkpad-caps=video/x-raw
- timecode-frame-number=60
)
⇨ Action `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:19 done 'OK' (duration: 0:00:00.002019047)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:21 (
- element-name=clip
- edit-mode=edit_trim
- edge=start
- source-frame=120
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:21 done 'OK' (duration: 0:00:00.001601822)
Executing `check-ges-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:22 (
- element-name=clip
- start=0.5
)
⇨ Action `check-ges-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:22 done 'OK' (duration: 0:00:00.001521342)
Executing `stop` at check_edit_in_frames_with_framerate_mismatch.scenario:23 ( )
⇨ Action `stop` at check_edit_in_frames_with_framerate_mismatch.scenario:23 done 'OK' (duration: 0:00:00.003330403)
<position: 0:00:00.000000000 duration: 0:00:08.333333335 speed: 1.000000 />
check_edit_in_frames_with_framerate_mismatch.scenario --> State change request NULL, quitting application
issue : FLUSH_START events that are part of the same pipeline 'operation' should have the same seqnum
Detected on <GESVideoTestSource:nlesource1:src>
Detected on <video_nlecomposition0:src>
Description : when events/messages are created from another event/message, they should have their seqnums set to the original event/message seqnum
warning : received an unexpected flush stop event
Detected on <GESVideoTestSource:nlesource1:src>
critical : The execution of an action did not properly happen
Detected on <check_edit_in_frames_with_framerate_mismatch.scenario>
Details : Last buffer frame number '0' is different than the expected one: '100'
dotfile : no dotfile produced as GST_DEBUG_DUMP_DOT_DIR is not set.
**Got criticals. Return value set to 18**:
* critical error Last buffer frame number '0' is different than the expected one: '100'
Issues found: 3
===> Iteration 3
**-> Running scenario /builds/thiblahute/gstreamer/subprojects/gst-editing-services/tests/check/scenarios/check_edit_in_frames_with_framerate_mismatch.scenario on pipeline gespipeline0**
Executing `add-clip` at check_edit_in_frames_with_framerate_mismatch.scenario:8 (
- name=clip
- asset-id="time-overlay\,framerate\=120/1"
- layer-priority=0
- type=GESSourceClip
- pattern=blue
- duration=f240
- inpoint=f100
)
⇨ Action `add-clip` at check_edit_in_frames_with_framerate_mismatch.scenario:8 done 'OK' (duration: 0:00:00.375429918)
Executing `set-child-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:9 (
- element-name=clip
- time-mode=time-code
)
⇨ Action `set-child-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:9 done 'OK' (duration: 0:00:00.004428306)
Executing `pause` at check_edit_in_frames_with_framerate_mismatch.scenario:10 ( )
track-element-videorate --> Setting qos to false
track-element-videoconvert --> Setting qos to false
track-element-videoscale --> Setting qos to false
track-element-videoflip --> Setting qos to false
videoconvert1 --> Setting qos to false
timecodestamper0 --> Setting qos to false
conv2 --> Setting qos to false
videobalance --> Setting qos to false
scale --> Setting qos to false
conv --> Setting qos to false
sink --> Setting max-lateness to -1
fakevideosink0 --> Setting max-lateness to -1<position: 0:00:00.000000000 duration: 0:00:08.000000001 speed: 1.000000 />
⇨ Action `pause` at check_edit_in_frames_with_framerate_mismatch.scenario:10 done 'ASYNC' (duration: 0:00:04.663148499)
Timeline description: `+track video +test-clip blue asset-id="time-overlay, framerate=(fraction)120/1;" tt=GES_TRACK_TYPE_AUDIO+GES_TRACK_TYPE_VIDEO inpoint=833333334 d=8.000000 n=clip p=blue set-halignment left set-pattern blue set-time-mode time-code set-valignment top`
====================
layer 0:
--------
- clip
start=0:00:00.000000000 inpoint=0:00:00.833333334 duration=0:00:08.000000000
Executing `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:12 (
- sinkpad-caps=video/x-raw
- timecode-frame-number=100
)
0:00:20.580295813 43838 0x5d9ef30 ERROR validate gst-validate-reporter.c:198:gst_validate_report_valist: <check_edit_in_frames_with_framerate_mismatch.scenario> 3130 (critical) : scenario: The execution of an action did not properly happen : Last buffer frame number '0' is different than the expected one: '100'
⇨ Action `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:12 done 'ERROR(reported)' (duration: 0:00:00.020685351)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:14 (
- element-name=clip
- edit-mode=normal
- position=1
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:14 done 'OK' (duration: 0:00:00.014046308)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:16 (
- element-name=clip
- edit-mode=edit_trim
- edge=start
- source-frame=60
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:16 done 'OK' (duration: 0:00:00.013285491)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:17 (
- element-name=clip
- position=0
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:17 done 'OK' (duration: 0:00:00.000507134)
Executing `commit` at check_edit_in_frames_with_framerate_mismatch.scenario:18 ( )
<position: 0:00:00.000000000 duration: 0:00:08.000000001 speed: 1.000000 />
<position: 0:00:00.000000000 duration: 0:00:08.333333335 speed: 1.000000 />
<position: 0:00:00.000000000 duration: 0:00:08.333333335 speed: 1.000000 />
⇨ Action `commit` at check_edit_in_frames_with_framerate_mismatch.scenario:18 done 'ASYNC' (duration: 0:00:00.691906346)
Executing `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:19 (
- sinkpad-caps=video/x-raw
- timecode-frame-number=60
)
⇨ Action `check-last-sample` at check_edit_in_frames_with_framerate_mismatch.scenario:19 done 'OK' (duration: 0:00:00.001491623)
Executing `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:21 (
- element-name=clip
- edit-mode=edit_trim
- edge=start
- source-frame=120
)
⇨ Action `edit` at check_edit_in_frames_with_framerate_mismatch.scenario:21 done 'OK' (duration: 0:00:00.001506652)
Executing `check-ges-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:22 (
- element-name=clip
- start=0.5
)
⇨ Action `check-ges-properties` at check_edit_in_frames_with_framerate_mismatch.scenario:22 done 'OK' (duration: 0:00:00.001573104)
Executing `stop` at check_edit_in_frames_with_framerate_mismatch.scenario:23 ( )
⇨ Action `stop` at check_edit_in_frames_with_framerate_mismatch.scenario:23 done 'OK' (duration: 0:00:00.001897257)
<position: 0:00:00.000000000 duration: 0:00:08.333333335 speed: 1.000000 />
check_edit_in_frames_with_framerate_mismatch.scenario --> State change request NULL, quitting application
issue : FLUSH_START events that are part of the same pipeline 'operation' should have the same seqnum
Detected on <GESVideoTestSource:nlesource1:src>
Detected on <video_nlecomposition0:src>
Description : when events/messages are created from another event/message, they should have their seqnums set to the original event/message seqnum
warning : received an unexpected flush stop event
Detected on <GESVideoTestSource:nlesource1:src>
critical : The execution of an action did not properly happen
Detected on <check_edit_in_frames_with_framerate_mismatch.scenario>
Details : Last buffer frame number '0' is different than the expected one: '100'
dotfile : no dotfile produced as GST_DEBUG_DUMP_DOT_DIR is not set.
**Got criticals. Return value set to 18**:
* critical error Last buffer frame number '0' is different than the expected one: '100'
Issues found: 3