[mythtv-commits] Ticket #9503: Very sluggish UI during reschedules especially
MythTV
noreply at mythtv.org
Tue Feb 8 20:47:59 UTC 2011
#9503: Very sluggish UI during reschedules especially
------------------------------------------------+--------------------------
Reporter: Mike Rice <mikerice1969@…> | Owner:
Type: Bug Report | Status: new
Priority: minor | Milestone: unknown
Component: MythTV - General | Version:
Severity: medium | 0.24-fixes
Keywords: | Resolution:
| Ticket locked: 0
------------------------------------------------+--------------------------
Description changed by wagnerrp:
Old description:
> I am experiencing very sluggish UI on my frontend (backend on another
> machine). It happens frequently but I usually notice a problem when a
> reschedule is happening. For example if I am watching something at 2
> minutes past the hour it may just pause playback for several seconds.
> After I delete a recording and am looking for the next in the playback
> box the UI may become unresponsive for several seconds. A fairly
> reliable way to reproduce it is as follows:[[BR]]
> 1. Start watching a recording on frontend[[BR]]
> 2. On backend do: mythbackend --resched[[BR]]
> 3. Pause/UnPause a few times. Usually there is no response from an
> unpause for several seconds.[[BR]]
>
> Here are log snippets from frontend and backend for one of these cases:
>
> Annotated front end log snippets:
> {{{
> 2011-01-22 15:39:02.065 Player(0): 2000 progressive frames seen.
> 'video_output' mean = '16664.54', std. dev. = '54.88', fps = '60.01'
> 'video_output' mean = '16665.06', std. dev. = '47.04', fps = '60.01'
> 'video_output' mean = '16664.17', std. dev. = '32.60', fps = '60.01'
> 2011-01-22 15:39:06.181 ScreenSaverX11Private: Calling xscreensaver-
> command -deactivate
> 2011-01-22 15:39:06.191 MythSocket(ffffffffb2214ed0:44): write -> 44 122
> MESSAGE[]:[]SYSTEM_EVENT PLAY_PAUSED HOSTNAME mythfrontend2 CHANID 5736
> STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2
> 2011-01-22 15:39:06.282 MythSocket(ffffffffb2214ed0:44): read <- 44 2
> OK
> 2011-01-22 15:39:06.283 UpdateOSDSeekMessage(Paused, 0)
> 2011-01-22 15:39:06.284 Player(0): Play speed: rate: 59.9401 speed: 0
> skip: 0 => new interval 16683
> 2011-01-22 15:39:06.300 VideoOutputXv: UpdatePauseFrame()
> UUUUUUuUUuUUULUUUUUUUUUUUUUUUUU
> 2011-01-22 15:39:06.305 ScreenSaverX11Private: StopTimer
> <<<>>>
> <<<Unpaused after about 3 sec pause>>>
> <<<>>>
> 2011-01-22 15:39:09.148 MythSocket(ffffffffb2214ed0:44): write -> 44 124
> MESSAGE[]:[]SYSTEM_EVENT PLAY_UNPAUSED HOSTNAME mythfrontend2 CHANID 5736
> STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2
> <<<<>>>
> <<<No response for 28 seconds>>
> <<<>>>
> 2011-01-22 15:39:37.884 MythSocket(ffffffffb2214ed0:44): read <- 44 2
> OK
> 2011-01-22 15:39:37.884 Player(0): Play( 1.0, normal 1, unpause audio 1)
> 2011-01-22 15:39:37.884 UpdateOSDSeekMessage(Play, 2)
> 2011-01-22 15:39:37.885 Player(0): Play speed: rate: 59.9401 speed: 1
> skip: 1 => new interval 16683
> 2011-01-22 15:39:37.885 Player(0): Stretch Factor 1, allow passthru
> }}}
> Annotated backend log snippets:
> {{{
> <<< OFirst pause >>>
> <<<>>>
> 2011-01-22 15:39:06.189 MythSocket(99b24e0:47): read <- 47 122
> MESSAGE[]:[]SYSTEM_EVENT PLAY_PAUSED HOSTNAME mythfrontend2 CHANID 5736
> STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2
> 2011-01-22 15:39:06.228 MythEvent: SYSTEM_EVENT PLAY_PAUSED HOSTNAME
> mythfrontend2 CHANID 5736 STARTTIME 2011-01-22T04:29:00 SENDER
> mythfrontend2
> 2011-01-22 15:39:06.254 MythSocket(99b24e0:47): write -> 47 2 OK
> 2011-01-22 15:39:06.254 MythSocket(9993d30:46): write -> 46 140
> BACKEND_MESSAGE[]:[]SYSTEM_EVENT PLAY_PAUSED HOSTNAME mythfrontend2
> CHANID 5736 STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2[]:[]empty
>
> <<<Unpaused after 3 seconds>>>
> 2011-01-22 15:39:09.145 MythSocket(99b24e0:47): read <- 47 124
> MESSAGE[]:[]SYSTEM_EVENT PLAY_UNPAUSED HOSTNAME mythfrontend2 CHANID 5736
> STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2
> <<< 12 seconds >>>
> 2011-01-22 15:39:22.256 MythEvent: SYSTEM_EVENT PLAY_UNPAUSED HOSTNAME
> mythfrontend2 CHANID 5736 STARTTIME 2011-01-22T04:29:00 SENDER
> mythfrontend2
> <<< 15 seconds >>>
> 2011-01-22 15:39:37.826 MythSocket(99b24e0:47): write -> 47 2 OK
> 2011-01-22 15:39:37.826 MythSocket(9993d30:46): write -> 46 142
> BACKEND_MESSAGE[]:[]SYSTEM_EVENT PLAY_UNPAUSED HOSTNAME mythfrontend2
> CHANID 5736 STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2[]:[]empty
> 2011-01-22 15:39:40.941 scheduler: Scheduled items: Scheduled 3550 items
> in 45.4 = 4.64 match + 40.78 place
> 2011-01-22 15:39:40.965 MythEvent: SYSTEM_EVENT SCHEDULER_RAN SENDER
> masterbackend
> }}}
>
> It seems the reschedule blocks processing and since my reschedule takes
> around 45 seconds it is really noticeable. I was ok though in 0.22 and I
> didn't see this problem until upgrading to 0.24.[[BR]]
>
> I'll attach more complete logs to the ticket. I'd be happy to provide
> any other logs and assist in any means possible. The WAF is really
> taking a hit due to this.
> {{{
> MythTV Version : v0.24-113-g90fe13c-dirty
> MythTV Branch : fixes/0.24
> Network Protocol : 63
> Library API : 0.24.20101129-1
> QT Version : 4.7.1
> Options compiled in:
> linux debug using_alsa using_oss using_backend using_bindings_perl
> using_bindings_python using_dvb using_firewire using_frontend
> using_hdhomerun using_hdpvr using_iptv using_ivtv using_joystick_menu
> using_lirc using_mheg using_opengl_video using_opengl_vsync using_qtdbus
> using_qtwebkit using_v4l using_x11 using_xrandr using_xv using_xvmc
> using_xvmc_vld using_xvmcw using_bindings_perl using_bindings_python
> using_mythtranscode using_opengl using_vdpau using_ffmpeg_threads
> using_live using_mheg
> }}}
New description:
I am experiencing very sluggish UI on my frontend (backend on another
machine). It happens frequently but I usually notice a problem when a
reschedule is happening. For example if I am watching something at 2
minutes past the hour it may just pause playback for several seconds.
After I delete a recording and am looking for the next in the playback box
the UI may become unresponsive for several seconds. A fairly reliable way
to reproduce it is as follows:[[BR]]
1. Start watching a recording on frontend[[BR]]
2. On backend do: mythbackend --resched[[BR]]
3. Pause/UnPause a few times. Usually there is no response from an
unpause for several seconds.[[BR]]
Here are log snippets from frontend and backend for one of these cases:
Annotated front end log snippets:
{{{
2011-01-22 15:39:02.065 Player(0): 2000 progressive frames seen.
'video_output' mean = '16664.54', std. dev. = '54.88', fps = '60.01'
'video_output' mean = '16665.06', std. dev. = '47.04', fps = '60.01'
'video_output' mean = '16664.17', std. dev. = '32.60', fps = '60.01'
2011-01-22 15:39:06.181 ScreenSaverX11Private: Calling xscreensaver-
command -deactivate
2011-01-22 15:39:06.191 MythSocket(ffffffffb2214ed0:44): write -> 44 122
MESSAGE[]:[]SYSTEM_EVENT PLAY_PAUSED HOSTNAME mythfrontend2 CHANID 5736
STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2
2011-01-22 15:39:06.282 MythSocket(ffffffffb2214ed0:44): read <- 44 2
OK
2011-01-22 15:39:06.283 UpdateOSDSeekMessage(Paused, 0)
2011-01-22 15:39:06.284 Player(0): Play speed: rate: 59.9401 speed: 0
skip: 0 => new interval 16683
2011-01-22 15:39:06.300 VideoOutputXv: UpdatePauseFrame()
UUUUUUuUUuUUULUUUUUUUUUUUUUUUUU
2011-01-22 15:39:06.305 ScreenSaverX11Private: StopTimer
<<<>>>
<<<Unpaused after about 3 sec pause>>>
<<<>>>
2011-01-22 15:39:09.148 MythSocket(ffffffffb2214ed0:44): write -> 44 124
MESSAGE[]:[]SYSTEM_EVENT PLAY_UNPAUSED HOSTNAME mythfrontend2 CHANID 5736
STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2
<<<<>>>
<<<No response for 28 seconds>>
<<<>>>
2011-01-22 15:39:37.884 MythSocket(ffffffffb2214ed0:44): read <- 44 2
OK
2011-01-22 15:39:37.884 Player(0): Play( 1.0, normal 1, unpause audio 1)
2011-01-22 15:39:37.884 UpdateOSDSeekMessage(Play, 2)
2011-01-22 15:39:37.885 Player(0): Play speed: rate: 59.9401 speed: 1
skip: 1 => new interval 16683
2011-01-22 15:39:37.885 Player(0): Stretch Factor 1, allow passthru
}}}
Annotated backend log snippets:
{{{
<<< OFirst pause >>>
<<<>>>
2011-01-22 15:39:06.189 MythSocket(99b24e0:47): read <- 47 122
MESSAGE[]:[]SYSTEM_EVENT PLAY_PAUSED HOSTNAME mythfrontend2 CHANID 5736
STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2
2011-01-22 15:39:06.228 MythEvent: SYSTEM_EVENT PLAY_PAUSED HOSTNAME
mythfrontend2 CHANID 5736 STARTTIME 2011-01-22T04:29:00 SENDER
mythfrontend2
2011-01-22 15:39:06.254 MythSocket(99b24e0:47): write -> 47 2 OK
2011-01-22 15:39:06.254 MythSocket(9993d30:46): write -> 46 140
BACKEND_MESSAGE[]:[]SYSTEM_EVENT PLAY_PAUSED HOSTNAME mythfrontend2 CHANID
5736 STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2[]:[]empty
<<<Unpaused after 3 seconds>>>
2011-01-22 15:39:09.145 MythSocket(99b24e0:47): read <- 47 124
MESSAGE[]:[]SYSTEM_EVENT PLAY_UNPAUSED HOSTNAME mythfrontend2 CHANID 5736
STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2
<<< 12 seconds >>>
2011-01-22 15:39:22.256 MythEvent: SYSTEM_EVENT PLAY_UNPAUSED HOSTNAME
mythfrontend2 CHANID 5736 STARTTIME 2011-01-22T04:29:00 SENDER
mythfrontend2
<<< 15 seconds >>>
2011-01-22 15:39:37.826 MythSocket(99b24e0:47): write -> 47 2 OK
2011-01-22 15:39:37.826 MythSocket(9993d30:46): write -> 46 142
BACKEND_MESSAGE[]:[]SYSTEM_EVENT PLAY_UNPAUSED HOSTNAME mythfrontend2
CHANID 5736 STARTTIME 2011-01-22T04:29:00 SENDER mythfrontend2[]:[]empty
2011-01-22 15:39:40.941 scheduler: Scheduled items: Scheduled 3550 items
in 45.4 = 4.64 match + 40.78 place
2011-01-22 15:39:40.965 MythEvent: SYSTEM_EVENT SCHEDULER_RAN SENDER
masterbackend
}}}
It seems the reschedule blocks processing and since my reschedule takes
around 45 seconds it is really noticeable. I was ok though in 0.22 and I
didn't see this problem until upgrading to 0.24.[[BR]]
I'll attach more complete logs to the ticket. I'd be happy to provide any
other logs and assist in any means possible. The WAF is really taking a
hit due to this.
--
--
Ticket URL: <http://code.mythtv.org/trac/ticket/9503#comment:1>
MythTV <http://code.mythtv.org/trac>
MythTV Media Center
More information about the mythtv-commits
mailing list