[mythtv-users] Backend is crashing, usually after commflag has finished.

James Dio psunit at gmail.com
Fri Mar 16 23:31:46 UTC 2007


Hi,

First of all, I wanted to say thanks for any help ahead of time, I love mythtv.

I am using svn trunk and recently setup a slave backend. Everything
had been working fine for a few days, but I woke up one morning and
saw that mythbackend was no longer running on my MBE (master backend,
hope abbreviation is alright) but instead there were about 10-12
mythcommflags running. I had been getting some:

 2007-03-16 19:11:40.844 NVP::OpenFile(): Error, file not found:
/GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/tvbox/1062_20060419173844.mpg

(not actual error, but it was like this) so I killed all of the
commercial flagging processes and started the backend up. I just
recently went through my recordings and tried to find most of the ones
which have entries but do not exist. I believe this is a separate
problem, but worth mentioning IMHO. (side note; is there a way to have
mythtv confirm the existence of recordings and if not let me know so I
can delete those entries? I'm not sure why they do not exist in the
first place)

I hadn't had any new problems with this specially since I got rid of
those entries, but a day or two ago I started having errors like:

[mpeg2video @ 0xb731d610]Warning MVs not available

and I was quickly informed that this is usually the cause of a poor
signal (no apparent changes which would make cable signal worse) so I
just changed around configuration so I now have a better signal
(judged by cable modem plugged into same splitter) and no longer get
these messages while recording. I also removed recordings from the
past few days in case those could also cause problems while being
watched or commercial flagged.

I no longer have these errors (but again, worth mentioning in case it
is part of the cause of MBE crashing).

I have enabled more logging now, and it always seems that the backend
crashes after commercial flagging has finished. I have also added the
--noupnp flag, I knew that could cause some instability (from past
problems I was instructed to try that, plus I don't use it).

.....
2007-03-16 19:00:22.641 Final Commercial Break Map
2007-03-16 19:00:30.885 DB Error (SetMarkupMap inserting):
Query was:
INSERT INTO recordedmarkup (chanid, starttime, mark, type) VALUES (
'1038' , '2007-03-16T18:00:00' , 0 , -3 );
Driver error was [2/1062]:
QMYSQL3: Unable to execute query
Database error was:
Duplicate entry '1038-2007-03-16 18:00:00--3-0' for key 1

2007-03-16 19:00:30.916 write ->  7 33      MESSAGE[]:[]RECORDING_LIST_CHANGE
2007-03-16 19:00:30.918 read  <- 18 33      MESSAGE[]:[]RECORDING_LIST_CHANGE
2007-03-16 19:00:30.920 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:30.922 write -> 18 2       OK
2007-03-16 19:00:30.922 write -> 14 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.925 write -> 19 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.927 write -> 23 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.928 write -> 27 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.936 read  <-  6 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.944 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:30.941 read  <-  6 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.949 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:30.941 read  <-  6 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.954 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:30.956 write ->  7 33      MESSAGE[]:[]RECORDING_LIST_CHANGE
2007-03-16 19:00:30.959 read  <- 26 33      MESSAGE[]:[]RECORDING_LIST_CHANGE
2007-03-16 19:00:30.961 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:30.964 write -> 14 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.964 write -> 26 2       OK
2007-03-16 19:00:30.966 write -> 19 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.969 write -> 23 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.971 write -> 27 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.941 read  <-  7 2       OK
2007-03-16 19:00:30.968 read  <-  7 2       OK
2007-03-16 19:00:30.970 read  <-  6 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.991 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:30.978 read  <-  6 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:32.026 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:30.996 write ->  7 33      MESSAGE[]:[]RECORDING_LIST_CHANGE
2007-03-16 19:00:32.268 read  <- 22 33      MESSAGE[]:[]RECORDING_LIST_CHANGE
2007-03-16 19:00:32.301 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:32.302 write -> 22 2       OK
2007-03-16 19:00:32.302 write -> 14 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:32.305 write -> 23 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:32.307 write -> 27 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:30.972 read  <-  6 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:32.443 Scheduled 454 items in 12.8 = 0.00 match + 12.82 place
2007-03-16 19:00:32.480 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:32.626 scheduler: Scheduled items: Scheduled 454
items in 12.8 = 0.00 match + 12.82 place
2007-03-16 19:00:32.856 MythEvent: SCHEDULE_CHANGE
2007-03-16 19:00:32.958 write -> 14 45
BACKEND_MESSAGE[]:[]SCHEDULE_CHANGE[]:[]empty
2007-03-16 19:00:32.961 write -> 23 45
BACKEND_MESSAGE[]:[]SCHEDULE_CHANGE[]:[]empty
2007-03-16 19:00:32.959 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:32.965 write -> 14 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:32.967 write -> 23 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:32.698 read  <-  6 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:32.973 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:32.979 read  <-  6 45
BACKEND_MESSAGE[]:[]SCHEDULE_CHANGE[]:[]empty
0: start_time: 0.036 duration: 8589.932
1: start_time: 0.026 duration: 0.004
stream: start_time: 0.289 duration: 95443.795 bitrate=0 kb/s
2007-03-16 19:00:32.989 AFD: Opened codec 0x8ce20b0, id(MPEG2VIDEO) type(Video)
2007-03-16 19:00:32.991 AFD: Opened codec 0x859a1c0, id(MP2) type(Audio)
2007-03-16 19:00:32.993 AFD: Audio Track #1 is A/V stream #1 and has 2
channels in the Unknown language(0).
2007-03-16 19:00:32.996 AFD: Selected track 1: Unknown MP2 2ch (A/V Stream #1)
2007-03-16 19:00:32.998 AFD: Initializing audio parms from audio track #1
2007-03-16 19:00:32.999 AFD: Audio format changed
                        from id(NONE)    -1Hz -1ch   0bps    ;
id(NONE)    -1Hz -1ch   0bps
                        to   id( MP2) 48000Hz  2ch  16bps    ; id(
MP2) 48000Hz  2ch  16bps
2007-03-16 19:00:32.989 MythEvent: SCHEDULE_CHANGE
2007-03-16 19:00:33.004 read  <-  6 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-03-16 19:00:33.009 MythEvent: RECORDING_LIST_CHANGE
2007-03-16 19:00:32.328 read  <-  7 2       OK
Input #0, mpeg, from '/store/myth2/1038_20070316180000.mpg':
  Duration: 26:30:43.7, start: 0.289389, bitrate: 0 kb/s
  Stream #0.0[0x1e0], 1/90000: Video: mpeg2video, yuv420p, 480x480,
1001/30000, 5000 kb/s, 29.97 fps(r)
  Stream #0.1[0x1c0], 1/90000: Audio: mp2, 48000 Hz, stereo, 384 kb/s
2007-03-16 19:00:33.251 commflag: Last message repeated 2 times:
Commercial Flagging Starting: 7th Heaven "Work" recorded from channel
1038 at Fri Mar 16 18:00:00 2007
2007-03-16 19:00:33.259 commflag: Commercial Flagging Finished: 7th
Heaven "Work" recorded from channel 1038 at Fri Mar 16 18:00:00 2007
(6 commercial break(s))


I have plenty more output before this, but this previous line is the
last outputted to log when the backend crashes.

I just ran mythcommflag alone, maybe thinking that it would tell me
something when manually running, the only odd thing (while still
finishing successfully) that I see is:

Compiler did not align stack variables. Libavcodec has been miscompiled
and may be very slow or crash. This is not a bug in libavcodec,
but in the compiler. Do not report crashes to FFmpeg developers.

Is this a real problem?

I run gentoo linux, I have run revdep-rebuild, and did not do any
updates prior to these problems. I had this problem with older svn
version (that had been successfully running for a few days) but now
have updated to Revision: 13054.

I really don't know where to go from here, but any help is greatly appreciated.

Thanks,
Jim


More information about the mythtv-users mailing list