[mythtv-users] Getting slower
DaveD
mythtv at guiplot.com
Mon Aug 10 15:49:16 UTC 2020
On 8/8/20 11:52 PM, jam at tigger.ws wrote:
>
>> On 9 Aug 2020, at 2:17 pm, Stephen Worthington <stephen_agent at jsw.gen.nz> wrote:
>>
>> On Sat, 8 Aug 2020 21:12:41 -0700, you wrote:
>>
>>> On 8/2/20 4:00 PM, jam at tigger.ws wrote:
>>>> Over the last few releases mythtv has got slower to start and stop.
>>>> What is the delay looking for ipv6 dtuff?
>>>>
>>>> This trace is from my mac frontrnd, my linux frontend start is similar, the stop takes 3 sec.
>>>>
>>>> If the issue is not my config should we not gently think about start and stop times from a dev point of view?
>>>>
>>>> James
>>>>
>>>> 00.730068 I Setup Interrupt: 2 handler
>>>> 00.730091 I Setup Terminated: 15 handler
>>>> 00.730098 I Setup Segmentation fault: 11 handler
>>>> 00.730104 I Setup Abort trap: 6 handler
>>>> 00.730109 I Setup Bus error: 10 handler
>>>> 00.730115 I Setup Floating point exception: 8 handler
>>>> 00.730123 I Setup Illegal instruction: 4 handler
>>>> 00.730130 I Setup User defined signal 1: 30 handler
>>>> 00.730137 I Setup User defined signal 2: 31 handler
>>>> .....
>>> I finally caught a slow startup (my wife usually has it started by the
>>> time I get to it) and here's the frontend output:
>>>
>>>> /usr/bin/mythfrontend --loglevel warning -O PowerOffTVOnExit=0 -O
>>> libCECEnabled=0 -geometry 1920x1080+1920+0
>>> qt.core.logging: Ignoring malformed logging rule: '’*.debug=false’'
>>> "Display: Requesting EGL for 'Mesa Project, 1.4'"
>>> 2020-08-08 20:44:32.526210 I [2264517/2264517] thread_unknown
>>> signalhandling.cpp:191:SetHandlerPrivate Setup Interrupt handler
>>> 2020-08-08 20:44:32.526259 I [2264517/2264517] thread_unknown
>>> signalhandling.cpp:191:SetHandlerPrivate Setup Terminated handler
>>> 2020-08-08 20:44:32.526288 I [2264517/2264517] thread_unknown
>>> signalhandling.cpp:191:SetHandlerPrivate Setup Segmentation fault handler
>>> 2020-08-08 20:44:32.526300 I [2264517/2264517] thread_unknown
>>> signalhandling.cpp:191:SetHandlerPrivate Setup Aborted handler
>>> 2020-08-08 20:44:32.526311 I [2264517/2264517] thread_unknown
>>> signalhandling.cpp:191:SetHandlerPrivate Setup Bus error handler
>>> 2020-08-08 20:44:32.526321 I [2264517/2264517] thread_unknown
>>> signalhandling.cpp:191:SetHandlerPrivate Setup Floating point exception
>>> handler
>>> 2020-08-08 20:44:32.526344 I [2264517/2264517] thread_unknown
>>> signalhandling.cpp:191:SetHandlerPrivate Setup Illegal instruction handler
>>> 2020-08-08 20:44:32.526358 I [2264517/2264517] thread_unknown
>>> signalhandling.cpp:191:SetHandlerPrivate Setup Real-time signal 0 handler
>>> 2020-08-08 20:44:32.526378 I [2264517/2264517] thread_unknown
>>> signalhandling.cpp:191:SetHandlerPrivate Setup User defined signal 1
>>> handler
>>> 2020-08-08 20:44:32.526387 I [2264517/2264517] thread_unknown
>>> signalhandling.cpp:191:SetHandlerPrivate Setup User defined signal 2
>>> handler
>>> 2020-08-08 20:44:32.526402 I [2264517/2264517] thread_unknown
>>> signalhandling.cpp:191:SetHandlerPrivate Setup Hangup handler
>>> 2020-08-08 20:44:32.526587 C [2264517/2264517] thread_unknown
>>> mythcommandlineparser.cpp:2602:ConfigureLogging mythfrontend version:
>>> fixes/31 [v31.0-v31.0-47-gfc90482281] www.mythtv.org
>>> 2020-08-08 20:44:32.526606 C [2264517/2264517] thread_unknown
>>> mythcommandlineparser.cpp:2606:ConfigureLogging Qt version: compile:
>>> 5.13.2, runtime: 5.13.2
>>> 2020-08-08 20:44:32.526669 I [2264517/2264517] thread_unknown
>>> mythcommandlineparser.cpp:2608:ConfigureLogging Fedora 31 (Workstation
>>> Edition) (x86_64)
>>> 2020-08-08 20:44:32.526674 N [2264517/2264517] thread_unknown
>>> mythcommandlineparser.cpp:2610:ConfigureLogging Enabled verbose msgs:
>>> general
>>> 2020-08-08 20:44:32.863781 E [2264517/2264517] CoreContext
>>> mythdb.cpp:181:DBError DB Error (StorageGroup::StorageGroup()):
>>> Query was:
>>>
>>> Driver error was [1/]:
>>> Driver not loaded
>>> Database error was:
>>> Driver not loaded
>>>
>>> 2020-08-08 20:44:32.969563 E [2264517/2264517] CoreContext
>>> serverpool.cpp:550:bind Failed binding to UDP [::]:0 - Error 10:
>>> Protocol type not supported
>>> libEGL warning: FIXME: egl/x11 doesn't support front buffer rendering.
>>> 2020-08-08 20:44:37.078916 E [2264517/2264517] CoreContext
>>> serverpool.cpp:427:listen Failed listening on TCP [::]:6547 - Error 10:
>>> Protocol type not supported
>>> libva info: VA-API version 1.6.0
>>> libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
>>> libva info: Found init function __vaDriverInit_1_6
>>> libva info: va_openDriver() returns 0
>>> libva info: VA-API version 1.6.0
>>> libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
>>> libva info: Found init function __vaDriverInit_1_6
>>> libva info: va_openDriver() returns 0
>>> Cannot load libcuda.so.1
>>>
>>> The above lines come out very quickly, then the hard drive thrashes for
>>> a long time before the next line comes up and the menu appears on the
>>> screen. The difference between the timestamps (20:44:37 to 20:45:25) is
>>> pretty much the time the hard drive is working (48 secs).
>>>
>>> 2020-08-08 20:45:25.153977 A [2264517/2264517] CoreContext
>>> mediamonitor-unix.cpp:204:CheckMountable MMUnix:CheckMountable: DBus
>>> interface error: The name is not activatable
>>> 2020-08-08 20:45:25.155653 W [2264517/2264517] CoreContext
>>> mediamonitor-unix.cpp:212:CheckMountable MMUnix:UDisks2 service found.
>>> Media Monitor does not support this yet!
>>> 2020-08-08 20:45:25.204403 W [2264517/2264517] CoreContext
>>> mythplugin.cpp:110:MythPluginManager No libraries in plugins directory
>>> /usr/lib64/mythtv/plugins
>>>
>>> All is normal after that. Should I increase the verbosity? Will it
>>> tell me what's going on during all that hard drive activity? After this
>>> startup, I exited and re-ran the frontend and it was ready to go in
>>> about 6 seconds. Here's that output:
>>>
>>> 2020-08-08 20:50:11.231130 I [2265508/2265508] thread_unknown
>>> mythcommandlineparser.cpp:2608:ConfigureLogging Fedora 31 (Workstation
>>> Edition) (x86_64)
>>> 2020-08-08 20:50:11.231131 N [2265508/2265508] thread_unknown
>>> mythcommandlineparser.cpp:2610:ConfigureLogging Enabled verbose msgs:
>>> general
>>> 2020-08-08 20:50:11.341611 E [2265508/2265508] CoreContext
>>> mythdb.cpp:181:DBError DB Error (StorageGroup::StorageGroup()):
>>> Query was:
>>>
>>> Driver error was [1/]:
>>> Driver not loaded
>>> Database error was:
>>> Driver not loaded
>>>
>>> 2020-08-08 20:50:11.388052 E [2265508/2265508] CoreContext
>>> serverpool.cpp:550:bind Failed binding to UDP [::]:0 - Error 10:
>>> Protocol type not supported
>>> libEGL warning: FIXME: egl/x11 doesn't support front buffer rendering.
>>> 2020-08-08 20:50:14.259651 E [2265508/2265508] CoreContext
>>> serverpool.cpp:427:listen Failed listening on TCP [::]:6547 - Error 10:
>>> Protocol type not supported
>>> libva info: VA-API version 1.6.0
>>> libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
>>> libva info: Found init function __vaDriverInit_1_6
>>> libva info: va_openDriver() returns 0
>>> libva info: VA-API version 1.6.0
>>> libva info: Trying to open /usr/lib64/dri/i965_drv_video.so
>>> libva info: Found init function __vaDriverInit_1_6
>>> libva info: va_openDriver() returns 0
>>> Cannot load libcuda.so.1
>>> 2020-08-08 20:50:17.821604 A [2265508/2265508] CoreContext
>>> mediamonitor-unix.cpp:204:CheckMountable MMUnix:CheckMountable: DBus
>>> interface error: The name is not activatable
>>> 2020-08-08 20:50:17.822071 W [2265508/2265508] CoreContext
>>> mediamonitor-unix.cpp:212:CheckMountable MMUnix:UDisks2 service found.
>>> Media Monitor does not support this yet!
>>>
>>> Same output, very different startup time. What's the difference?
>>>
>>> Dave D.
>> Do you have the Media Monitor looking for disks in the CD/DVD drive?
>> Is there a disk in the CD/DVD drive? The time when you are getting
>> the slowdown is about when mythfrontend will look for a disk to play,
>> if there is one. However, it will only do that if you have the Media
>> Monitor enabled. What does this SQL show?
>>
>> select * from settings where value like '%monitord%';
>>
>> I get this as I have it disabled on all frontends:
>>
>> MariaDB [mythconverg]> select * from settings where value like
>> '%monitord%';
>> +---------------+------+----------+
>> | value | data | hostname |
>> +---------------+------+----------+
>> | MonitorDrives | 0 | mypvr |
>> | MonitorDrives | 0 | gt70 |
>> | MonitorDrives | 0 | lith |
>> | MonitorDrives | 0 | crw-pvr |
>> +---------------+------+----------+
>> 4 rows in set (0.00 sec)
>>
>> If mythfrontend has to wait while an optical disk is spun up and read,
>> that would explain the long delay. When mythfrontend is restarted, it
>> is likely that the data from the disk that it need to read is still
>> cached and that would explain the lack of delay.
> What troubles me is that ALL the front ends are slow. There have been lots of sugestions but none seem to go anythere. eg
>
> mysql> select * from settings where value like '%monitord%';
> +---------------+------+--------------------------+
> | value | data | hostname |
> +---------------+------+--------------------------+
> | MonitorDrives | 0 | sandypit |
> | MonitorDrives | 0 | haycorn.local |
> | MonitorDrives | 0 | twill |
> | MonitorDrives | 0 | haycorn |
> | MonitorDrives | 0 | haycorn.home |
> | MonitorDrives | 0 | twill.home |
> | MonitorDrives | 0 | jamess-macbook.local |
> | MonitorDrives | 0 | dropbear |
> | MonitorDrives | 0 | ws101.home |
> | MonitorDrives | 0 | jamess-macbook-pro.local |
> | MonitorDrives | 0 | piglet.home |
> | MonitorDrives | 0 | twill.local |
> | MonitorDrives | 0 | ws123.home |
> | MonitorDrives | 0 | ws120.home |
> | MonitorDrives | 0 | plasma.home |
> | MonitorDrives | 0 | clydesdale |
> | MonitorDrives | 0 | sanders |
> | MonitorDrives | 0 | ws104.home |
> | MonitorDrives | 0 | blackbeauty |
> | MonitorDrives | 0 | mipad.home |
> +---------------+------+--------------------------+
>
> James
Mine, too, are all zero. I rarely use my other frontends and expect
them to be slow, anyway, since they are low power machines. My main
frontend in the living room is a hot, (relatively) new I7 with modern,
fast (although not SSD fast) hard drives. Also, the spin-up wait
wouldn't account for the difference in startup times. The hard drive is
working constantly during that 48 seconds of no output (light doesn't
even flicker once). This machine is also my master backend so next time
I'll watch the BACKEND log to see if it gives a clue.
Dave D.
More information about the mythtv-users
mailing list