New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 694083 link

Starred by 1 user

Issue metadata

Status: Started
Owner:
Last visit > 30 days ago
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 3
Type: Bug



Sign in to add a comment

JIngleSession::OrderedMessageQueue::OnIncomingMessage crashes when handling invalid message

Project Member Reported by zijiehe@chromium.org, Feb 20 2017

Issue description

Call 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.
 
Description: Show this description
Description: Show this description
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?
Status: assigned (was: Untriaged)
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.

Comment 6 Deleted

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]
Owner: kelv...@chromium.org
I wrote the original implementation and I fixed a similar bug earlier.  I think I can take a look.
A fix to *avoid* crashes with DCHECK_IS_ON() is at https://codereview.chromium.org/2911663004/. Just in case it may be helpful.
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.
Status: Started (was: Assigned)
Project Member

Comment 12 by bugdroid1@chromium.org, 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