Android sender: user initiated disconnect sometimes shows reason: unknown

[GoogleCodeExporter]

What steps will reproduce the problem?
1. Implement a project with latest CCL Android library and custom receiver
2. Select cast device and connect to app
3. Disconnect the device
4. In about half the time I see this in the receiver logs:
Sender disconnected: 
{"type":"senderdisconnected","H":false,"defaultPrevented":false,"lb":true,"data"
:"430:com.mynamespace-26","senderId":"430:com.mynamespace-26","userAgent":"Andro
id CastSDK,6183000,GT-I9500,ja3gxx,4.4.2","reason":"unknown"} 

In the sender logs I see the following:
[DEBUG] :  ccl_CastMediaRouterCal: [v1.10] onRouteUnselected: 
route=MediaRouter.RouteInfo{ 
uniqueId=com.google.android.gms/.cast.media.CastMediaRouteProviderService:d4d528
eae47fd37aaa63dad999ec8298, name=CastM, description=Casting Jukodev, 
enabled=true, connecting=false, playbackType=1, playbackStream=-1, 
volumeHandling=1, volume=20, volumeMax=20, presentationDisplayId=-1, 
extras=Bundle[mParcelledData.dataSize=580], 
providerPackageName=com.google.android.gms }
[DEBUG] :  ccl_BaseCastManager: [v1.10] disconnectDevice(true,false)
[DEBUG] :  ccl_BaseCastManager: [v1.10] mConnectionSuspended: false
[DEBUG] :  ccl_BaseCastManager: [v1.10] clearPersistedConnectionInfo(): 
Clearing persisted data for 0
[DEBUG] :  ccl_BaseCastManager: [v1.10] stopReconnectionService()
[DEBUG] :  ccl_BaseCastManager: [v1.10] onDisconnected() reached

What is the expected output? What do you see instead?
I expect to see reason: requested_by_sender in the receiver disconnect event. 
This is important since in this case I want to exit the receiver app. In the 
error case the receiver app is kept on screen, not what the user wants. 
Additionally, the cast icon is of course off.

What version of the product are you using? On what operating system?
Android 4.4.2, you can see the Google Play Services version in the logs, CCL 
1.10

Please provide any additional information below.

Original issue reported on code.google.com by m...@juko.fm on 27 Oct 2014 at 1:38

[GoogleCodeExporter]

Could you provide full timestamped logs of both the sender and the receiver so 
we can see what is happening on both sides? Also, how consistently can you 
reproduce this?

Original comment by and...@google.com on 20 Nov 2014 at 4:22

• Changed state: NeedInfo

[GoogleCodeExporter]

This is very easily reproducible, happens about 1/3-1/2 of the time.
Attached are both receiver and Android sender logs.
On the receiver, note the disconnect message at 11.004s, and on the sender at 
23:43:53.071 onRouteUnselected - the user chooses to disconnect the app.

Original comment by mokesmo...@gmail.com on 20 Nov 2014 at 10:06

Attachments:

• receiverLog.txt
• AndroidLog.txt

[GoogleCodeExporter]

Bottom line, as you can see: frequently when an Android user initiates a 
disconnection, the receiver gets a message with 
{"data":"{\"reason\":\"transport_closed\",\"senderId\":\"62:com.zz.myapp-12\",\"
type\":\"senderdisconnected\"} , which is then dispatched as an "unknown" 
disconnection event. The disconnect event reason should of course be 
"requested_by_sender"

Original comment by m...@juko.fm on 21 Nov 2014 at 11:35

[GoogleCodeExporter]

Verified that this occurs also with Google Play Services 6.5.87. In fact, on my 
S4 running 4.4.2 this bug happens on almost every disconnect.

Original comment by m...@juko.fm on 25 Nov 2014 at 6:20

[GoogleCodeExporter]

Confirmed that it occurs both on Nexus S 4.1.2 and Samsung S4 4.4.2. The Nexus 
S was using GPS 6.1 up until a few minutes ago when it received the 6.5 update. 
On occasion when the user disconnects we get a "closed_by_peer" message which 
leads to a "requested_by_user" disconnect event. More often we see a 
"transport_closed" message which leads to disconnect reason: unknown

Original comment by m...@juko.fm on 25 Nov 2014 at 7:12

[GoogleCodeExporter]

I am also seeing this issue (Galaxy S4 4.4.2). Not sure when it started as 
development has been focused in other areas. All I can say is at some point in 
the last few months, the behavior has changed. My receiver app almost always 
get a reason 'unknown' instead of the proper requested_by_sender.

Original comment by sakamoto...@myqubix.com on 30 Nov 2014 at 5:12

[GoogleCodeExporter]

@Google team, can you please prioritize this? Currently it's hard to know when 
to shut down the receiver app due to this bug.

Original comment by m...@juko.fm on 30 Nov 2014 at 6:20

[GoogleCodeExporter]

sakamoto: could you please capture both sender and receiver log at the same 
time so we can see what your sender is sending and what your receiver is doing; 
you would need to turn on debugging in console and capture the log.

Original comment by anad...@google.com on 30 Nov 2014 at 6:21

[GoogleCodeExporter]

[deleted comment]

[GoogleCodeExporter]

@Google, have you seen the logs 7 comments above this one? I can confirm the 
logs are the same for GPS 6.1 and 6.5

Original comment by m...@juko.fm on 30 Nov 2014 at 6:29

[GoogleCodeExporter]

I have seen that and I asked for more logs to investigate. A new user reported 
that and a new set of logs from the new user is valuable.

Original comment by anad...@google.com on 30 Nov 2014 at 6:45

[GoogleCodeExporter]

It is also very useful if anyone who can reproduce this could provide a better 
log on Chromecast by using the Chromecast app on Android and sending a feedback 
from there (making sure the box that the checkbox "Send Chromecast usage and 
crash reports to Google" is checked and then send a feedback; that has more low 
level information that can tell us with a lot more detail why receiver is 
interpreting the disconnect reason as "unknown". To help us find that feedback 
easily, please have the user enter "issue-416" string in the description of 
feedback. When that is done, please let us know so we can look for the log so 
we can investigate, thanks.

Original comment by anad...@google.com on 1 Dec 2014 at 7:12

[GoogleCodeExporter]

@Google, you can easily reproduce this with the CastHelloText-android app.
In MainActivity.java, inside onRouteUnselected change the teardown() call to 
mApiClient.disconnect(); You will then easily see the unknown disconnect reason 
bug.

Original comment by mokesmo...@gmail.com on 4 Dec 2014 at 1:37

[GoogleCodeExporter]

I can reproduce this easily, so I did that now and sent feedback using the 
Chromecast app, as requested. I started my feedback description with 
"issue-416", so it should be easy to find!

Original comment by erik.mid...@gmail.com on 4 Dec 2014 at 2:03

[GoogleCodeExporter]

we are investigating the issue.

Original comment by anad...@google.com on 4 Dec 2014 at 5:41

• Changed state: Accepted

[GoogleCodeExporter]

It's happening in our app too, almost every time when sender disconnects.
tested on Samsung Note4- 4.4.4, Nexus5 Android 4.4.4.
i've attached sender and receiver logs as well. Expecting a fix for this soon 
as this has a huge impact on receiver app behaviour.

Thanks,
Sri

Original comment by s...@spuul.com on 8 Dec 2014 at 5:30

Attachments:

• Receiver_disconnect_logs.txt
• sender_disconnect_logs.txt

[GoogleCodeExporter]

[deleted comment]

[GoogleCodeExporter]

[deleted comment]

[GoogleCodeExporter]

This will be fixed in an upcoming update.

Original comment by and...@google.com on 6 Feb 2015 at 4:14

• Changed state: Accepted

[GoogleCodeExporter]

Any timeframe for the fix? Thanks.

Original comment by m...@juko.fm on 11 Feb 2015 at 5:07

[GoogleCodeExporter]

I will add that this issue now occurs EVERY time and not some of the time, as 
before.

Original comment by m...@juko.fm on 11 Feb 2015 at 8:01

[GoogleCodeExporter]

Do you have the latest version of Google Play Services? If you still experience 
the issue, could you send us a feedback report (please prefix the feedback 
report with "Issue 416" so we can identify it quickly) and include in it what 
type of receiver you are using (for custom receivers please include what you 
are doing in the "onSenderDisconnected" callback for the receiver). Also, 
please include the Android sender logs for the same session as the one in the 
feedback report, so we can see what happens on both ends. 

Original comment by and...@google.com on 6 Mar 2015 at 5:13

[GoogleCodeExporter]

Hmmm, now with GPS 6.7.76 it works fine.... there was a period where it behaved 
well, then it again broke, now fixed again. All this without my relevant app 
code changing. So looks good now, hope it stays this way this time :)

Original comment by m...@juko.fm on 9 Mar 2015 at 10:39

[GoogleCodeExporter]

I can confirm that with 6.5.99 the error occurs frequently. I have yet to see 
it happen with 6.7.76

Original comment by m...@juko.fm on 9 Mar 2015 at 12:50

[GoogleCodeExporter]

Original comment by and...@google.com on 9 Mar 2015 at 4:22

• Changed state: Fixed