News:

Latest versions:
Server plugin: 0.5.1
MVP dongle: 0.5.2
Raspberry Pi client: 0.5.2
Windows client: 0.5.2-1

Main Menu
Menu

Show posts

This section allows you to view all posts made by this member. Note that you can only see posts made in areas you currently have access to.

Show posts Menu

Messages - davep

#1
The update to libc6 on the Raspbian distribution which has recently been released can cause the vompclient (and any other program linked to the videocore libraries) to fail with 'library not found' errors. This forum post gives the workaround:

http://www.raspberrypi.org/phpBB3/viewtopic.php?f=66&t=34661

otherwise don't update your system until the problem is fixed.
#2
VOMP for Raspberry Pi / Re: Shutdown / Reboot fix
November 20, 2012, 20:05:04
Unfortunately that does not work, as the vomp_options parameter is only being applied to the link step. This works:

diff --git a/GNUmakefile b/GNUmakefile
index e52ff4d..34f4df0 100644
--- a/GNUmakefile
+++ b/GNUmakefile
@@ -26,8 +26,8 @@ endif



-CXXFLAGS_DEV = -g -O0 -Wall -Wshadow -DDEV -D_GNU_SOURCE $(INCLUDES)
-CXXFLAGS_REL = -O3 -Wall -Wshadow  -D_GNU_SOURCE $(INCLUDES)
+CXXFLAGS_DEV = -g -O0 -Wall -Wshadow -DDEV -D_GNU_SOURCE $(INCLUDES) $(vomp_options)
+CXXFLAGS_REL = -O3 -Wall -Wshadow  -D_GNU_SOURCE $(INCLUDES) $(vomp_options)


LIBPATHS =
@@ -75,7 +75,7 @@ default: dev
fresh:   clean default

vompclient: $(OBJECTS) $(TIOBJECT) $(CROSSLIBS)
-       $(LD) $(LDFLAGS) $(LIBPATHS) $(RELEASE) $(vomp_options) -o vompclient $(TIOBJECT) $(OBJECTS) $(CROSSLIBS) $(LIBS)
+       $(LD) $(LDFLAGS) $(LIBPATHS) $(RELEASE) -o vompclient $(TIOBJECT) $(OBJECTS) $(CROSSLIBS) $(LIBS)

# A slight hash up
ticonfig.o:

#3
VOMP for Raspberry Pi / Shutdown / Reboot fix
November 18, 2012, 09:52:17
The option in GNUMakefile which gives the choice of shutting down or rebooting the Pi from the remote doesn't work. The #define VOMP_HAS_EXIT is never passed to the compiler. I don't really understand Makefiles so this is a quick fix:

diff --git a/GNUmakefile b/GNUmakefile
index f759c16..a7684b1 100644
--- a/GNUmakefile
+++ b/GNUmakefile
@@ -68,6 +68,7 @@ CXXFLAGS_DEV += -D__STDC_CONSTANT_MACROS
CXXFLAGS_REL += -D__STDC_CONSTANT_MACROS

endif
+INCLUDES += $(vomp_options)

.PHONY: clean fresh all install strip


#4
VOMP for Raspberry Pi / Re: Font Size
November 08, 2012, 09:35:24
Apologies I missed out the most important step, actually changing the font size  :'(  Also I didn't spot the incompatible license.
#5
VOMP for Raspberry Pi / Re: Font Size
November 07, 2012, 19:49:47
I had the same problem a while ago, the existing font is too small to read on a TV 3m away.

I'm away from my Pi at the moment, but I recall replacing the font sourcesans.ttf with a larger version. I also found the font difficult to read at a distance so I used the GNU Free Sans Bold font instead. I had some difficulty as the most recent version of the font on the GNU website didn't display correctly, so I've attached the one which worked.

I didn't change the Makefile, just overwrote the sourcesans.ttf file with the new one.

Having changed the font size, I found the line spacing on the OSD needed to be changed. In file osdopenvg.cc line 498 I changed the number 64 to (I think) 84.
#6
The processing of the pause command is in omxplayer.cpp around line 659

      case 'p':
        m_Pause = !m_Pause;
        if(m_Pause)
        {
          SetSpeed(OMX_PLAYSPEED_PAUSE);
          m_av_clock->OMXPause();
        }
        else
        {
          SetSpeed(OMX_PLAYSPEED_NORMAL);
          m_av_clock->OMXResume();
        }
        break;

However when I look into the code more deeply there is rather more happening than simply setting the speed to zero, so it may not be possible to use the same idea.
.
#7
In omxplayer, pausing is handled by setting the replay speed to zero - audio and video freeze instantly and continue as normal when the pause is deselected. I presume the same solution would not work on Vomp?
#8
First impression is that the latest git fixes my hanging problem. Maybe there are some other quirks but we can fix those later.

Many thanks, and well done.

Dave
#9
Not as difficult as I feared  8)

The failing line is

     error = vw->ProtOMXEmptyThisBuffer(omx_aud_rend/*dec*/, cur_input_buf_omx);

at the end of the function. I suspect there is a timing issue somewhere as the failure changed depending on how many logging statements were included - in some cases the hang problem disappeared completely. This is the output with one log statement immediately before the above line:

15:54:15.905686 [debug]  2028 Remote - CECLOG: 64502 16 received data: header:00030004 p0:00044404 p1:00000000 p2:0000000
0 p3:00000000 reason:4
15:54:15.906636 [debug]  2028 Remote - CECLOG: 64503 8 >> 04:44:04
15:54:15.906842 [debug]  2028 Remote - CECLOG: 64504 4 >> TV (0) -> Playback 1 (4): user control pressed (44)
15:54:15.906996 [debug]  2028 Remote - CECLOG: 64504 16 key pressed: right (4)
15:54:15.913810 [debug]  2028 Boxx - Construct, now 8
15:54:15.909163 [debug]  2028 VDR - Rxd a response packet, requestID=1318, len=100000
15:54:15.914351 [debug]  2028 VVideoRec - Draw bar clocks
15:54:15.915965 [debug]  2028 DemuxerTS - getFrameNumfromPTS pts 6051208009 deleted 15 difference 0
15:54:15.916198 [debug]  2028 VVideoRec - 0:15:56 / 1:00:28
15:54:15.916888 [debug]  2028 BoxStack - Update called
15:54:15.917002 [debug]  2028 BoxStack - Locked for update
15:54:15.917506 [debug]  2028 BoxStack - Unlocked for update
15:54:15.917635 [debug]  2028 Timers - Starting cancel timer 0xa638ac 1, list size = 3
15:54:15.917737 [debug]  2028 Timers - Removed timer for 0xa638ac ref 1
15:54:15.918042 [debug]  2028 VDR - RR unsleep
15:54:15.904278 [debug]  2028 Timers - sending timer to 0xa638ac with parameter 2
15:54:15.924730 [debug]  2028 VVideoRec - Draw bar clocks
15:54:15.925799 [debug]  2028 Timers - Starting set timer 1
15:54:15.926074 [debug]  2028 Timers - Timer set for 0xa638ac ref 1
15:54:15.926177 [debug]  2028 Timers - Second rollover - CHECK FIXME
15:54:15.926252 [debug]  2028 Timers - Starting set timer 1
15:54:15.926330 [debug]  2028 Boxx - Destruct, now 7
15:54:15.926410 [debug]  2028 Player - LOCKED
15:54:15.926483 [debug]  2028 Player - SKIP FORWARD 60 SECONDS
15:54:15.928447 [debug]  2028 Audio - ****9
15:54:15.929584 [debug]  2028 DemuxerTS - getFrameNumfromPTS pts 6051209179 deleted 15 difference 0
15:54:15.929759 [debug]  2028 Player - Switch state from 1 to 7
15:54:15.929843 [debug]  2028 VFeed - Stop1
15:54:15.930666 [debug]  2028 VFeed - Stop2

#10
Quote from: MartenR on November 02, 2012, 21:37:53
@davep
Please also add to audioomx, log message. I do not think that the videoomx thread causes problems, since it exits cleanly.
I did log audioomx but it seemed that the video function was the last to be called. However I've now added logging to the entry and to every exit point and it seems that there may be a problem:
13:29:50.929267 [debug]  2126 Remote - CECLOG: 42622 8 >> 04:44:04
13:29:50.929566 [debug]  2126 Remote - CECLOG: 42622 4 >> TV (0) -> Playback 1 (4): user control pressed (44)
13:29:50.929754 [debug]  2126 Remote - CECLOG: 42622 16 key pressed: right (4)
13:29:50.934198 [debug]  2126 Audio - ++++IN
13:29:50.934417 [debug]  2126 Audio - ----4
13:29:50.937258 [debug]  2126 VDR - RR sleep - opcode 7
13:29:50.939620 [debug]  2126 Audio - ++++IN
13:29:50.939771 [debug]  2126 Audio - ----4
13:29:50.941122 [debug]  2126 Timers - Timer firing for client 0x25a07c ref 2
13:29:50.942435 [debug]  2126 Boxx - Construct, now 8
13:29:50.943731 [debug]  2126 VVideoRec - Draw bar clocks
13:29:50.945727 [debug]  2126 Audio - ++++IN
13:29:50.947276 [debug]  2126 DemuxerTS - getFrameNumfromPTS pts 6878675788 deleted 8 difference 0
13:29:50.948233 [debug]  2126 VVideoRec - 0:09:25 / 1:00:50
13:29:50.948914 [debug]  2126 BoxStack - Update called
13:29:50.949016 [debug]  2126 BoxStack - Locked for update
13:29:50.953240 [debug]  2126 VDR - Rxd a response packet, requestID=609, len=100000
13:29:50.954256 [debug]  2126 VDR - RR unsleep
13:29:50.956589 [debug]  2126 BoxStack - Unlocked for update
13:29:50.957784 [debug]  2126 Timers - Starting cancel timer 0x25a07c 1, list size = 3
13:29:50.957936 [debug]  2126 Timers - Removed timer for 0x25a07c ref 1
13:29:50.958998 [debug]  2126 Timers - Starting set timer 1
13:29:50.959302 [debug]  2126 Timers - Timer set for 0x25a07c ref 1
13:29:50.959408 [debug]  2126 Timers - Second rollover - CHECK FIXME
13:29:50.959483 [debug]  2126 Timers - Starting set timer 1
13:29:50.959566 [debug]  2126 Boxx - Destruct, now 7
13:29:50.959649 [debug]  2126 Player - LOCKED
13:29:50.962920 [debug]  2126 Player - SKIP FORWARD 60 SECONDS
13:29:50.961781 [debug]  2126 Timers - sending timer to 0x25a07c with parameter 2
13:29:50.963544 [debug]  2126 VVideoRec - Draw bar clocks
13:29:50.964785 [debug]  2126 DemuxerTS - getFrameNumfromPTS pts 6878677408 deleted 8 difference 0
13:29:50.964960 [debug]  2126 Player - Switch state from 1 to 7
13:29:50.965044 [debug]  2126 VFeed - Stop1
13:29:50.968532 [debug]  2126 DemuxerTS - getFrameNumfromPTS pts 6878677768 deleted 8 difference 0
13:29:50.968804 [debug]  2126 VVideoRec - 0:09:25 / 1:00:50
13:29:50.969084 [debug]  2126 VFeed - Stop2
13:29:50.969206 [debug]  2126 AFeed - Stop1
13:29:50.969924 [debug]  2126 BoxStack - Update called
13:29:50.970044 [debug]  2126 BoxStack - Locked for update
13:29:50.972577 [debug]  2126 AFeed - Stop2
13:29:50.974870 [debug]  2126 BoxStack - Unlocked for update
13:29:50.975064 [debug]  2126 Timers - Second rollover - CHECK FIXME
13:29:50.975146 [debug]  2126 Timers - Starting set timer 1
13:29:50.975228 [debug]  2126 Timers - timerEventFinished for 0x25a07c
13:29:50.975306 [debug]  2126 Timers - timerEventFinished RESTART for 0x25a07c

The ++++ lines are the function entry and ---- marks the exits. It seems that we do enter just before the skip and never exit.

I will try to narrow down the point of failure, but this is a complex function with many code paths and may take a while...
#11
Quote from: MartenR on November 01, 2012, 21:42:50
Your problem is caused, by an interuption of the audio and video feeding threads inside an omx command, we have to find out, where it occurs.
So can you please put log message in videomx and audioomx inside DeliverMediaPacket( so that we can see where the threads is forcefully exited, when the omx connection is damaged. (So in which command it was)

These are rather large functions and so difficult to instrument. Also it seems that adding more debug code reduces the likelihood of failure. However I do see a consistent signature of the failure in the log:

12:39:26.999358 [debug]  2031 BoxStack - Update called
12:39:27.000129 [debug]  2031 BoxStack - Locked for update
12:39:27.000760 [debug]  2031 BoxStack - Unlocked for update
12:39:27.000918 [debug]  2031 Timers - Starting cancel timer 0x2a9cb4 1, list size = 3
12:39:27.001107 [debug]  2031 Timers - Removed timer for 0x2a9cb4 ref 1
12:39:27.001844 [debug]  2031 Timers - Starting set timer 1
12:39:27.002931 [debug]  2031 Timers - Timer set for 0x2a9cb4 ref 1
12:39:27.003144 [debug]  2031 Timers - Starting set timer 1
12:39:27.004074 [debug]  2031 Boxx - Destruct, now 7
12:39:27.004224 [debug]  2031 Player - LOCKED
12:39:27.004301 [debug]  2031 Player - SKIP FORWARD 60 SECONDS
12:39:27.005327 [debug]  2031 Video - ++++DP0
12:39:27.005496 [debug]  2031 Video - ++++DP1
12:39:27.005573 [debug]  2031 Video - ++++DP2
12:39:27.005649 [debug]  2031 Video - ++++DP2a
12:39:27.006861 [debug]  2031 DemuxerTS - getFrameNumfromPTS pts 3288940265 deleted 21 difference 0
12:39:27.007045 [debug]  2031 Player - Switch state from 1 to 7
12:39:27.007127 [debug]  2031 VFeed - Stop1
12:39:27.008377 [debug]  2031 VFeed - Stop2
12:39:27.008582 [debug]  2031 AFeed - Stop1
12:39:27.010694 [debug]  2031 AFeed - Stop2

This pattern of video calls immediately after the skip does not appear if the skip is successful. Here is the section of code in videoomx.cc:

Log::getInstance()->log("Video", Log::DEBUG, "++++DP2");

        if (!cur_input_buf_omx) {
                input_bufs_omx_mutex.Lock();
                if (input_bufs_omx_free.size()==0) {
                        input_bufs_omx_mutex.Unlock();
                        //Log::getInstance()->log("Video", Log::DEBUG, "Deliver MediaPacket no free sample");
Log::getInstance()->log("Video", Log::DEBUG, "++++DP2a");
                        return 0; // we do not have a free media sample

                }
Log::getInstance()->log("Video", Log::DEBUG, "++++DP2b");
                cur_input_buf_omx=input_bufs_omx_free.front();
                cur_input_buf_omx->nFilledLen=0;
                cur_input_buf_omx->nOffset=0;
                cur_input_buf_omx->nTimeStamp=intToOMXTicks(0);
                input_bufs_omx_free.pop_front();
                input_bufs_omx_mutex.Unlock();
        }

Log::getInstance()->log("Video", Log::DEBUG, "++++DP3");

so it seems that the function returns successfully?
#12
The hang is in the line

        error=OMX_SendCommand(handle,OMX_CommandStateSet,type,0);

in VideoOMX::ChangeComponentState.

I already commented out the lines in audioomx.cc.
#13
Here's the instrumented code:
                Log::getInstance()->log("Audio", Log::DEBUG, "deallocatecodecsomx mark 5");
                 video->LockClock();
Log::getInstance()->log("Audio", Log::DEBUG, "**DP0**");
                if (!video->ChangeComponentState(omx_aud_rend,OMX_StateIdle)) {
                        Log::getInstance()->log("Audio", Log::DEBUG, "aud_rend ChangeComponentState");
                }
Log::getInstance()->log("Audio", Log::DEBUG, "**DP1**");
        // TODO proper deinit sequence
                // first flush all buffers

                error=OMX_SendCommand(omx_aud_rend,OMX_CommandFlush, omx_rend_input_port, NULL);
Log::getInstance()->log("Audio", Log::DEBUG, "**DP2**");
                if (error!=OMX_ErrorNone) {
                        Log::getInstance()->log("Audio", Log::DEBUG, "OMX_Flush rend in failed %x", error);

                }

        /*      error=OMX_SendCommand(omx_aud_dec,OMX_CommandFlush, omx_codec_input_port, NULL);
                if (error!=OMX_ErrorNone){
                        Log::getInstance()->log("Audio", Log::DEBUG, "OMX_Flush codec out failed %x", error);

                }*/


        /*      if (!video->CommandFinished(omx_aud_dec,OMX_CommandFlush,omx_codec_input_port)) {
                        Log::getInstance()->log("Audio", Log::DEBUG, "flush cmd codec input failed");
                }*/



                error=OMX_SendCommand(omx_clock,OMX_CommandFlush, omx_clock_output_port, NULL);
Log::getInstance()->log("Audio", Log::DEBUG, "**DP3**");
                if (error!=OMX_ErrorNone){
                        Log::getInstance()->log("Audio", Log::DEBUG, "OMX_Flush clock out failed %x", error);

                }

                error=OMX_SendCommand(omx_aud_rend,OMX_CommandFlush, omx_rend_clock_port, NULL);
Log::getInstance()->log("Audio", Log::DEBUG, "**DP4**");
                if (error!=OMX_ErrorNone){
                        Log::getInstance()->log("Audio", Log::DEBUG, "OMX_Flush rend clock failed %x", error);

                }
                Log::getInstance()->log("Audio", Log::DEBUG, "deallocatecodecsomx mark 6");


and the hang occurs after DP0 but before DP1. The "aud_rend ChangeComponentState" log entry does not appear either.
#14
I've attached a log file showing the problem. Vompclient is up-to-date and with the patch from reply 7 applied. Raspbian is also up-to-date.

To create the log, I navigated using the TV remote to a recording and started it playing. I pressed the 'skip 60s' button on the remote 5 times, each time waiting until the progress bar OSD had disappeared before the next press. So far so good. Then I pressed the 'skip 60s' again, and once more about 2s later while the progress bar was still shown. The client then froze.

In a separate experiment I was able to skip at least 25 times without a problem, provided the progress bar had disappeared before pressing again. With a shorter wait (so the bar was still displayed) the client froze on the 4th attempt.
#15
Quote from: MartenR on November 01, 2012, 07:22:06
So one comment, the problem with loosing the progress bar is probably a second issue (related to the vector osd) than the black screen.
I think all other then laz are reporting the second issue?

The client freezing/hanging on skip issue has been happening since the first RasPi version. The progress bar issue is more recent and is likely related to the vector ISD.

@JTe: Yes I recall the MVP occasionally freezing on skip; maybe 5% of the time and only when repeatedly pressing the skip buttons. RasPi freezes about 25% of the time.