1297321 - [Presentation WebAPI] Occasional launch failure with closed connection

Status: RESOLVED WONTFIX

(Core :: DOM: Core & HTML, defect, P3)

Description

[Teri Wen [:twen]]

Attachment: presentation.log

Sometimes presentation failed to launch with a closed connection. Unable to get a stable STR, often happens when the receiver has successfully opened the presentation page, and attempt to launch presentation again. 


STR:
1. Successfully launch a presentation and keep connection connected
2. Wait for 10 mins or so
3. Launch presentation again to the same receiver

Actual Behavior:
Connection shows connecting then session state change: closed
See attached file for detailed log

Expected Behavior:
Successfully Connection

Comment 1

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

@teri, can you help reproduce this issue with following configuration?

  1. create a pref named "logging.Presentation" and set string value to "debug"
  2. set pref "dom.presentation.tcp_server.debug" to true

It'll provide detailed log for further investigation.

Comment 2

[Teri Wen [:twen]]

Attachment: debug.log

Finally got a recreate! Both debug settings are on.
See attachment for detailed log.

Comment 3

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Need to figure out what causes the TCP establishment timeout.

>I/Gecko   (10889): [Main Thread]: D/Presentation controller virtual nsresult mozilla::dom::PresentationControllingInfo::OnStopListening(nsIServerSocket*, nsresult):status[804b0002]
>I/GeckoConsole(10889): call PresentationRequest.start
>I/Gecko   (10889): [Main Thread]: D/Presentation virtual nsresult mozilla::dom::PresentationService::StartSession(const nsAString_internal&, const nsAString_internal&, const nsAString_internal&, const nsAString_internal&, uint64_t, nsIPresentationServiceCallback*):url[http://www.cnn.com/], id[{ce35a89c-8d51-4b86-906b-e677533d8d54}]
>I/Gecko   (10889): -*- PresentationControlService.js: PresentationControlService - connect to Android-4.local
>I/Gecko   (10889): -*- PresentationControlService.js: create TCPControlChannel for : sender
>I/Gecko   (10889): -*- PresentationControlService.js: TCPControlChannel - set listener: [xpconnect wrapped nsIPresentationControlChannelListener]
>I/Gecko   (10889): [Main Thread]: D/Presentation virtual nsresult mozilla::dom::PresentationControllingInfo::Init(nsIPresentationControlChannel*):ServerSocket created.port[34415]
>I/Gecko   (10889): [Main Thread]: D/Presentation virtual nsresult mozilla::dom::PresentationService::RegisterSessionListener(const nsAString_internal&, uint8_t, nsIPresentationSessionListener*):id[{ce35a89c-8d51-4b86-906b-e677533d8d54}], role[1]
>I/Gecko   (10889): [Main Thread]: D/Presentation connection state change:id[{ce35a89c-8d51-4b86-906b-e677533d8d54}], state[0], reason[0], role[1]
>I/Gecko   (10889): -*- PresentationControlService.js: TCPControlChannel - onTransportStatus: 804b0003 with role: sender
>I/Gecko   (10889): -*- PresentationControlService.js: TCPControlChannel - onTransportStatus: 804b000b with role: sender
>I/Gecko   (10889): -*- PresentationControlService.js: TCPControlChannel - onTransportStatus: 804b0007 with role: sender
>I/Gecko   (10889): -*- PresentationControlService.js: TCPControlChannel - onInputStreamReady
>I/Gecko   (10889): -*- PresentationControlService.js: TCPControlChannel - onInputStreamReady error: NS_ERROR_NET_TIMEOUT
>I/Gecko   (10889): -*- PresentationControlService.js: TCPControlChannel - notify closed with role: sender
>I/Gecko   (10889): [Main Thread]: D/Presentation virtual nsresult mozilla::dom::PresentationControllingInfo::NotifyDisconnected(nsresult):id[{ce35a89c-8d51-4b86-906b-e677533d8d54}], reason[804b000e], role[1]
>I/Gecko   (10889): -*- PresentationControlService.js: TCPControlChannel - set listener: null
>I/Gecko   (10889): [Main Thread]: D/Presentation connection state change:id[{ce35a89c-8d51-4b86-906b-e677533d8d54}], state[2], reason[804b000e], role[1]
>I/Gecko   (10889): [Main Thread]: D/Presentation virtual void mozilla::dom::PresentationSessionInfo::Shutdown(nsresult):id[{ce35a89c-8d51-4b86-906b-e677533d8d54}], reason[80530020], role[1]
>I/Gecko   (10889): [Main Thread]: D/Presentation virtual nsresult mozilla::dom::PresentationService::UntrackSessionInfo(const nsAString_internal&, uint8_t):id[{ce35a89c-8d51-4b86-906b-e677533d8d54}], role[1]
>I/Gecko   (10889): [Main Thread]: D/Presentation controller virtual nsresult mozilla::dom::PresentationControllingInfo::OnStopList

Comment 4

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

From the tcpdump log on Nexus Player, SYN is received on TV side and SYN/ACK is transmitted. However, several retransmission of SYN and SYN/ACK is found but no ACK on TV side.

Need to figure out if this error belongs to RX or TX.

Comment 5

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

From the tcpdump log on Fennec, SYN is sent and retransmitted. Then, SYN/ACK is received later, which causes TCP out-of-order error and more retransmission.

Comment 6

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Comparing the tcpdump log on both endpoint, I observed there is a huge delay between sending and receiving SYN/ACK. My first guess is that SYN/ACK is queued in Nexus Player somehow which cause the TCP handshake fail. However we'll need to do more experiment to confirm my guess.

Comment 7

[Kagami Rosylight [:saschanaz] (they/them)]

Bug 1697680 removed Presentation API implementation.