[mythtv-users] [0.25/0.26-fixes] mythvideo: 30 second delay after deleting video QUERY_SG_FILEQUERY

[Angela]

Hello

When I delete a movie in mythvideo the movie list gets updated, but playing
a movie or showing the recordings listing takes around 30 seconds.

I noticed that the first call to QUERY_SG_FILEQUERY does get answered
immediately, it takes up to 30 seconds or the socket gets a timeout and
reconnects.

I didn't manage to get a mythbackend log with socket or other interesting
debug, tried:
/usr/bin/mythbackend --user mythtv -v all --loglevel debug --syslog local7
/usr/bin/mythbackend --user mythtv -v  socket --loglevel debug --syslog
local7

Please find the mythfrontend.log below.

Coverart is on the root disk, all disk are active (not stand-by).
The problem exists since 0.25-fixes (around June) and in 0.26-fixes.

What takes the first QUERY_SG_FILEQUERY so long to complete ?

Angela 

2012-10-29 18:10:25.726205 I  MythSocket(2019070:51): write -> 51 43
DELETE_FILE[]:[]ABCD-Trailer.avi[]:[]Videos
2012-10-29 18:10:25.726745 I  MythSocket(2019070:51): read  <- 51 1       1
2012-10-29 18:10:25.727898 E  Top level can't become selected child
2012-10-29 18:10:25.728050 N  'title' (video-ui.xml:753): height overflow.
line height 62 paragraph height 62, area height 56
2012-10-29 18:10:25.728085 N  'title' (video-ui.xml:753): height overflow.
line height 62 paragraph height 62, area height 56
2012-10-29 18:10:25.728844 N  Container 'mythvideo' is missing child
'banner'
2012-10-29 18:10:25.738573 I  MythUIHelper:
LoadCacheImage(myth://Coverart@[::1]:6543/1492_coverart.jpg,myth:--Coverart@
[::1]:6543-1492_coverart.jpg--47x80.png)

>>2012-10-29 18:10:25.738650 I  MythSocket(2019070:51): write -> 51 61
QUERY_SG_FILEQUERY[]:[]::1[]:[]Coverart[]:[]1492_coverart.jpg

2012-10-29 18:10:25.738829 I  MythUIHelper:
LoadCacheImage(myth://Coverart@[::1]:6543/48752_coverart.jpg,myth:--Coverart
@[::1]:6543-48752_coverart.jpg--47x80.png)
2012-10-29 18:10:25.739167 I  (0x7f11f42fc708)::DecrRef() -> 1
2012-10-29 18:10:25.739210 I  MythUIHelper:
LoadCacheImage(myth://Coverart@[::1]:6543/12819_coverart.jpg,myth:--Coverart
@[::1]:6543-12819_coverart.jpg--47x80.png)
2012-10-29 18:10:25.739430 I  (0x7f11d8173c88)::DecrRef() -> 1
2012-10-29 18:10:25.739473 I  MythUIHelper:
LoadCacheImage(myth://Coverart@[::1]:6543/23398_coverart.jpg,myth:--Coverart
@[::1]:6543-23398_coverart.jpg--47x80.png)
2012-10-29 18:10:25.739995 I  MythUIHelper:
LoadCacheImage(myth://Coverart@[::1]:6543/9992_coverart.jpg,myth:--Coverart@
[::1]:6543-9992_coverart.jpg--47x80.png)
2012-10-29 18:10:27.042373 I  MythSocket(2919480:97): read  <- 97 83
BACKEND_MESSAGE[]:[]UPDATE_FILE_SIZE 10038 2012-10-29T17:00:00Z 9...
2012-10-29 18:10:27.042390 I  MythEvent: UPDATE_FILE_SIZE 10038
2012-10-29T17:00:00Z 910429668

>>2012-10-29 18:10:34.741891 I  MythSocket(2019070:51): read  <- 51 69
/var/lib/mythtv/coverart/1492_coverart.jpg[]:[]1347705420[]:[]226...

2012-10-29 18:10:34.741928 I  MythSocket(2019070:51): write -> 51 62
QUERY_SG_FILEQUERY[]:[]::1[]:[]Coverart[]:[]48752_coverart.jpg
2012-10-29 18:10:34.741942 I  (0x7f11f88a22d8)::IncrRef() -> 3
2012-10-29 18:10:34.741949 I  (0x7f11f88a22d8)::IncrRef() -> 4
2012-10-29 18:10:34.741952 I  (0x7f11f88a22d8)::DecrRef() -> 3
2012-10-29 18:10:34.741956 I
ImageLoader::LoadImage(myth:--Coverart@[::1]:6543-1492_coverart.jpg--47x80.p
ng) Found in cache, RefCount = 3
2012-10-29 18:10:34.742352 I  MythSocket(2019070:51): read  <- 51 69
/var/lib/mythtv/coverart/48752_coverart.jpg[]:[]1351284371[]:[]22...
2012-10-29 18:10:34.742382 I  (0x7f11f4512048)::IncrRef() -> 3
2012-10-29 18:10:34.742388 I  (0x7f11f4512048)::IncrRef() -> 4
2012-10-29 18:10:34.742389 I  MythSocket(2019070:51): write -> 51 62
QUERY_SG_FILEQUERY[]:[]::1[]:[]Coverart[]:[]12819_coverart.jpg
2012-10-29 18:10:34.742390 I  (0x7f11f4512048)::DecrRef() -> 3
2012-10-29 18:10:34.742394 I
ImageLoader::LoadImage(myth:--Coverart@[::1]:6543-48752_coverart.jpg--47x80.
png) Found in cache, RefCount = 3
2012-10-29 18:10:34.742696 I  MythSocket(2019070:51): read  <- 51 69
/var/lib/mythtv/coverart/12819_coverart.jpg[]:[]1334166935[]:[]54...
2012-10-29 18:10:34.742728 I  MythSocket(2019070:51): write -> 51 62
QUERY_SG_FILEQUERY[]:[]::1[]:[]Coverart[]:[]23398_coverart.jpg
2012-10-29 18:10:34.742735 I  (0x7f11f42fc708)::IncrRef() -> 2
2012-10-29 18:10:34.742744 I  (0x7f11f42fc708)::IncrRef() -> 3
2012-10-29 18:10:34.742748 I  (0x7f11f42fc708)::DecrRef() -> 2
2012-10-29 18:10:34.742753 I
ImageLoader::LoadImage(myth:--Coverart@[::1]:6543-12819_coverart.jpg--47x80.
png) Found in cache, RefCount = 2
2012-10-29 18:10:34.743032 I  MythSocket(2019070:51): read  <- 51 69
/var/lib/mythtv/coverart/23398_coverart.jpg[]:[]1334166937[]:[]58...
2012-10-29 18:10:34.743060 I  MythSocket(2019070:51): write -> 51 61
QUERY_SG_FILEQUERY[]:[]::1[]:[]Coverart[]:[]9992_coverart.jpg
2012-10-29 18:10:34.743066 I  (0x7f11d8173c88)::IncrRef() -> 2
2012-10-29 18:10:34.743076 I  (0x7f11d8173c88)::IncrRef() -> 3
2012-10-29 18:10:34.743080 I  (0x7f11d8173c88)::DecrRef() -> 2
2012-10-29 18:10:34.743085 I
ImageLoader::LoadImage(myth:--Coverart@[::1]:6543-23398_coverart.jpg--47x80.
png) Found in cache, RefCount = 2
2012-10-29 18:10:34.743388 I  MythSocket(2019070:51): read  <- 51 68
/var/lib/mythtv/coverart/9992_coverart.jpg[]:[]1334166935[]:[]344861
2012-10-29 18:10:34.743421 I  (0x7f120000c128)::IncrRef() -> 2
2012-10-29 18:10:34.743421 I  MythSocket(2019070:51): write -> 51 125
QUERY_FILE_EXISTS[]:[]Alice im Wunderland/Alice Trailer ...
2012-10-29 18:10:34.743430 I  (0x7f120000c128)::IncrRef() -> 3
2012-10-29 18:10:34.743433 I  (0x7f120000c128)::DecrRef() -> 2
2012-10-29 18:10:34.743436 I
ImageLoader::LoadImage(myth:--Coverart@[::1]:6543-9992_coverart.jpg--47x80.p
ng) Found in cache, RefCount = 2
2012-10-29 18:10:34.744278 I  MythSocket(2019070:51): read  <- 51 1       0
2012-10-29 18:10:34.744320 I  MythSocket(2019070:51): write -> 51 121
QUERY_FILE_EXISTS[]:[]Alice im Wunderland/Alice Trailer ...
2012-10-29 18:10:34.745126 I  MythSocket(2019070:51): read  <- 51 1       0