Additional requests send to server on start and/or stop of streaming

[JanHSchulz]

I use Transistor mainly to listen to streams provided by my own (local) server, running on a raspberry pi. When I was looking at the server's logs, I noticed a strange behavior. On start and/or stop of streaming, Transistor sends additional (unnecessary) requests to the server (and immediately closes the connections). Here are three examples from the server log:

1. Additional requests on stop:

<26.06.2022 12:37:25.547><INFO><pool-1-thread-1346> GET /stream/Musik/Pop HTTP/1.1 - 192.168.178.94

<26.06.2022 12:41:33.141><INFO><pool-1-thread-1347> GET /stream/Musik/Pop HTTP/1.1 - 192.168.178.94
<26.06.2022 12:41:33.143><INFO><pool-1-thread-1348> GET /stream/Musik/Pop HTTP/1.1 - 192.168.178.94
<26.06.2022 12:41:33.152><INFO><pool-1-thread-1349> GET /stream/Musik/Pop HTTP/1.1 - 192.168.178.94
<26.06.2022 12:41:33.172><INFO><pool-1-thread-1347> Stream stopped - (broken pipe) (Write failed)
<26.06.2022 12:41:33.180><INFO><pool-1-thread-1348> Stream stopped - (broken pipe) (Write failed)
<26.06.2022 12:41:33.182><INFO><pool-1-thread-1349> Stream stopped - (broken pipe) (Write failed)
<26.06.2022 12:41:34.778><INFO><pool-1-thread-1346> Stream stopped - Connection reset

You can see the initial request at 12:37:25.547 with thread number 1346, that is stopped in the last line (same thread). And three additional request just before the "real" stream is stopped.

2. Additional requests on start:

<27.06.2022 13:25:47.188><INFO><pool-1-thread-1366> GET /stream/Audiobooks/Latest HTTP/1.1 - 192.168.178.94
<27.06.2022 13:25:48.116><INFO><pool-1-thread-1368> GET /stream/Audiobooks/Latest HTTP/1.1 - 192.168.178.94
<27.06.2022 13:25:48.120><INFO><pool-1-thread-1367> GET /stream/Audiobooks/Latest HTTP/1.1 - 192.168.178.94
<27.06.2022 13:25:48.131><INFO><pool-1-thread-1369> GET /stream/Audiobooks/Latest HTTP/1.1 - 192.168.178.94
<27.06.2022 13:25:48.140><INFO><pool-1-thread-1370> GET /stream/Audiobooks/Latest HTTP/1.1 - 192.168.178.94
<27.06.2022 13:25:48.147><INFO><pool-1-thread-1371> GET /stream/Audiobooks/Latest HTTP/1.1 - 192.168.178.94
<27.06.2022 13:25:48.168><INFO><pool-1-thread-1373> GET /stream/Audiobooks/Latest HTTP/1.1 - 192.168.178.94
<27.06.2022 13:25:48.171><INFO><pool-1-thread-1372> GET /stream/Audiobooks/Latest HTTP/1.1 - 192.168.178.94
<27.06.2022 13:25:48.180><INFO><pool-1-thread-1374> GET /stream/Audiobooks/Latest HTTP/1.1 - 192.168.178.94
<27.06.2022 13:25:48.507><INFO><pool-1-thread-1368> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 13:25:48.509><INFO><pool-1-thread-1367> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 13:25:48.520><INFO><pool-1-thread-1371> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 13:25:48.522><INFO><pool-1-thread-1369> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 13:25:48.531><INFO><pool-1-thread-1373> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 13:25:48.532><INFO><pool-1-thread-1372> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 13:25:48.536><INFO><pool-1-thread-1374> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 13:25:48.538><INFO><pool-1-thread-1370> Stream stopped - (broken pipe) (Write failed)

<27.06.2022 13:32:00.618><INFO><pool-1-thread-1366> Stream stopped - Connection reset

About 1 second after the "real" stream has been started (thread 1366), the same request is send another 8 times to the server (within a few milliseconds) and all additional connects are immediately closed.

3. Additional requests on start and stop:

<27.06.2022 14:39:34.068><INFO><pool-1-thread-1375> GET /stream/Musik/Pop HTTP/1.1 - 192.168.178.94
<27.06.2022 14:39:34.998><INFO><pool-1-thread-1377> GET /stream/Musik/Pop HTTP/1.1 - 192.168.178.94
<27.06.2022 14:39:34.999><INFO><pool-1-thread-1376> GET /stream/Musik/Pop HTTP/1.1 - 192.168.178.94
<27.06.2022 14:39:35.001><INFO><pool-1-thread-1378> GET /stream/Musik/Pop HTTP/1.1 - 192.168.178.94
<27.06.2022 14:39:35.053><INFO><pool-1-thread-1376> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 14:39:35.055><INFO><pool-1-thread-1378> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 14:39:35.086><INFO><pool-1-thread-1377> Stream stopped - (broken pipe) (Write failed)

<27.06.2022 14:41:37.376><INFO><pool-1-thread-1379> GET /stream/Musik/Pop HTTP/1.1 - 192.168.178.94
<27.06.2022 14:41:37.379><INFO><pool-1-thread-1381> GET /stream/Musik/Pop HTTP/1.1 - 192.168.178.94
<27.06.2022 14:41:37.380><INFO><pool-1-thread-1380> GET /stream/Musik/Pop HTTP/1.1 - 192.168.178.94
<27.06.2022 14:41:37.471><INFO><pool-1-thread-1379> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 14:41:37.473><INFO><pool-1-thread-1381> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 14:41:37.476><INFO><pool-1-thread-1380> Stream stopped - (broken pipe) (Write failed)
<27.06.2022 14:41:39.096><INFO><pool-1-thread-1375> Stream stopped - Connection reset

[y20k]

Hi, good morning.

That is an interesting observation.

Transistor lets the (very popular) ExoPlayer library handle the streaming. All the app does is handing over a valid streaming url and listening for callbacks from the library (playback state, metadata).

If you have the impression that the behavior you observed is not just odd, but problematic, you could consider to file a bug report in the ExoPlayer GitHub issue tracker.

Or do you think I should become active on your behalf?

[JanHSchulz]

Hi,

usually playback is fine, so it might only be a "problem" for the server. But I think it should be fixed and sometimes playback stops after a few seconds and restarts - this might be related to this.

I could file a bug report for ExoPlayer, but I don't know how ExoPlayer is used in Transistor. It might be a bug in ExoPlayer, but maybe it is somehow related to the way ExoPlayer is used in Transistor (for example how callbacks are handled). Very likely the ExoPlayer developers will ask questions I can't answer. So, I think it will be better if you file the bug report.