Open Bug 1503329 Opened 6 years ago Updated 2 years ago

Check failed: payload_size_left >= fragment->length (1172 vs. 1635) in media/webrtc/trunk/webrtc/modules/rtp_rtcp/source/rtp_format_h264.cc

Categories

(Core :: WebRTC: Networking, defect, P5)

defect

Tracking

()

People

(Reporter: dvarga, Unassigned)

References

(Depends on 1 open bug)

Details

[task 2018-10-30T15:26:18.223Z] 15:26:18     INFO -  5 INFO SimpleTest FINISHED
[task 2018-10-30T15:26:18.223Z] 15:26:18     INFO - Buffered messages finished
[task 2018-10-30T15:26:18.223Z] 15:26:18     INFO - SUITE-END | took 388s
[task 2018-10-30T15:26:18.265Z] 15:26:18    ERROR - Return code: 1
[task 2018-10-30T15:26:18.272Z] 15:26:18     INFO - TinderboxPrint: mochitest-mochitest-media<br/>1231/0/26&nbsp;<em class="testfail">CRASH</em>
[task 2018-10-30T15:26:18.272Z] 15:26:18  WARNING - # TBPL WARNING #
[task 2018-10-30T15:26:18.272Z] 15:26:18  WARNING - setting return code to 1
[task 2018-10-30T15:26:18.272Z] 15:26:18  WARNING - The mochitest suite: mochitest-media ran with return status: WARNING
[task 2018-10-30T15:26:18.272Z] 15:26:18     INFO - Running post-action listener: _package_coverage_data
[task 2018-10-30T15:26:18.272Z] 15:26:18     INFO - Running post-action listener: _resource_record_post_action
[task 2018-10-30T15:26:18.272Z] 15:26:18     INFO - Running post-action listener: process_java_coverage_data
[task 2018-10-30T15:26:18.272Z] 15:26:18     INFO - [mozharness: 2018-10-30 15:26:18.269656Z] Finished run-tests step (success)
[task 2018-10-30T15:26:18.272Z] 15:26:18     INFO - Running post-run listener: _resource_record_post_run
[task 2018-10-30T15:26:18.358Z] 15:26:18     INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2018-10-30T15:26:18.364Z] 15:26:18     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 40.33157248157249}, {"name": "io_write_bytes", "value": 2424066048}, {"name": "io.read_bytes", "value": 12288000}, {"name": "io_write_time", "value": 141668}, {"name": "io_read_time", "value": 256}], "extraOptions": ["e10s", "taskcluster-m3.large"], "name": "mochitest.mochitest-media.3.overall"}, {"subtests": [{"name": "time", "value": 18.14686894416809}, {"name": "cpu_percent", "value": 50.394444444444446}], "name": "mochitest.mochitest-media.3.install"}, {"subtests": [{"name": "time", "value": 0.0009610652923583984}], "name": "mochitest.mochitest-media.3.stage-files"}, {"subtests": [{"name": "time", "value": 389.9215610027313}, {"name": "cpu_percent", "value": 39.82512886597939}], "name": "mochitest.mochitest-media.3.run-tests"}]}
[task 2018-10-30T15:26:18.365Z] 15:26:18     INFO - Total resource usage - Wall time: 408s; CPU: 40.0%; Read bytes: 12288000; Write bytes: 2424066048; Read time: 256; Write time: 141668
[task 2018-10-30T15:26:18.365Z] 15:26:18     INFO - TinderboxPrint: CPU usage<br/>39.8%
[task 2018-10-30T15:26:18.366Z] 15:26:18     INFO - TinderboxPrint: I/O read bytes / time<br/>12,288,000 / 256
[task 2018-10-30T15:26:18.366Z] 15:26:18     INFO - TinderboxPrint: I/O write bytes / time<br/>2,424,066,048 / 141,668
[task 2018-10-30T15:26:18.367Z] 15:26:18     INFO - TinderboxPrint: CPU idle<br/>448.9 (58.8%)
[task 2018-10-30T15:26:18.368Z] 15:26:18     INFO - TinderboxPrint: CPU system<br/>75.7 (9.9%)
[task 2018-10-30T15:26:18.368Z] 15:26:18     INFO - TinderboxPrint: CPU user<br/>229.2 (30.0%)
[task 2018-10-30T15:26:18.369Z] 15:26:18     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2018-10-30T15:26:18.370Z] 15:26:18     INFO - install - Wall time: 18s; CPU: 50.0%; Read bytes: 0; Write bytes: 27226112; Read time: 0; Write time: 7848
[task 2018-10-30T15:26:18.371Z] 15:26:18     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2018-10-30T15:26:18.375Z] 15:26:18     INFO - run-tests - Wall time: 390s; CPU: 40.0%; Read bytes: 12288000; Write bytes: 2396839936; Read time: 256; Write time: 133820
[task 2018-10-30T15:26:18.478Z] 15:26:18  WARNING - returning nonzero exit status 1
[task 2018-10-30T15:26:18.497Z] cleanup
[task 2018-10-30T15:26:18.498Z] + cleanup
[task 2018-10-30T15:26:18.499Z] + local rv=1
[task 2018-10-30T15:26:18.499Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2018-10-30T15:26:18.499Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2018-10-30T15:26:18.523Z] + true
[task 2018-10-30T15:26:18.524Z] + cleanup_xvfb
[task 2018-10-30T15:26:18.524Z] pidof Xvfb
[task 2018-10-30T15:26:18.524Z] ++ pidof Xvfb
[task 2018-10-30T15:26:18.544Z] + local xvfb_pid=25
[task 2018-10-30T15:26:18.544Z] + local vnc=false
[task 2018-10-30T15:26:18.544Z] + local interactive=false
[task 2018-10-30T15:26:18.544Z] + '[' -n 25 ']'
[task 2018-10-30T15:26:18.544Z] + [[ false == false ]]
[task 2018-10-30T15:26:18.545Z] + [[ false == false ]]
[task 2018-10-30T15:26:18.545Z] + kill 25
[task 2018-10-30T15:26:18.545Z] + screen -XS xvfb quit
[task 2018-10-30T15:26:18.558Z] XIO:  fatal IO error 11 (Resource temporarily unavailable) on X server ":0"
[task 2018-10-30T15:26:18.558Z]       after 3594 requests (3594 known processed) with 0 events remaining.
[task 2018-10-30T15:26:18.558Z] compizconfig - Info: Backend     : ini
[task 2018-10-30T15:26:18.558Z] compizconfig - Info: Integration : true
[task 2018-10-30T15:26:18.558Z] compizconfig - Info: Profile     : default
[task 2018-10-30T15:26:18.754Z] No screen session found.
[task 2018-10-30T15:26:18.755Z] + true
[task 2018-10-30T15:26:18.755Z] + exit 1
[taskcluster 2018-10-30 15:26:19.122Z] === Task Finished ===
[taskcluster 2018-10-30 15:26:19.240Z] Artifact "public/logs/" not found at "/builds/worker/workspace/build/logs/"
[taskcluster 2018-10-30 15:26:28.257Z] Unsuccessful task run with exit code: 1 completed in 645.752 seconds
Why this is a WebAudio error? Would you like to provide a short description?
Flags: needinfo?(dvarga)
I searched the component in the console and this component was returned.
Flags: needinfo?(dvarga)
Can you provide a link to the failed run, please?

I don't know what "search the component in the console" means.
Can you describe or point to instructions for this please?
Which console?
Did you explicitly search for "component"?
Flags: needinfo?(dvarga)
(In reply to Karl Tomlinson (:karlt) from comment #3)
> Did you explicitly search for "component"?

Sorry, I mean did you literally search for "component"?
Sorry for the missing link

Log link https://treeherder.mozilla.org/logviewer.html#?job_id=208652839&repo=autoland

Revision link: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=60129b9fe3f652601b1fdbe0d3bc2786f0ca4105&selectedJob=208652839

I used that component based on the first test-start which it was dom/media/webaudio/test/blink/test_biquadFilterNodeAutomation.html
Flags: needinfo?(dvarga)
The output in comment 0 seems to show "cleanup" killing the Xvfb process.
After that there is output from compizconfig as if it was still running while Xvfb was killed.  Such a client running while the X server terminates would be expected to report "fatal IO error".

I would normally expect the session manager to give the clients a chance to exit before the X server is killed.  That does require buy-in from the clients, but I suspect the session manager would kill the clients if they have not bought in.

I don't know what is telling the session manager to exit.  Perhaps that is what is missing here, but this is all happening after the tests have run to completion, and so clean shutdown of the X server is not really important.
GECKO(1062) | # Fatal error in /builds/worker/workspace/build/src/media/webrtc/trunk/webrtc/modules/rtp_rtcp/source/rtp_format_h264.cc, line 250
GECKO(1062) | # last system error: 0
GECKO(1062) | # Check failed: payload_size_left >= fragment->length (1172 vs. 1635)
GECKO(1062) | # Payload size left 1172, fragment length 1635, packetization mode SingleNalUnit

Crash reason:  SIGSEGV
Crash address: 0x0
Process uptime: not available

Thread 27 (crashed)
 0  firefox-bin!mozalloc_abort [mozalloc_abort.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 35 + 0x0]
    eip = 0x5658b861   esp = 0xe794dda0   ebp = 0xe794dda8   ebx = 0x565b7000
    esi = 0xf748ddf8   edi = 0xe794ddc8   eax = 0x565ad6c0   ecx = 0x565b74f4
    edx = 0x0000000a   efl = 0x00210286
    Found by: given as instruction pointer in context
 1  firefox-bin!abort [mozalloc_abort.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 82 + 0x1a]
    eip = 0x5658b88f   esp = 0xe794ddb0   ebp = 0xe794ddb8   ebx = 0x565b7000
    esi = 0xf748ddf8   edi = 0xe794ddc8
    Found by: call frame info
 2  libxul.so!rtc::FatalMessage::~FatalMessage() [checks.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 109 + 0x5]
    eip = 0xf2235b83   esp = 0xe794ddc0   ebp = 0xe794ddd8   ebx = 0xf53dc000
    esi = 0xf748ddf8   edi = 0xe794ddc8
    Found by: call frame info
 3  libxul.so!webrtc::RtpPacketizerH264::PacketizeSingleNalu(unsigned int) [rtp_format_h264.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 0 + 0x9]
    eip = 0xf22f365b   esp = 0xe794dde0   ebp = 0xe794dec8   ebx = 0xf53dc000
    esi = 0xe794ddf8   edi = 0xe488be10
    Found by: call frame info
 4  libxul.so!webrtc::RtpPacketizerH264::GeneratePackets() [rtp_format_h264.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 173 + 0xd]
    eip = 0xf22f3391   esp = 0xe794ded0   ebp = 0xe794def8   ebx = 0xf53dc000
    esi = 0x00000001   edi = 0xe2d92d60
    Found by: call frame info
 5  libxul.so!webrtc::RtpPacketizerH264::SetPayloadData(unsigned char const*, unsigned int, webrtc::RTPFragmentationHeader const*) [rtp_format_h264.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 166 + 0xb]
    eip = 0xf22f32fd   esp = 0xe794df00   ebp = 0xe794df78   ebx = 0xf53dc000
    esi = 0x00000002   edi = 0x00000663
    Found by: call frame info
 6  libxul.so!webrtc::RTPSenderVideo::SendVideo(webrtc::RtpVideoCodecTypes, webrtc::FrameType, signed char, unsigned int, long long, unsigned char const*, unsigned int, webrtc::RTPFragmentationHeader const*, webrtc::RTPVideoHeader const*, webrtc::StreamId const*, webrtc::StreamId const*) [rtp_sender_video.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 367 + 0x10]
    eip = 0xf2308c95   esp = 0xe794df80   ebp = 0xe794e0a8   ebx = 0xf53dc000
    esi = 0xe794df90   edi = 0xe2d92d60
    Found by: call frame info
 7  libxul.so!webrtc::RTPSender::SendOutgoingData(webrtc::FrameType, signed char, unsigned int, long long, unsigned char const*, unsigned int, webrtc::RTPFragmentationHeader const*, webrtc::RTPVideoHeader const*, unsigned int*) [rtp_sender.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 462 + 0x27]
    eip = 0xf2305791   esp = 0xe794e0b0   ebp = 0xe794e1e8   ebx = 0xf53dc000
    esi = 0xe794e2a8   edi = 0xe486c008
    Found by: call frame info
 8  libxul.so!webrtc::ModuleRtpRtcpImpl::SendOutgoingData(webrtc::FrameType, signed char, unsigned int, long long, unsigned char const*, unsigned int, webrtc::RTPFragmentationHeader const*, webrtc::RTPVideoHeader const*, unsigned int*) [rtp_rtcp_impl.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 419 + 0x29]
    eip = 0xf230548f   esp = 0xe794e1f0   ebp = 0xe794e268   ebx = 0xf53dc000
    esi = 0xe486c008   edi = 0xe486c300
    Found by: call frame info
 9  libxul.so!webrtc::PayloadRouter::OnEncodedImage(webrtc::EncodedImage const&, webrtc::CodecSpecificInfo const*, webrtc::RTPFragmentationHeader const*) [payload_router.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 137 + 0x2d]
    eip = 0xf234a1ad   esp = 0xe794e270   ebp = 0xe794e918   ebx = 0xf53dc000
    esi = 0xe794e2a8   edi = 0xe794ea60
    Found by: call frame info
10  libxul.so!webrtc::internal::VideoSendStreamImpl::OnEncodedImage(webrtc::EncodedImage const&, webrtc::CodecSpecificInfo const*, webrtc::RTPFragmentationHeader const*) [video_send_stream.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 1032 + 0x14]
    eip = 0xf2361f8c   esp = 0xe794e920   ebp = 0xe794e958   ebx = 0xf53dc000
    esi = 0xde4bc8e8   edi = 0xe794ea60
    Found by: call frame info
11  libxul.so!non-virtual thunk to webrtc::internal::VideoSendStreamImpl::OnEncodedImage(webrtc::EncodedImage const&, webrtc::CodecSpecificInfo const*, webrtc::RTPFragmentationHeader const*) [video_send_stream.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 0 + 0x5]
    eip = 0xf236201d   esp = 0xe794e960   ebp = 0xe794e988   ebx = 0xf53dc000
    esi = 0xe794ea50   edi = 0xe486b000
    Found by: call frame info
12  libxul.so!non-virtual thunk to webrtc::ViEEncoder::OnEncodedImage(webrtc::EncodedImage const&, webrtc::CodecSpecificInfo const*, webrtc::RTPFragmentationHeader const*) [vie_encoder.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 610 + 0x13]
    eip = 0xf2368692   esp = 0xe794e990   ebp = 0xe794e9d8   ebx = 0xf53dc000
    esi = 0xe794ea60   edi = 0xe486b000
    Found by: call frame info
13  libxul.so!webrtc::VCMEncodedFrameCallback::OnEncodedImage(webrtc::EncodedImage const&, webrtc::CodecSpecificInfo const*, webrtc::RTPFragmentationHeader const*) [generic_encoder.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 162 + 0x11]
    eip = 0xf23198a2   esp = 0xe794e9e0   ebp = 0xe794ea28   ebx = 0xf53dc000
    esi = 0xe794ea50   edi = 0xe486b3c8
    Found by: call frame info
14  libxul.so!mozilla::WebrtcGmpVideoEncoder::Encoded(GMPVideoEncodedFrame*, nsTArray<unsigned char> const&) [WebrtcGmpVideoCodec.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 663 + 0xe]
    eip = 0xefc63d21   esp = 0xe794ea30   ebp = 0xe794eaf8   ebx = 0xf53dc000
    esi = 0xde4bc8e8   edi = 0xe794eaa8
    Found by: call frame info
15  libxul.so!non-virtual thunk to mozilla::gmp::GMPVideoEncoderParent::RecvEncoded(mozilla::gmp::GMPVideoEncodedFrameData const&, nsTArray<unsigned char>&&) [GMPVideoEncoderParent.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 263 + 0xd]
    eip = 0xf0fe3246   esp = 0xe794eb00   ebp = 0xe794eb28   ebx = 0xf53dc000
    esi = 0xe6b1ea10   edi = 0xe2d96740
    Found by: call frame info
16  libxul.so!mozilla::gmp::PGMPVideoEncoderParent::OnMessageReceived(IPC::Message const&) [PGMPVideoEncoderParent.cpp: : 321 + 0x1d]
    eip = 0xef999c54   esp = 0xe794eb30   ebp = 0xe794ebb8   ebx = 0xf53dc000
    esi = 0xe47f7070   edi = 0xe6b1ea14
    Found by: call frame info
17  libxul.so!mozilla::gmp::PGMPContentParent::OnMessageReceived(IPC::Message const&) [PGMPContentParent.cpp: : 278 + 0xa]
    eip = 0xef98ca51   esp = 0xe794ebc0   ebp = 0xe794ebe8   ebx = 0xf53dc000
    esi = 0xe47f706c   edi = 0x00000001
    Found by: call frame info
18  libxul.so!mozilla::ipc::MessageChannel::DispatchAsyncMessage(IPC::Message const&) [MessageChannel.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 2255 + 0xa]
    eip = 0xef881e48   esp = 0xe794ebf0   ebp = 0xe794ec18   ebx = 0xf53dc000
    esi = 0xe72c8ce4   edi = 0x00000001
    Found by: call frame info
19  libxul.so!mozilla::ipc::MessageChannel::DispatchMessage(IPC::Message&&) [MessageChannel.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 2182 + 0xe]
    eip = 0xef880ea7   esp = 0xe794ec20   ebp = 0xe794ec88   ebx = 0xf53dc000
    esi = 0xe47f706c   edi = 0xe794ec30
    Found by: call frame info
20  libxul.so!mozilla::ipc::MessageChannel::RunMessage(mozilla::ipc::MessageChannel::MessageTask&) [MessageChannel.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 2019 + 0xa]
    eip = 0xef881459   esp = 0xe794ec90   ebp = 0xe794ecd8   ebx = 0xf53dc000
    esi = 0xe72c8ce4   edi = 0xe47f7040
    Found by: call frame info
21  libxul.so!mozilla::ipc::MessageChannel::MessageTask::Run() [MessageChannel.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 2052 + 0xc]
    eip = 0xef881864   esp = 0xe794ece0   ebp = 0xe794ecf8   ebx = 0xf53dc000
    esi = 0xe47f7040   edi = 0xe4921f60
    Found by: call frame info
22  libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 1245 + 0x8]
    eip = 0xef40a91b   esp = 0xe794ed00   ebp = 0xe794f208   ebx = 0xf53dc000
    esi = 0x00000001   edi = 0xe8e37a00
    Found by: call frame info
23  libxul.so!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 530 + 0x16]
    eip = 0xef40cda0   esp = 0xe794f210   ebp = 0xe794f228   ebx = 0xf53dc000
    esi = 0xe794f21f   edi = 0xe9ff0b50
    Found by: call frame info
24  libxul.so!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [MessagePump.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 364 + 0x13]
    eip = 0xef884833   esp = 0xe794f230   ebp = 0xe794f258   ebx = 0xf53dc000
    esi = 0xe9fe9250   edi = 0xe9ff0b50
    Found by: call frame info
25  libxul.so!MessageLoop::Run() [message_loop.cc:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 325 + 0x9]
    eip = 0xef8539dc   esp = 0xe794f260   ebp = 0xe794f288   ebx = 0xf53dc000
    esi = 0xe794f2a0   edi = 0xe8e37a00
    Found by: call frame info
26  libxul.so!nsThread::ThreadFunc(void*) [nsThread.cpp:60129b9fe3f652601b1fdbe0d3bc2786f0ca4105 : 505 + 0xb]
    eip = 0xef4087be   esp = 0xe794f290   ebp = 0xe794f338   ebx = 0xf53dc000
    esi = 0xe794f2a0   edi = 0xe8e37a00
    Found by: call frame info
Component: Web Audio → WebRTC: Networking
Summary: fatal IO error 11 (Resource temporarily unavailable) on X server ":0" → Check failed: payload_size_left >= fragment->length (1172 vs. 1635) in media/webrtc/trunk/webrtc/modules/rtp_rtcp/source/rtp_format_h264.cc
Depends on: 1504037
I'll prioritize this as if it were an intermittent failure for now.
Rank: 45
Priority: -- → P5
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.