JIngleSession::OrderedMessageQueue::OnIncomingMessage crashes when handling invalid message |
|||||
Issue descriptionCall stack is, remoting_core.dll!base::debug::BreakDebugger(void) C++ remoting_core.dll!logging::LogMessage::~LogMessage(void) C++ > remoting_core.dll!remoting::protocol::JingleSession::OrderedMessageQueue::OnIncomingMessage(class std::basic_string<char,struct std::char_traits<char>,class std::allocator<char> > const &,struct remoting::protocol::JingleSession::PendingMessage &&) C++ remoting_core.dll!remoting::protocol::JingleSession::OnIncomingMessage(class std::basic_string<char,struct std::char_traits<char>,class std::allocator<char> > const &,class std::unique_ptr<struct remoting::protocol::JingleMessage,struct std::default_delete<struct remoting::protocol::JingleMessage> >,class base::Callback<void ,1,1> const &) C++ remoting_core.dll!remoting::protocol::JingleSessionManager::OnSignalStrategyIncomingStanza(class buzz::XmlElement const *) C++ If an invalid message or unordered message has been sent to OrderedMessageQueue, it will trigger an assertion failure, which does not look like a correct behavior. I have reproduced the error on my virtual machine three times. It looks like this issue happens frequently on low-end machines.
,
Feb 20 2017
,
Feb 21 2017
Looks like one of the two DCHECKs fails. They probably should be replaced with warning logs. Do you see this in release builds? Can you please attach logs from the host or the client?
,
Feb 23 2017
,
Feb 24 2017
Sorry, I forgot to reply this bug. Yes, it happens in release builds. I will try to reproduce it tomorrow for client side log. The first DCHECK, i.e. DCHECK_GE(current, next_incoming_); failed. Though I am not quite familiar with jingle session generation logic. It looks like it's easy to reproduce it in a designed environment, say, the client intentionally sends unordered messages. It's easy to be reproduced on a lowend machine (virtual machine, especially immediately after startup), maybe because of https://cs.chromium.org/chromium/src/remoting/signaling/delegating_signal_strategy.cc?l=28. i.e. even the input messages are well ordered, we may still process them unorderly.
,
Jun 14 2017
INFORMATION 9792 7800 15:09:40-820 0 Received incoming stanza: <cli:iq type="set" to="6656ad2a1de9d442064c3385c3a6a39f@chromoting.gserviceaccount.com/chromoting????????" id="17137619193948826189_1" from="foo@bar.com/chromoting????????" xmlns:cli="jabber:client"><jingle sid="9827406821711993067" action="session-initiate" initiator="foo@bar.com/chromoting????????" xmlns="urn:xmpp:jingle:1"><content name="chromoting" creator="initiator"><description xmlns="google:remoting"><standard-ice/><control transport="mux-stream" version="3"/><event transport="mux-stream" version="2"/><video transport="stream" version="2" codec="vp9"/><video transport="stream" version="2" codec="vp8"/><audio transport="mux-stream" version="2" codec="opus"/><audio transport="none"/><authentication method="spake2_pair" supported-methods="third_party_spake2_curve25519,third_party,pair_spake2_curve25519,spake2_pair,spake2_curve25519,spake2_hmac,spake2_plain"><eke-message>tUFKvqxEPzWB1pjFyShmJRIEWWiiQVRCHo7O8TWqdpOELhqSEhi0YS4v0KeQqgdRt/3vD4v45aU=</eke-message><pairing-info client-id="e50fb6bd-d1f8-438e-8a39-9748d65ba347"/></authentication></description></content></jingle></cli:iq> ========================================================= INFORMATION 9792 7800 15:09:40-820 0 Sending outgoing stanza: <iq xmlns="jabber:client" id="17137619193948826189_1" type="result" to="foo@bar.com/chromoting????????"><jingle xmlns="urn:xmpp:jingle:1"/></iq> ========================================================= INFORMATION 9792 7800 15:09:40-820 0 Client connected: foo@bar.com/chromoting???????? INFORMATION 9792 7800 15:09:40-820 0 Sending outgoing stanza: <cli:iq type="get" id="3913792055363328585" xmlns:cli="jabber:client"><query xmlns="google:jingleinfo"/></cli:iq> ========================================================= INFORMATION 9792 7800 15:09:40-857 0 Sending outgoing stanza: <iq xmlns="jabber:client" type="set" to="foo@bar.com/chromoting????????" id="1041017953802921053_1"><jingle xmlns="urn:xmpp:jingle:1" sid="9827406821711993067" action="session-accept"><rem:attachments xmlns:rem="google:remoting"><rem:host-attributes>ChromeBrand,NonOfficialBuild,DirectX-Capturer,MinD3DGT10,MinD3DGT11</rem:host-attributes></rem:attachments><content name="chromoting" creator="initiator"><description xmlns="google:remoting"><standard-ice/><control transport="mux-stream" version="3"/><event transport="mux-stream" version="2"/><video transport="stream" version="2" codec="vp8"/><audio transport="mux-stream" version="2" codec="opus"/><authentication method="spake2_pair"><eke-message>NZKYaO/0mymo9sCA6Qm1xD7qbTYnXB9ys5FpNtM2weoqLdNNd969rH5XV1ACqAzgmCwAyCOoULI=</eke-message><eke-message>M9r0c/WV8mphajij33EVHOT1mmZyYJ1U+d8//H+PRBc=</eke-message><certificate>MIICpjCCAY6gAwIBAgIEGiwIDzANBgkqhkiG9w0BAQUFADAVMRMwEQYDVQQDDApjaHJvbW90aW5nMB4XDTE3MDYxMzIxNTk0NFoXDTE3MDYxNDIxNTk0NFowFTETMBEGA1UEAwwKY2hyb21vdGluZzCCASIwDQYJKoZIhvcNAQEBBQADggEPADCCAQoCggEBAL+I/cmyjrWMc9bm7RGqojWQIJc9N8+/0rPxufljqv+AyDr9+Xn1Vh+43bIwAVU7NDNrAGv/qqvTX5G4BkypkC4pdP/r8KS3WQFQwuSwKYNhACPThW8TGYuReOl0No1IivHfNW6+XAtxuHv2ZKPZXGa/HehOgBENd5Jn3bIC4KJMAAdRwiQeBvJZ4irTp3ljYI1/Wo7m0Jgldlumz4dYdkFLa5lel+katu+iMbwR7LndR7x4RMLYnvt8N0iJFLhFJDVhZPKHu/PJ5DW4+Uc52lO9Txg8xfUOrk8V6q472TxmC+XX5EO4af3cnfhyVBCxG1Br50gVqc3hgCc+KihaTEcCAwEAATANBgkqhkiG9w0BAQUFAAOCAQEAF2gcFVyaQwZ6mweJAdgc9Yog9/ljWM8ItW0PaNt/EmSpQmOFBzTNMGjgUDhGDI3HRgo2F0odak8XZ+MkKDVtWCXa/S3s6cpEmruMgoCbCWTmSyokThON+ZubWdjqneb8KXsKtx0pxCOzZjVfHHqOMwYfbwadJEYvwU0/kO+hOPj92/0JIf+9H7/UuViftfHQalNYvnh8lS37R7aphL0OnrG0wrn42rwLc9y6/0Y6xtLt9amyiY7CVG5bTHdduwYCYgJFZBkazWnKhvTbVojh8ZuA7uPUnxiX2ijwl60iPUOG+mXOoEgHcMHoc61Hp+U60xL+bSo69uKCPx21V686vA==</certificate></authentication></description></content></jingle></iq> ========================================================= INFORMATION 9792 7800 15:09:40-874 0 Received incoming stanza: <cli:iq to="6656ad2a1de9d442064c3385c3a6a39f@chromoting.gserviceaccount.com/chromoting????????" id="3913792055363328585" type="result" xmlns:cli="jabber:client"><query xmlns="google:jingleinfo"><stun><server host="stun.l.google.com" udp="19302"/><server host="alt1.stun.l.google.com" udp="19302"/><server host="alt2.stun.l.google.com" udp="19302"/><server host="alt4.stun.l.google.com" udp="19302"/><server host="alt3.stun.l.google.com" udp="19302"/></stun><relay><token>CAESSAo/NjY1NmFkMmExZGU5ZDQ0MjA2NGMzMzg1YzNhNmEzOWZAY2hyb21vdGluZy5nc2VydmljZWFjY291bnQuY29tEN6Oj6rKKxoQa1Pjo/S4AmQ8pUFHRn15/Q==</token><server host="relay.google.com" udp="19305" tcp="19305" tcpssl="443"/></relay></query></cli:iq> ========================================================= INFORMATION 9792 7800 15:09:40-904 0 Received incoming stanza: <cli:iq id="5u6r8xau1zb8_3" from="remoting@bot.talk.google.com" to="6656ad2a1de9d442064c3385c3a6a39f@chromoting.gserviceaccount.com/chromoting????????" type="set" xmlns:cli="jabber:client"><jingle sid="menpzufqgknc" action="session-terminate" from-endpoint-id="zijiehe@google.com/EhJ6aWppZWhlQGdvb2dsZS5jb20aDmNocm9tb3RpbmdfbGNzIh4KCmNocm9tb3RpbmcSEGZBQ2JfM3dpRXRtNkVieEE=" from-channel="lcs" xmlns="urn:xmpp:jingle:1"><reason><success/></reason></jingle></cli:iq> ========================================================= INFORMATION 9792 7800 15:09:40-904 0 Sending outgoing stanza: <iq xmlns="jabber:client" id="5u6r8xau1zb8_3" type="result" to="remoting@bot.talk.google.com"><jingle xmlns="urn:xmpp:jingle:1" to-endpoint-id="zijiehe@google.com/EhJ6aWppZWhlQGdvb2dsZS5jb20aDmNocm9tb3RpbmdfbGNzIh4KCmNocm9tb3RpbmcSEGZBQ2JfM3dpRXRtNkVieEE=" to-channel="lcs"/></iq> ========================================================= ERROR 9792 7800 15:09:40-904 0 SctpTransport->SendQueuedStreamResets(): Failed to send a stream reset for 1 streams: [0x00000009] Bad file descriptor INFORMATION 9792 7800 15:09:40-904 0 Client disconnected: zijiehe@google.com/EhJ6aWppZWhlQGdvb2dsZS5jb20aDmNocm9tb3RpbmdfbGNzIh4KCmNocm9tb3RpbmcSEGZBQ2JfM3dpRXRtNkVieEE=; error = 0 ERROR 9792 7800 15:09:40-905 0 SctpTransport->SendQueuedStreamResets(): Failed to send a stream reset for 2 streams: [0x00000009] Bad file descriptor INFORMATION 9792 7800 15:09:40-905 0 Sending outgoing stanza: <cli:iq type="set" to="remoting@bot.talk.google.com" id="12569363924674036536" xmlns:cli="jabber:client"><rem:log xmlns:rem="google:remoting"><rem:entry cpu="x86_64" event-name="session-state" host-version="61.0.3129.0" mode="me2me" os-name="Windows" os-version="10.0.14393" role="host" session-state="closed"/></rem:log></cli:iq> ========================================================= INFORMATION 9792 7800 15:09:41-003 0 Received incoming stanza: <cli:iq from="remoting@bot.talk.google.com" to="6656ad2a1de9d442064c3385c3a6a39f@chromoting.gserviceaccount.com/chromoting????????" id="12569363924674036536" type="result" xmlns:cli="jabber:client"><rem:log-result xmlns:rem="google:remoting"/></cli:iq> ========================================================= INFORMATION 9792 7800 15:09:43-396 0 Received incoming stanza: <cli:iq id="1041017953802921053_1" type="result" to="6656ad2a1de9d442064c3385c3a6a39f@chromoting.gserviceaccount.com/chromoting????????" from="foo@bar.com/chromoting????????" xmlns:cli="jabber:client"><jingle xmlns="urn:xmpp:jingle:1"/></cli:iq> ========================================================= INFORMATION 9792 7800 15:09:43-444 0 Received incoming stanza: <cli:iq type="set" to="6656ad2a1de9d442064c3385c3a6a39f@chromoting.gserviceaccount.com/chromoting????????" id="17137619193948826189_3" from="foo@bar.com/chromoting????????" xmlns:cli="jabber:client"><jingle sid="9827406821711993067" action="transport-info" xmlns="urn:xmpp:jingle:1"><content name="chromoting" creator="initiator"><transport xmlns="google:remoting:ice"><credentials channel="mux" ufrag="PnbkxDJ80RF2vhic" password="RxzVkUFS1SHBkz/gLqphzLxu"/><credentials channel="video" ufrag="JnKBrYHCMPxxGU9c" password="lFdov57RK50IOb0VldU87hGx"/></transport></content></jingle></cli:iq> ========================================================= INFORMATION 9792 7800 15:09:43-462 0 Received incoming stanza: <cli:iq type="set" to="6656ad2a1de9d442064c3385c3a6a39f@chromoting.gserviceaccount.com/chromoting????????" id="17137619193948826189_4" from="foo@bar.com/chromoting????????" xmlns:cli="jabber:client"><jingle sid="9827406821711993067" action="transport-info" xmlns="urn:xmpp:jingle:1"><content name="chromoting" creator="initiator"><transport xmlns="google:remoting:ice"><candidate name="mux" foundation="2136640592" address="2620:0:1008:1201:df7:a730:d1ac:f28f" port="45068" type="local" protocol="udp" priority="2122197248" generation="0"/><candidate name="mux" foundation="2136640592" address="2620:0:1008:1201:df7:a730:d1ac:f28f" port="49486" type="local" protocol="udp" priority="2122197248" generation="0"/><candidate name="mux" foundation="1934376684" address="2620:0:1008:1201:c4ef:e0aa:73d5:2181" port="38788" type="local" protocol="udp" priority="2122131712" generation="0"/><candidate name="mux" foundation="1934376684" address="2620:0:1008:1201:c4ef:e0aa:73d5:2181" port="51262" type="local" protocol="udp" priority="2122131712" generation="0"/><candidate name="mux" foundation="1801007035" address="2620:0:1008:1201:88e9:13f4:481a:acbd" port="51387" type="local" protocol="udp" priority="2122066176" generation="0"/><candidate name="mux" foundation="1801007035" address="2620:0:1008:1201:88e9:13f4:481a:acbd" port="42792" type="local" protocol="udp" priority="2122066176" generation="0"/><candidate name="mux" foundation="1914311919" address="2620:0:1008:1201:8189:d8e4:c2f:ea4e" port="59623" type="local" protocol="udp" priority="2122000640" generation="0"/><candidate name="mux" foundation="1914311919" address="2620:0:1008:1201:8189:d8e4:c2f:ea4e" port="57878" type="local" protocol="udp" priority="2122000640" generation="0"/><candidate name="mux" foundation="3659802439" address="172.23.164.252" port="55362" type="local" protocol="udp" priority="2121670400" generation="0"/><candidate name="mux" foundation="3659802439" address="172.23.164.252" port="34872" type="local" protocol="udp" priority="2121670400" generation="0"/><candidate name="video" foundation="2136640592" address="2620:0:1008:1201:df7:a730:d1ac:f28f" port="58621" type="local" protocol="udp" priority="2122197248" generation="0"/><candidate name="video" foundation="2136640592" address="2620:0:1008:1201:df7:a730:d1ac:f28f" port="58347" type="local" protocol="udp" priority="2122197248" generation="0"/><candidate name="video" foundation="1934376684" address="2620:0:1008:1201:c4ef:e0aa:73d5:2181" port="36035" type="local" protocol="udp" priority="2122131712" generation="0"/><candidate name="video" foundation="1934376684" address="2620:0:1008:1201:c4ef:e0aa:73d5:2181" port="42299" type="local" protocol="udp" priority="2122131712" generation="0"/><candidate name="video" foundation="1801007035" address="2620:0:1008:1201:88e9:13f4:481a:acbd" port="60631" type="local" protocol="udp" priority="2122066176" generation="0"/><candidate name="video" foundation="1801007035" address="2620:0:1008:1201:88e9:13f4:481a:acbd" port="45312" type="local" protocol="udp" priority="2122066176" generation="0"/><candidate name="video" foundation="1914311919" address="2620:0:1008:1201:8189:d8e4:c2f:ea4e" port="42153" type="local" protocol="udp" priority="2122000640" generation="0"/><candidate name="video" foundation="1914311919" address="2620:0:1008:1201:8189:d8e4:c2f:ea4e" port="51572" type="local" protocol="udp" priority="2122000640" generation="0"/><candidate name="video" foundation="3659802439" address="172.23.164.252" port="37661" type="local" protocol="udp" priority="2121670400" generation="0"/><candidate name="video" foundation="3659802439" address="172.23.164.252" port="33944" type="local" protocol="udp" priority="2121670400" generation="0"/></transport></content></jingle></cli:iq> ========================================================= INFORMATION 9792 7800 15:09:43-520 0 Received incoming stanza: <cli:iq type="set" to="6656ad2a1de9d442064c3385c3a6a39f@chromoting.gserviceaccount.com/chromoting????????" id="17137619193948826189_5" from="foo@bar.com/chromoting????????" xmlns:cli="jabber:client"><jingle sid="9827406821711993067" action="transport-info" xmlns="urn:xmpp:jingle:1"><content name="chromoting" creator="initiator"><transport xmlns="google:remoting:ice"><candidate name="mux" foundation="380180692" address="104.132.51.92" port="61279" type="stun" protocol="udp" priority="1685462784" generation="0"/><candidate name="video" foundation="380180692" address="104.132.51.92" port="44277" type="stun" protocol="udp" priority="1685462784" generation="0"/></transport></content></jingle></cli:iq> ========================================================= INFORMATION 9792 7800 15:09:43-524 0 Received incoming stanza: <cli:iq type="set" to="6656ad2a1de9d442064c3385c3a6a39f@chromoting.gserviceaccount.com/chromoting????????" id="17137619193948826189_2" from="foo@bar.com/chromoting????????" xmlns:cli="jabber:client"><jingle sid="9827406821711993067" action="session-info" xmlns="urn:xmpp:jingle:1"><rem:authentication method="spake2_pair" xmlns:rem="google:remoting"><rem:eke-message>GuF2+DM9s79UsCRhVVa4Iuz4ov7XCsccOEm0nKkFyRY=</rem:eke-message></rem:authentication></jingle></cli:iq> ========================================================= FATAL 9792 7800 15:09:43-530 0 Check failed: current >= next_incoming_ (2 vs. 6) Backtrace: GetHandleVerifier [0x602637B7+150407] GetHandleVerifier [0x6026368A+150106] GetHandleVerifier [0x6049D072+2483266] GetHandleVerifier [0x6049CF82+2483026] GetHandleVerifier [0x60490552+2431266] GetHandleVerifier [0x60769913+5418211] GetHandleVerifier [0x604A1BBC+2502540] GetHandleVerifier [0x604A08E4+2497716] GetHandleVerifier [0x6076D978+5434696] GetHandleVerifier [0x6076E6F5+5438149] GetHandleVerifier [0x6076E641+5437969] GetHandleVerifier [0x60C0EDAA+10289530] GetHandleVerifier [0x60C0E3FD+10287053] GetHandleVerifier [0x60C0D808+10283992] GetHandleVerifier [0x60C0D75E+10283822] GetHandleVerifier [0x6076E8E1+5438641] GetHandleVerifier [0x6076D71E+5434094] GetHandleVerifier [0x607691D5+5416357] GetHandleVerifier [0x60769668+5417528] GetHandleVerifier [0x60360CAD+1187965] remoting::StartHostMain [0x6014D32F+85703] GetHandleVerifier [0x60305952+814370] GetHandleVerifier [0x60307CAA+823418] GetHandleVerifier [0x6035C64D+1169949] GetHandleVerifier [0x6036734C+1214236] GetHandleVerifier [0x6037C5D6+1300902] GetHandleVerifier [0x603090FD+828621] GetHandleVerifier [0x6040AFBD+1885069] remoting::StartHostMain [0x6014D32F+85703] GetHandleVerifier [0x60360C8B+1187931] GetHandleVerifier [0x60360CAD+1187965] remoting::StartHostMain [0x6014D32F+85703] GetHandleVerifier [0x6035FC90+1183840] GetHandleVerifier [0x60360573+1186115] GetHandleVerifier [0x602448FB+23755] GetHandleVerifier [0x602448CD+23709] GetHandleVerifier [0x60267419+165865] DllUnregisterServer [0x60231111+41442] DllUnregisterServer [0x6023058D+38494] GetHandleVerifier [0x602685AC+170364] GetHandleVerifier [0x60268E9A+172650] DllUnregisterServer [0x60230C0B+40156] DllUnregisterServer [0x6022E983+31316] remoting::StartHostMain [0x6014CA70+83464] DllUnregisterServer [0x60239F32+77827] BaseThreadInitThunk [0x77BE62C4+36] RtlSubscribeWnfStateChangeNotification [0x77D10FD9+1081] RtlSubscribeWnfStateChangeNotification [0x77D10FA4+1028]
,
Jun 14 2017
I wrote the original implementation and I fixed a similar bug earlier. I think I can take a look.
,
Jun 14 2017
A fix to *avoid* crashes with DCHECK_IS_ON() is at https://codereview.chromium.org/2911663004/. Just in case it may be helpful.
,
Jun 14 2017
Looking at the log I think the problem is that JingleSession doesn't account for sequence ID in the very first session-initiate message. OrderedMessageQueue never sees that message, so it doesn't know that sequence_id starts at 1. This should be easy to fix in JingleSession::InitializeIncomingConnection(): it should initialize OrderedMessageQueue with the id from that message.
,
Jun 30 2017
,
Jul 6 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/18a8dd58a06879fec5b97e682e3bc6e90899bbab commit 18a8dd58a06879fec5b97e682e3bc6e90899bbab Author: kelvinp <kelvinp@chromium.org> Date: Thu Jul 06 00:13:07 2017 Fix ASSERT in JingleMessage::OrderedMessageQueue. Session-initate messages doesn't go through JingleSession::OnIncomingMessage() We need to initialize the OrderedMessageQueue with the id of the session-initiate message. BUG=694083 Review-Url: https://codereview.chromium.org/2967213002 Cr-Commit-Position: refs/heads/master@{#484385} [modify] https://crrev.com/18a8dd58a06879fec5b97e682e3bc6e90899bbab/remoting/protocol/jingle_session.cc [modify] https://crrev.com/18a8dd58a06879fec5b97e682e3bc6e90899bbab/remoting/protocol/jingle_session.h [modify] https://crrev.com/18a8dd58a06879fec5b97e682e3bc6e90899bbab/remoting/protocol/jingle_session_manager.cc |
|||||
►
Sign in to add a comment |
|||||
Comment 1 by zijiehe@chromium.org
, Feb 20 2017