[mythtv-users] Slow MySQL query after delete

[Michael Rice]

On Nov 29, 2007 6:38 PM, Michael T. Dean <mtdean at thirdcontact.com> wrote:
> In other words, my system seems--to me--to be proof that a system that
> takes 6-7 seconds to execute the scheduling run does not lock up when a
> recording is deleted.  Perhaps I'm just naive, though, in thinking my
> system acts like a properly configured Myth system.  Maybe I've
> misconfigured my system and gotten unreasonably good performance because
> of it.

Mike,

It's good to know that it is possible to delete without lock up... but
whatever it
takes isn't obvious to me.  I am using slow deletes and do not have my database
on my recordings disks.  I have a newish Core 2 Duo backend and frontend.  I
optimize my database in a cronjob regularly.  I read the list and try to
follow the advise you and others give but I've always had this issue.

Tonight I turned on "all" logging in the frontend and the backend is running
"most" logging right now.  In the front end I deleted a show.. the UI came back
immediately.  I then chose another show and selected "Delete".  The
delete dialog came up then the frontend hung.  After some seconds
it returned and I was able to delete the second show.  Below I've added log
snippets...  Can you see the problem?  I am sure those of us that suffer from
this would be forever in your debt if you could identify what the
misconfiguration
is.


FE 2007-11-29 18:05:44.596 MSqlQuery: UPDATE record SET last_delete = '2007
FE 2007-11-29 18:05:44.596 write -> 24 627     DELETE_RECORDING[]:[]SpongeB
FE 2007-11-29 18:05:44.603 read  <- 24 2       -1

  BE 2007-11-29 18:05:44.589 read  <-  5 627     DELETE_RECORDING[]:[]Spong
  BE 2007-11-29 18:05:44.591 write ->  5 2       -1
  BE 2007-11-29 18:05:44.592 MythEvent: RECORDING_LIST_CHANGE
  BE 2007-11-29 18:05:44.599 write ->  6 51      BACKEND_MESSAGE[]:[]RECORD

FE 2007-11-29 18:05:44.607 MSqlQuery: SELECT icon FROM channel WHERE chanid
FE 2007-11-29 18:05:44.611 MythSocket(b4bc39c0:22): socket is readable
FE 2007-11-29 18:05:44.611 MythSocket(b4bc39c0:22): cb->readyRead()
FE 2007-11-29 18:05:44.611 read  <- 22 51      BACKEND_MESSAGE[]:[]RECORDIN
FE 2007-11-29 18:05:44.611 MythEvent: RECORDING_LIST_CHANGE
FE 2007-11-29 18:05:44.640 MSqlQuery: SELECT icon FROM channel WHERE chanid

FE 2007-11-29 18:05:45.649 MSqlQuery: SELECT recgroup, password FROM recgro
FE 2007-11-29 18:05:45.652 write -> 24 21      QUERY_RECORDINGS Play

  BE 2007-11-29 18:05:45.644 read  <-  5 21      QUERY_RECORDINGS Play
  BE 2007-11-29 18:05:45.928 write ->  5 269233  457[]:[]Eureka[]:[]H.O.U.S

FE 2007-11-29 18:05:45.946 read  <- 24 269230  457[]:[]Eureka[]:[]H.O.U.S.E

  BE 2007-11-29 18:05:47.617 About to unlink/delete file: '/usr1/recordings
  BE 2007-11-29 18:05:47.620 About to delete file: /usr1/recordings/1040_20
  BE 2007-11-29 18:05:48.729 write ->  6 51      BACKEND_MESSAGE[]:[]RECORD

FE 2007-11-29 18:05:49.752 MSqlQuery: SELECT recgroup, password FROM recgro
FE 2007-11-29 18:05:49.754 write -> 24 21      QUERY_RECORDINGS Play

  BE 2007-11-29 18:05:49.747 read  <-  5 21      QUERY_RECORDINGS Play
  BE 2007-11-29 18:05:50.030 write ->  5 269233  457[]:[]Eureka[]:[]H.O.U.S

FE 2007-11-29 18:05:50.048 read  <- 24 269230  457[]:[]Eureka[]:[]H.O.U.S.E
FE 2007-11-29 18:05:50.110 MSqlQuery: SELECT icon FROM channel WHERE chanid
FE 2007-11-29 18:05:50.151 MSqlQuery: SELECT icon FROM channel WHERE chanid

<frontend blocking>

  BE 2007-11-29 18:05:51.780 MythEvent: RESCHEDULE_RECORDINGS 0
  BE 2007-11-29 18:05:51.836 Reschedule requested for id 0.

  BE 2007-11-29 18:05:51.838 Truncating '/usr1/recordings/1040_200711270800
  BE 2007-11-29 18:05:51.838 BuildWorkList...
  BE 2007-11-29 18:05:51.840 AddNewRecords...
  BE 2007-11-29 18:05:51.870  |-- Start DB Query...

<ok back, can delete another>

FE 2007-11-29 18:06:06.691 MSqlQuery: UPDATE record SET last_delete = '2007
FE 2007-11-29 18:06:06.691 write -> 24 621     DELETE_RECORDING[]:[]SpongeB

  BE 2007-11-29 18:06:06.681 MythSocket(ac5bd350:5): socket is readable
  BE 2007-11-29 18:06:06.685 MythSocket(ac5bd350:5): cb->readyRead()
  BE 2007-11-29 18:06:06.685 MythSocket(ac5bd350:5): UpRef: 2
  BE 2007-11-29 18:06:06.686 read  <-  5 621     DELETE_RECORDING[]:[]Spong
  ...
  BE 2007-11-29 18:06:11.397 Scheduled 2127 items in 17.8 = 0.00 match
+ 17.82 place
  BE 2007-11-29 18:06:11.425 scheduler: Scheduled items: Scheduled
2127 items in 17.8 = 0.00 match + 17.82 place