Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Playback hanging after a while #146

Closed
stevellion opened this issue Mar 1, 2017 · 41 comments
Closed

Playback hanging after a while #146

stevellion opened this issue Mar 1, 2017 · 41 comments
Labels

Comments

@stevellion
Copy link

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
Copy link

xi784 commented Mar 1, 2017

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
Copy link

seapoint commented Mar 1, 2017

Same here on Shiels - changing channels restarts playback

@kiall
Copy link
Owner

kiall commented Mar 1, 2017

Yea, it seems to be affecting everyone :(

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

@stevellion
Copy link
Author

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

@kiall
Copy link
Owner

kiall commented Mar 1, 2017

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
Copy link
Author

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

@stevellion
Copy link
Author

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

@stevellion
Copy link
Author

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

@stevellion stevellion reopened this Mar 1, 2017
@kiall
Copy link
Owner

kiall commented Mar 1, 2017

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
Copy link

xi784 commented Mar 7, 2017

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
Copy link
Owner

kiall commented Mar 7, 2017

@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
Copy link

xi784 commented Mar 7, 2017

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

@kiall
Copy link
Owner

kiall commented Mar 7, 2017

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
Copy link

xi784 commented Mar 7, 2017

Could be an approach..

@xi784
Copy link

xi784 commented Mar 8, 2017

No success with it?

@kiall
Copy link
Owner

kiall commented Mar 8, 2017

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

@xi784
Copy link

xi784 commented Mar 8, 2017

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

@kiall kiall added the bug label Mar 8, 2017
@kiall
Copy link
Owner

kiall commented Mar 8, 2017

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
Copy link

xi784 commented Mar 8, 2017

I thought so.

@xi784
Copy link

xi784 commented Mar 8, 2017

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
Copy link
Owner

kiall commented Mar 8, 2017

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
Copy link

xi784 commented Mar 8, 2017

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
Copy link
Owner

kiall commented Mar 8, 2017

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
Copy link
Owner

kiall commented Mar 8, 2017

Possible workaround 32235de

@kiall
Copy link
Owner

kiall commented Mar 8, 2017

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

@xi784
Copy link

xi784 commented Mar 8, 2017

Mmmh mmh .. exacatly ~40min

@xi784
Copy link

xi784 commented Mar 8, 2017

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
Copy link

xi784 commented Mar 8, 2017

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
Copy link
Owner

kiall commented Mar 8, 2017

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
Copy link

xi784 commented Mar 8, 2017

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
Copy link
Owner

kiall commented Mar 8, 2017

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

@kiall
Copy link
Owner

kiall commented Mar 8, 2017

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
Copy link

xi784 commented Mar 8, 2017

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
Copy link

xi784 commented Mar 8, 2017

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
Copy link

xi784 commented Mar 8, 2017

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
Copy link

xi784 commented Mar 9, 2017

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 added a commit that referenced this issue Mar 10, 2017
@kiall
Copy link
Owner

kiall commented Mar 10, 2017

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

@kiall
Copy link
Owner

kiall commented Mar 10, 2017

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
Copy link
Owner

kiall commented Mar 10, 2017

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

@kiall kiall closed this as completed Mar 10, 2017
@kiall
Copy link
Owner

kiall commented Mar 11, 2017

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

@xi784
Copy link

xi784 commented Mar 11, 2017

looks quite good, constant stream since 4 hours.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

4 participants