search

kiall / android-tvheadend

Android + TV Headend + TV Input Framework
Apache License 2.0
193 stars 62 forks source link

Playback hanging after a while #146

Closed stevellion closed 7 years ago

stevellion commented 7 years ago

After watching a channel on Sony Bravia TV, playback stops and picture freezes. This seems to be anything from 20 minutes to 40 minutes or so. Changing channel or even re-selecting sometimes will refresh. logcat attached, with a playback between 22:22 > 22:57 https://drive.google.com/open?id=0B9TagJWY48fFbERNNWNkZE5aWnM

xi784 commented 7 years ago

Similar issuse on Nexus Player, stream starts ok or with stuttering, then htsp connection get lost and restart, then streaming gets ok for a while.

seapoint commented 7 years ago

Same here on Shiels - changing channels restarts playback

kiall commented 7 years ago

Yea, it seems to be affecting everyone :(

Working on it, for now - turning HTSP Video off in the settings will workaround it...

stevellion commented 7 years ago

Workaround may not hang.. but I get issue 104 again... (Screen shrunk to 3/4 size) https://github.com/kiall/android-tvheadend/issues/104 So I'm back to the htsp streaming again, at least I get a whole screen. :-)

kiall commented 7 years ago

Ugh, that sucks. I pushed a release an hour or so ago, 0.3.82 from memory, that might help, otherwise it'll be Tuesday before I can even look again! (Holidays always come at the worst time ;))

stevellion commented 7 years ago

Just trying .82 now.. just a couple of minutes in though. :-)

stevellion commented 7 years ago

Seems OK for now.. 40 minutes in and no hang.. Closing this issue.

stevellion commented 7 years ago

Spoke too soon.. just hung slightly over 40 mins.

kiall commented 7 years ago

Maybe I'll call this a feature, "Anti TV addiction technology" built in! Will dig in again Tuesday...

In the meantime, if anyone has time, could they install 0.2.73, test (aka watch TV), if it doesnt stall, try 0.2.74 and repeat until you hit the issue.. if it's something that changed recently, this will help track it down and give me a head start! APKs are on the the GitHub releases page..

xi784 commented 7 years ago

2017-03-07 10:56:02.434 tsfix: The timediff for TELETEXT is big (1243001580), using current dts 2017-03-07 10:56:02.434 tsfix: transport stream TELETEXT, DTS discontinuity. DTS = 0, last = 7346929412

kiall commented 7 years ago

@xi784, so your saying the issue happened right as you saw that message in TVheadend logs? Support for textsub was added recently to the HTSP builds.

xi784 commented 7 years ago

im not sure, i see this before it gets stuttering and crashed.

kiall commented 7 years ago

Okay, I've filtered out TELETEXT and TEXTSUB (which is derived from the TELETEXT stream) and have left the TV on the in background.. If there are no crashes / stalls, you might have found a lead :)

xi784 commented 7 years ago

Could be an approach..

xi784 commented 7 years ago

No success with it?

kiall commented 7 years ago

Nope, it's still locking up every so often...

xi784 commented 7 years ago

Ok, it was worth trying. :) Did you notice that we sometimes have two HTSP connections per client?

kiall commented 7 years ago

Yes, that's expected for the moment. One is used for EPG sync, and is always on.. The other is used for Video, and is connected as long as you are watching something.

This will likely drop back to 1 connection whenever we get all non-HTSP video code paths removed.

xi784 commented 7 years ago

I thought so.

xi784 commented 7 years ago

I think the problem depends on the EPGsyncservice and the multiple htsp connections. Can it be that TVheadend tries to push epg data over the wrong connection or something similar?

Currently I look over a client, but get only one HTSP connection, epgsync service seems crashed. Streaming works well for more than 2 hours, channel switch as well - only get 1-2 crashes with error: TELETEXT @ # 32 Continuity counter error (total 1) - this might be anaother problem. But now after 2 hours I get a second htsp connection (looks like epg sync process), stream starts immediately to stutter and remains hanging, again and again.

kiall commented 7 years ago

It's possible - there's a preference at the end of the setup process to disable EPG sync, it prevents that EPG connection from happening (and - also means no new/updated EPG data will be downloaded).

However, I don't think that's it! I often run with EPG sync disabled, to avoid too much noise in the logs while I debug something..

Also - Changing channels before the crash "resets" things, so the only length of time that matters is continous streaming of a single channel

xi784 commented 7 years ago

What should i say, that did the trick. No stuttering, hanging or crashing with disabled epg. Might be a performance problem with the nexus player, but i think a option to prevent EPG sync while streaming would be a nice option for limited hardware - i know we had this option even in Kodi...

It is not my day to write in english.. *arg :)

kiall commented 7 years ago

Adding a log message around an exception we previously caught and ignored seems to have revealed something, I think I have a workaround to push in a minute:

03-08 11:43:04.201 7770-7770/ie.macinnes.tvheadend D/ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onPlayerStateChanged: 2 (0)
03-08 11:43:04.201 7770-7770/ie.macinnes.tvheadend D/ie.macinnes.tvheadend.tvinput.BaseSession: Notifying video is unavailable, reason: 3
03-08 11:43:04.202 7770-7770/ie.macinnes.tvheadend D/ie.macinnes.tvheadend.player.EventLogger: state [2150.61, true, B]
03-08 11:43:04.202 7770-7770/ie.macinnes.tvheadend D/ie.macinnes.tvheadend.player.EventLogger: droppedFrames [2150.61, 11]
03-08 11:43:04.203 7770-7770/ie.macinnes.tvheadend D/ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onSetStreamVolume: 0.0 (0)
03-08 11:43:04.203 7770-7770/ie.macinnes.tvheadend D/ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onSetCaptionEnabled: false (0)
03-08 11:43:04.203 7770-7770/ie.macinnes.tvheadend D/ie.macinnes.tvheadend.tvinput.BaseSession: Session onSetCaptionEnabled: false (0)
03-08 11:43:28.691 7770-7778/ie.macinnes.tvheadend I/art: hprof: heap dump "[DDMS]" starting...
03-08 11:44:05.388 7770-7778/ie.macinnes.tvheadend I/art: hprof: heap dump completed (60MB) in 36.697s objects 437860 objects with stack traces 0
03-08 11:44:05.936 7770-8146/ie.macinnes.tvheadend W/ie.macinnes.tvheadend.player.HtspExtractor: IOException
                                                                                                 java.io.EOFException
                                                                                                     at java.io.ObjectInputStream$BlockDataInputStream.readFully(ObjectInputStream.java:2750)
                                                                                                     at java.io.ObjectInputStream.readArray(ObjectInputStream.java:1688)
                                                                                                     at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1345)
                                                                                                     at java.io.ObjectInputStream.readObject(ObjectInputStream.java:373)
                                                                                                     at java.util.HashMap.readObject(HashMap.java:1469)
                                                                                                     at java.lang.reflect.Method.invoke(Native Method)
                                                                                                     at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:1006)
                                                                                                     at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1894)
                                                                                                     at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1799)
                                                                                                     at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1351)
                                                                                                     at java.io.ObjectInputStream.readUnshared(ObjectInputStream.java:463)
                                                                                                     at ie.macinnes.tvheadend.player.HtspExtractor.read(HtspExtractor.java:115)
                                                                                                     at com.google.android.exoplayer2.source.ExtractorMediaPeriod$ExtractingLoadable.load(ExtractorMediaPeriod.java:630)
                                                                                                     at com.google.android.exoplayer2.upstream.Loader$LoadTask.run(Loader.java:295)
                                                                                                     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
                                                                                                     at java.util.concurrent.FutureTask.run(FutureTask.java:237)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
                                                                                                     at java.lang.Thread.run(Thread.java:761)
03-08 11:44:05.937 7770-8146/ie.macinnes.tvheadend W/ie.macinnes.tvheadend.player.HtspExtractor: IOException
                                                                                                 java.io.StreamCorruptedException: invalid stream header: 89279710
                                                                                                     at java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:805)
                                                                                                     at java.io.ObjectInputStream.<init>(ObjectInputStream.java:302)
                                                                                                     at ie.macinnes.tvheadend.player.HtspExtractor.read(HtspExtractor.java:114)
                                                                                                     at com.google.android.exoplayer2.source.ExtractorMediaPeriod$ExtractingLoadable.load(ExtractorMediaPeriod.java:630)
                                                                                                     at com.google.android.exoplayer2.upstream.Loader$LoadTask.run(Loader.java:295)
                                                                                                     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
                                                                                                     at java.util.concurrent.FutureTask.run(FutureTask.java:237)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
                                                                                                     at java.lang.Thread.run(Thread.java:761)
03-08 11:44:15.379 7770-7778/ie.macinnes.tvheadend I/art: hprof: heap dump "[DDMS]" starting...
03-08 11:44:56.024 7770-7778/ie.macinnes.tvheadend I/art: hprof: heap dump completed (70MB) in 40.644s objects 403756 objects with stack traces 0
03-08 11:44:56.184 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.270 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.305 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.326 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.353 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.370 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.394 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.409 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.431 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.448 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.462 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.477 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.497 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.512 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.528 7770-8126/ie.macinnes.tvheadend D/EpgSyncTask: Flushing 1 channel operations
03-08 11:44:56.787 7770-8146/ie.macinnes.tvheadend W/ie.macinnes.tvheadend.player.HtspExtractor: IOException
                                                                                                 java.io.EOFException
                                                                                                     at java.io.ObjectInputStream$BlockDataInputStream.readFully(ObjectInputStream.java:2750)
                                                                                                     at java.io.ObjectInputStream.readArray(ObjectInputStream.java:1688)
                                                                                                     at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1345)
                                                                                                     at java.io.ObjectInputStream.readObject(ObjectInputStream.java:373)
                                                                                                     at java.util.HashMap.readObject(HashMap.java:1469)
                                                                                                     at java.lang.reflect.Method.invoke(Native Method)
                                                                                                     at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:1006)
                                                                                                     at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1894)
                                                                                                     at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1799)
                                                                                                     at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1351)
                                                                                                     at java.io.ObjectInputStream.readUnshared(ObjectInputStream.java:463)
                                                                                                     at ie.macinnes.tvheadend.player.HtspExtractor.read(HtspExtractor.java:115)
                                                                                                     at com.google.android.exoplayer2.source.ExtractorMediaPeriod$ExtractingLoadable.load(ExtractorMediaPeriod.java:630)
                                                                                                     at com.google.android.exoplayer2.upstream.Loader$LoadTask.run(Loader.java:295)
                                                                                                     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
                                                                                                     at java.util.concurrent.FutureTask.run(FutureTask.java:237)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
                                                                                                     at java.lang.Thread.run(Thread.java:761)
03-08 11:44:56.789 7770-8146/ie.macinnes.tvheadend W/ie.macinnes.tvheadend.player.HtspExtractor: IOException
                                                                                                 java.io.StreamCorruptedException: invalid stream header: 79ABB91F
                                                                                                     at java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:805)
                                                                                                     at java.io.ObjectInputStream.<init>(ObjectInputStream.java:302)
                                                                                                     at ie.macinnes.tvheadend.player.HtspExtractor.read(HtspExtractor.java:114)
                                                                                                     at com.google.android.exoplayer2.source.ExtractorMediaPeriod$ExtractingLoadable.load(ExtractorMediaPeriod.java:630)
                                                                                                     at com.google.android.exoplayer2.upstream.Loader$LoadTask.run(Loader.java:295)
                                                                                                     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
                                                                                                     at java.util.concurrent.FutureTask.run(FutureTask.java:237)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
                                                                                                     at java.lang.Thread.run(Thread.java:761)
03-08 11:44:56.789 7770-8146/ie.macinnes.tvheadend W/ie.macinnes.tvheadend.player.HtspExtractor: IOException
                                                                                                 java.io.StreamCorruptedException: invalid stream header: 37851080
                                                                                                     at java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:805)
                                                                                                     at java.io.ObjectInputStream.<init>(ObjectInputStream.java:302)
                                                                                                     at ie.macinnes.tvheadend.player.HtspExtractor.read(HtspExtractor.java:114)
                                                                                                     at com.google.android.exoplayer2.source.ExtractorMediaPeriod$ExtractingLoadable.load(ExtractorMediaPeriod.java:630)
                                                                                                     at com.google.android.exoplayer2.upstream.Loader$LoadTask.run(Loader.java:295)
                                                                                                     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
                                                                                                     at java.util.concurrent.FutureTask.run(FutureTask.java:237)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
                                                                                                     at java.lang.Thread.run(Thread.java:761)
03-08 11:44:57.158 7770-8146/ie.macinnes.tvheadend W/ie.macinnes.tvheadend.player.HtspExtractor: IOException
                                                                                                 java.io.EOFException
                                                                                                     at java.io.ObjectInputStream$BlockDataInputStream.readFully(ObjectInputStream.java:2750)
                                                                                                     at java.io.ObjectInputStream.readArray(ObjectInputStream.java:1688)
                                                                                                     at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1345)
                                                                                                     at java.io.ObjectInputStream.readObject(ObjectInputStream.java:373)
                                                                                                     at java.util.HashMap.readObject(HashMap.java:1469)
                                                                                                     at java.lang.reflect.Method.invoke(Native Method)
                                                                                                     at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:1006)
                                                                                                     at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1894)
                                                                                                     at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1799)
                                                                                                     at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1351)
                                                                                                     at java.io.ObjectInputStream.readUnshared(ObjectInputStream.java:463)
                                                                                                     at ie.macinnes.tvheadend.player.HtspExtractor.read(HtspExtractor.java:115)
                                                                                                     at com.google.android.exoplayer2.source.ExtractorMediaPeriod$ExtractingLoadable.load(ExtractorMediaPeriod.java:630)
                                                                                                     at com.google.android.exoplayer2.upstream.Loader$LoadTask.run(Loader.java:295)
                                                                                                     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
                                                                                                     at java.util.concurrent.FutureTask.run(FutureTask.java:237)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
                                                                                                     at java.lang.Thread.run(Thread.java:761)
03-08 11:44:57.158 7770-8146/ie.macinnes.tvheadend W/ie.macinnes.tvheadend.player.HtspExtractor: IOException
                                                                                                 java.io.StreamCorruptedException: invalid stream header: E718CD6B
                                                                                                     at java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:805)
                                                                                                     at java.io.ObjectInputStream.<init>(ObjectInputStream.java:302)
                                                                                                     at ie.macinnes.tvheadend.player.HtspExtractor.read(HtspExtractor.java:114)
                                                                                                     at com.google.android.exoplayer2.source.ExtractorMediaPeriod$ExtractingLoadable.load(ExtractorMediaPeriod.java:630)
                                                                                                     at com.google.android.exoplayer2.upstream.Loader$LoadTask.run(Loader.java:295)
                                                                                                     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
                                                                                                     at java.util.concurrent.FutureTask.run(FutureTask.java:237)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
                                                                                                     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
                                                                                                     at java.lang.Thread.run(Thread.java:761)
kiall commented 7 years ago

Possible workaround https://github.com/kiall/android-tvheadend/commit/32235dee247b4383a9a4e6a295c29729033b723c

kiall commented 7 years ago

v0.2.84 has ^ workaround, can people give it a shot?

xi784 commented 7 years ago

Mmmh mmh .. exacatly ~40min

xi784 commented 7 years ago 
03-08 20:22:34.389  3335  3335 D ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onPlayerStateChanged: 2 (0)
03-08 20:22:34.389  3335  3335 D ie.macinnes.tvheadend.tvinput.BaseSession: Notifying video is unavailable, reason: 3
03-08 20:22:34.390  3335  3335 D ie.macinnes.tvheadend.player.EventLogger: state [2150.49, true, B]
03-08 20:22:34.392  3335  3335 D ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onSetStreamVolume: 0.0 (0)
03-08 20:22:34.394  3335  3335 D ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onSetCaptionEnabled: false (0)
03-08 20:22:34.394  3335  3335 D ie.macinnes.tvheadend.tvinput.BaseSession: Session onSetCaptionEnabled: false (0)
03-08 20:22:34.906   180  2360 I AudioFlinger: BUFFER TIMEOUT: remove(4098) from active list on thread 0xebf03dc0

After 4 hours of logging, thats all what happend when stream crashs. On serverside i did full trace subsystem, without any event at errortime.

xi784 commented 7 years ago

But there is one thing that happends on serverside before it crashs

2017-03-08 20:22:00.003 epg: expire event 1083887 (The Garfield Show) from Boomerang
2017-03-08 20:22:00.003 epg: now/next 1083889/1083891 set on Boomerang
2017-03-08 20:22:00.003 epg: inform HTSP of now event change on Boomerang
2017-03-08 20:22:00.003 epg: arm channel timer @ 2017-03-08;20:35:00(+0100) for Boomeran
kiall commented 7 years ago

Yea, whatever is happening to cause the freeze triggered those errors. the B in state [2150.49, true, B] means ExoPlayer thinks it needs to buffer, but we're still pumping in the video as fast as we get it... Eventually, it'll crash with an OutOfMemory exception, if left in that state for long enough.

I'm currently testing the lib itself, subscribing to a stream but just throwing away the data it gets... Assuming that doesn't crash (or its memory usage doesn't balloon over a few hours), I'll see about doing the same with some of the ExoPlayer integration code we've got..

If only I could find somewhere useful to drop a breakpoint :(

xi784 commented 7 years ago

This happend minutes later, dont know...

03-08 20:25:17.577  3335  3358 E ACRA    : ACRA caught a OutOfMemoryError for ie.macinnes.tvheadend
03-08 20:25:17.577  3335  3358 E ACRA    : java.lang.OutOfMemoryError: Failed to allocate a 11516 byte allocation with 4824 free bytes and 4KB until OOM
03-08 20:25:17.577  3335  3358 E ACRA    :  at java.util.Arrays.copyOf(Arrays.java:3256)
03-08 20:25:17.577  3335  3358 E ACRA    :  at java.io.ByteArrayOutputStream.grow(ByteArrayOutputStream.java:113)
03-08 20:25:17.577  3335  3358 E ACRA    :  at java.io.ByteArrayOutputStream.ensureCapacity(ByteArrayOutputStream.java:93)
03-08 20:25:17.577  3335  3358 E ACRA    :  at java.io.ByteArrayOutputStream.write(ByteArrayOutputStream.java:140)
03-08 20:25:17.577  3335  3358 E ACRA    :  at java.io.ObjectOutputStream$BlockDataOutputStream.drain(ObjectOutputStream.java:1946)
03-08 20:25:17.577  3335  3358 E ACRA    :  at java.io.ObjectOutputStream$BlockDataOutputStream.setBlockDataMode(ObjectOutputStream.java:1833)
03-08 20:25:17.577  3335  3358 E ACRA    :  at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1229)
03-08 20:25:17.577  3335  3358 E ACRA    :  at java.io.ObjectOutputStream.writeUnshared(ObjectOutputStream.java:429)
03-08 20:25:17.577  3335  3358 E ACRA    :  at ie.macinnes.tvheadend.player.HtspDataSource.serializeMessageToBuffer(HtspDataSource.java:207)
03-08 20:25:17.577  3335  3358 E ACRA    :  at ie.macinnes.tvheadend.player.HtspDataSource.onMuxpkt(HtspDataSource.java:196)
03-08 20:25:17.577  3335  3358 E ACRA    :  at ie.macinnes.htsp.tasks.Subscriber.onMessage(Subscriber.java:143)
03-08 20:25:17.577  3335  3358 E ACRA    :  at ie.macinnes.htsp.HtspMessageDispatcher.onMessage(HtspMessageDispatcher.java:180)
03-08 20:25:17.577  3335  3358 E ACRA    :  at ie.macinnes.htsp.HtspDataHandler.read(HtspDataHandler.java:115)
03-08 20:25:17.577  3335  3358 E ACRA    :  at ie.macinnes.htsp.HtspConnection.processReadableSelectionKey(HtspConnection.java:303)
03-08 20:25:17.577  3335  3358 E ACRA    :  at ie.macinnes.htsp.HtspConnection.run(HtspConnection.java:226)
03-08 20:25:17.577  3335  3358 E ACRA    :  at java.lang.Thread.run(Thread.java:761)
03-08 20:25:17.577  3335  3358 E ACRA    :  Suppressed: java.lang.OutOfMemoryError: Failed to allocate a 11516 byte allocation with 4872 free bytes and 4KB until OOM
03-08 20:25:17.577  3335  3358 E ACRA    :      at java.util.Arrays.copyOf(Arrays.java:3256)
03-08 20:25:17.577  3335  3358 E ACRA    :      at java.io.ByteArrayOutputStream.grow(ByteArrayOutputStream.java:113)
03-08 20:25:17.577  3335  3358 E ACRA    :      at java.io.ByteArrayOutputStream.ensureCapacity(ByteArrayOutputStream.java:93)
03-08 20:25:17.577  3335  3358 E ACRA    :      at java.io.ByteArrayOutputStream.write(ByteArrayOutputStream.java:140)
03-08 20:25:17.577  3335  3358 E ACRA    :      at java.io.ObjectOutputStream$BlockDataOutputStream.drain(ObjectOutputStream.java:1946)
03-08 20:25:17.577  3335  3358 E ACRA    :      at java.io.ObjectOutputStream$BlockDataOutputStream.flush(ObjectOutputStream.java:1888)
03-08 20:25:17.577  3335  3358 E ACRA    :      at java.io.ObjectOutputStream.flush(ObjectOutputStream.java:731)
03-08 20:25:17.577  3335  3358 E ACRA    :      at java.io.ObjectOutputStream.close(ObjectOutputStream.java:752)
03-08 20:25:17.577  3335  3358 E ACRA    :      at ie.macinnes.tvheadend.player.HtspDataSource.serializeMessageToBuffer(HtspDataSource.java:216)
03-08 20:25:17.577  3335  3358 E ACRA    :      ... 7 more
kiall commented 7 years ago

Re the EPG event, I was running with EPG turned off after your comment and still saw it :(

kiall commented 7 years ago

Re that OutOfMemory error, it's "expected" as we're pumping video into ExoPlayer, and it's still thinking it's not enough.. eventually we use all the RAM and we see that exception.

Part of the problem fixing this is, everything ive found so far is just a symptom rather than the root cause.. grr ;)

xi784 commented 7 years ago

The EPG event, i get this again, i see this on multiple times now, 30 seconds till 1 minute before it crashs.

03-08 21:01:09.826  3511  3511 D ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onPlayerStateChanged: 2 (0)
03-08 21:01:09.827  3511  3511 D ie.macinnes.tvheadend.tvinput.BaseSession: Notifying video is unavailable, reason: 3
03-08 21:01:09.827  3511  3511 D ie.macinnes.tvheadend.player.EventLogger: state [2150.73, true, B]
03-08 21:01:09.829  3511  3511 D ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onSetStreamVolume: 0.0 (0)
03-08 21:01:09.832  3511  3511 D ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onSetCaptionEnabled: false (0)
03-08 21:01:09.832  3511  3511 D ie.macinnes.tvheadend.tvinput.BaseSession: Session onSetCaptionEnabled: false (0)
03-08 21:01:10.341   180  2360 I AudioFlinger: BUFFER TIMEOUT: remove(4098) from active list on thread 0xebf03dc0
2017-03-08 21:00:00.003 epg: expire event 1074465 (Météo Monde) from France 24 (in English)
2017-03-08 21:00:00.003 epg: now/next 1074467/1074469 set on France 24 (in English)
2017-03-08 21:00:00.003 epg: inform HTSP of now event change on France 24 (in English)
2017-03-08 21:00:00.003 epg: arm channel timer @ 2017-03-08;21:15:00(+0100) for France 24 (in English)
2017-03-08 21:00:00.003 epg: expire event 1079517 (Meteo) from RAI News 24
2017-03-08 21:00:00.003 epg: now/next 1079519/1079521 set on RAI News 24
2017-03-08 21:00:00.003 epg: inform HTSP of now event change on RAI News 24
2017-03-08 21:00:00.003 epg: arm channel timer @ 2017-03-08;21:30:00(+0100) for RAI News 24
2017-03-08 21:00:00.003 epg: expire event 1108723 (Earrann Eachdraidh/History Shorts) from BBC ALBA
2017-03-08 21:00:00.003 epg: now/next 1108725/1108727 set on BBC ALBA
2017-03-08 21:00:00.003 epg: inform HTSP of now event change on BBC ALBA
2017-03-08 21:00:00.003 epg: arm channel timer @ 2017-03-08;21:30:00(+0100) for BBC ALBA
2017-03-08 21:00:00.003 epg: expire event 1127727 (Focus) from FRANCE24 UK
2017-03-08 21:00:00.003 epg: now/next 1127729/1127731 set on FRANCE24 UK
2017-03-08 21:00:00.003 epg: inform HTSP of now event change on FRANCE24 UK
...
xi784 commented 7 years ago

Also turned off the EPG.. Looks as if tvheadend try to push some epg data over the connection via Server to Client method, but streamextractor cant handle this?!

I have no idea what I'm talking about :D

xi784 commented 7 years ago

Hmpf ..and again...

03-08 21:40:33.438  3702  3702 D ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onPlayerStateChanged: 2 (0)
03-08 21:40:33.438  3702  3702 D ie.macinnes.tvheadend.tvinput.BaseSession: Notifying video is unavailable, reason: 3
03-08 21:40:33.440  3702  3702 D ie.macinnes.tvheadend.player.EventLogger: state [2150.76, true, B]
03-08 21:40:33.442  3702  3702 D ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onSetStreamVolume: 0.0 (0)
03-08 21:40:33.443  3702  3702 D ie.macinnes.tvheadend.tvinput.ExoPlayerSession: Session onSetCaptionEnabled: false (0)
03-08 21:40:33.443  3702  3702 D ie.macinnes.tvheadend.tvinput.BaseSession: Session onSetCaptionEnabled: false (0)
03-08 21:40:33.947   180  2360 I AudioFlinger: BUFFER TIMEOUT: remove(4098) from active list on thread 0xebf03dc0
2017-03-08 21:40:00.003 epg: expire event 850423 (heutejournal) from ZDF HD
2017-03-08 21:40:00.003 epg: now/next 850425/850441 set on ZDF HD
2017-03-08 21:40:00.003 epg: inform HTSP of now event change on ZDF HD
2017-03-08 21:40:00.003 epg: arm channel timer @ 2017-03-08;23:15:00(+0100) for ZDF HD
2017-03-08 21:40:00.003 epg: expire event 1065225 (Niedrig und Kuhnt - Kommissare ermitteln) from SAT.1 Gold HD
2017-03-08 21:40:00.003 epg: now/next 1065227/1065229 set on SAT.1 Gold HD
2017-03-08 21:40:00.003 epg: inform HTSP of now event change on SAT.1 Gold HD
2017-03-08 21:40:00.003 epg: arm channel timer @ 2017-03-08;22:10:00(+0100) for SAT.1 Gold HD
2017-03-08 21:40:00.003 epg: expire event 850405 (Malala - Ihr Recht auf Bildung) from 3sat HD
2017-03-08 21:40:00.003 epg: now/next 850407/1065653 set on 3sat HD
2017-03-08 21:40:00.003 epg: inform HTSP of now event change on 3sat HD
2017-03-08 21:40:00.003 epg: arm channel timer @ 2017-03-08;23:15:00(+0100) for 3sat HD
xi784 commented 7 years ago

Ok, forget this.. Did some tests today without any EPG data on server side, with the same result..

Interesting fact, without EPG data no channel synchronization..

kiall commented 7 years ago

I believe I found the issue, testing now...

kiall commented 7 years ago

Re without EPG, you get no channels, that's expected.. we insert all the channels as soon as we see the first EPG event. This lets us batch them up (and soon sort them, to fix a Sony TV specific issue)

kiall commented 7 years ago

Yep, 88% sure this is fixed in v0.2.85 - I've pushed this version to the Play Store.

kiall commented 7 years ago

@xi784 re the no channels without EPG - fixed by 0be5b850f9f8493006ee791492b2eceaa7318531

xi784 commented 7 years ago

looks quite good, constant stream since 4 hours.