[mythtv-users] HDHR Prime & 0.00GB recordings

Fri Jan 18 15:58:30 UTC 2013

I'm running 0.26/fixes.

MythTV Version : v0.26.0-80-g8ca4caf
MythTV Branch : fixes/0.26
Network Protocol : 75
Library API : 0.26.20130112-1
QT Version : 4.8.1
Options compiled in:
 linux profile use_hidesyms using_alsa using_oss using_pulse
using_pulseoutput using_backend using_bindings_perl using_bindings_python
using_bindings_php using_crystalhd using_dvb using_firewire using_frontend
using_hdhomerun using_ceton using_hdpvr using_iptv using_ivtv
using_joystick_menu using_libcec using_libcrypto using_libdns_sd
using_libxml2 using_lirc using_mheg using_opengl_video using_qtwebkit
using_qtscript using_qtdbus using_v4l2 using_x11 using_xrandr using_xv
using_bindings_perl using_bindings_python using_bindings_php
using_mythtranscode using_opengl using_vaapi using_vdpau
using_ffmpeg_threads using_live using_mheg using_libass using_libxml2

My HDHR Prime has the official firmware (20120405).  I'm wary of trying the
beta firmware in fear of making things worse and not being able to revert
back to official firmware.

I was originally having problems with pixelated recordings that would
suddenly be missing several minutes of recording.  Consequentely, I added
an upstart job that did a ping to keep the tuner alive:

#Ping of Death,
#workaround for http://code.mythtv.org/trac/ticket/10414
#and http://www.silicondust.com/forum/viewtopic.php?t=13227

description "endlessly ping a HDHR prime"

start on net-device-up IFACE!=lo

script
ID=$(hdhomerun_config discover | awk '{ print $6 }')
ping -i 1 -n $ID > /dev/null
end script

Now i'm noticing that i'm encountering recordings every few recordings that
show up as 0.00 GB.  While it's going on the tuner shows it's in progress,
but no file gets written.  For example here's one from last night:

Jan 17 21:01:00 supermario mythlogserver: mythbackend[1956]: I TVRecEvent
tv_rec.cpp:1043 (HandleStateChange) TVRec(1): Changing from None to
RecordingOnly
Jan 17 21:01:00 supermario mythlogserver: mythbackend[1956]: I TVRecEvent
tv_rec.cpp:3562 (TuningCheckForHWChange) TVRec(1): HW Tuner: 1->1
Jan 17 21:01:00 supermario mythlogserver: mythbackend[1956]: N Scheduler
autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams(): Max required Free
Space: 22.0 GB w/freq: 14 min
Jan 17 21:01:00 supermario mythlogserver: mythbackend[1956]: I Scheduler
scheduler.cpp:2648 (HandleRecordingStatusChange) Tuning recording:
Elementary:"Flight Risk": channel 2611 on cardid 1, sourceid 2
Jan 17 21:01:01 supermario mythlogserver: mythbackend[1956]: E
HDHRStreamHandler dtvsignalmonitor.cpp:321 (HandlePAT) DTVSM(13118BC4-0):
Program #0 not found in PAT!#012Program Association Section#012 PSIP
tableID(0x0) length(13) extension(0x0)#012      version(9) current(1)
section(0) last_section(0)#012      tsid(0) programCount(1)#012  program
number   611 has PID 0x0050
Jan 17 21:01:01 supermario mythlogserver: mythbackend[1956]: E
HDHRStreamHandler dtvsignalmonitor.cpp:326 (HandlePAT) DTVSM(13118BC4-0):
But there is only one program in the PAT, so we'll just use it
Jan 17 21:01:01 supermario mythlogserver: mythbackend[1956]: I CoreContext
scheduler.cpp:655 (UpdateRecStatus) Updating status for Elementary:"Flight
Risk" on cardid 1 (Tuning => Recording)
Jan 17 21:01:01 supermario mythlogserver: mythbackend[1956]: E
HDHRStreamHandler hdhrstreamhandler.cpp:211 (UpdateFilters)
HDHRSH(13118BC4-0): UpdateFilters called in wrong tune mode
Jan 17 21:01:01 supermario mythlogserver: mythbackend[1956]: I TVRecEvent
tv_rec.cpp:4056 (TuningNewRecorder) TVRec(1): rec->GetPathname():
'/var/lib/mythtv/1.5tb/recordings/2611_20130118030100.mpg'
Jan 17 21:01:01 supermario mythlogserver: mythbackend[1956]: E TVRecEvent
recorderbase.cpp:166 (SetStrOption) RecBase(1:13118BC4-0):
SetStrOption(...recordingtype): Option not in profile.
Jan 17 21:02:53 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:07:10 supermario mythlogserver: mythbackend[1956]: N Expire
autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams(): Max required Free
Space: 22.0 GB w/freq: 14 min
Jan 17 21:07:56 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:10:10 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Monitor
Jan 17 21:10:10 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding: supermario as a
client (events: 0)
Jan 17 21:10:10 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Monitor
Jan 17 21:10:10 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding: supermario as a
client (events: 1)
Jan 17 21:11:02 supermario mythlogserver: mythbackend[1956]: I
Metadata_7081 jobqueue.cpp:2156 (DoMetadataLookupThread) JobQueue: Metadata
Lookup Starting for Elementary:"Flight Risk" recorded from channel
2611 at 2013-01-18T03:01:00Z
Jan 17 21:11:06 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Monitor
Jan 17 21:11:07 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding: supermario as a
client (events: 0)
Jan 17 21:11:07 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Monitor
Jan 17 21:11:07 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding: supermario as a
client (events: 1)
Jan 17 21:12:07 supermario mythlogserver: mythbackend[1956]: I
Commflag_7082 jobqueue.cpp:2281 (DoFlagCommercialsThread) JobQueue:
Commercial Detection Starting for Elementary:"Flight Risk" recorded from ch
annel 2611 at 2013-01-18T03:01:00Z
Jan 17 21:12:08 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Playback
Jan 17 21:12:08 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding: supermario as a
client (events: 0)
Jan 17 21:12:08 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Monitor
Jan 17 21:12:08 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding: supermario as a
client (events: 1)
Jan 17 21:12:12 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Monitor
Jan 17 21:12:12 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding: supermario as a
client (events: 0)
Jan 17 21:12:12 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Monitor
Jan 17 21:12:12 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding: supermario as a
client (events: 1)
Jan 17 21:12:13 supermario mythlogserver: mythbackend[1956]: E
Commflag_7082 previewgenerator.cpp:255 (Run) Preview: Encountered problems
running '/usr/bin/mythpreviewgen --size 0x0 --chanid 2611 --starttim
e 20130118030100 --verbose general --loglevel info --syslog local7 --quiet'
(128)
Jan 17 21:13:02 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:16:25 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Playback
Jan 17 21:16:25 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1397 (HandleAnnounce) adding: supermario as a
client (events: 0)
Jan 17 21:16:25 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1510 (HandleAnnounce)
MainServer::HandleAnnounce FileTransfer
Jan 17 21:16:25 supermario mythlogserver: mythbackend[1956]: I
ProcessRequest mainserver.cpp:1512 (HandleAnnounce) adding: supermario as a
remote file transfer
Jan 17 21:16:26 supermario mythlogserver: mythbackend[1956]: W
ProcessRequest mainserver.cpp:5841 (connectionClosed) MainServer: Unknown
socket closing MythSocket(0x9cbd1f0)
Jan 17 21:16:26 supermario mythlogserver: mythbackend[1956]: E
ProcessRequest mythsocket.cpp:344 (writeStringList) MythSocket(9cbd1f0:-1):
writeStringList: Error, socket went unconnected.#012#011#011#011We
wrote 0 of 10 bytes with 1 errors#012#011#011#011starts with: 2       OK
Jan 17 21:18:09 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:21:10 supermario mythlogserver: mythbackend[1956]: N Expire
autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams(): Max required Free
Space: 22.0 GB w/freq: 14 min
Jan 17 21:23:15 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:28:17 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:33:17 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:35:10 supermario mythlogserver: mythbackend[1956]: N Expire
autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams(): Max required Free
Space: 22.0 GB w/freq: 14 min
Jan 17 21:38:20 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:43:25 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:48:30 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:49:10 supermario mythlogserver: mythbackend[1956]: N Expire
autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams(): Max required Free
Space: 22.0 GB w/freq: 14 min
Jan 17 21:53:31 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:58:33 supermario mythlogserver: mythbackend[1956]: I HouseKeeping
housekeeper.cpp:221 (RunHouseKeeping) Running housekeeping thread
Jan 17 21:59:29 supermario mythlogserver: mythbackend[1956]: I TVRecEvent
tv_rec.cpp:1557 (HandlePendingRecordings) TVRec(1): ASK_RECORDING 1 29 0 0
Jan 17 22:00:00 supermario mythlogserver: mythbackend[1956]: I TVRecEvent
tv_rec.cpp:1043 (HandleStateChange) TVRec(1): Changing from RecordingOnly
to None
Jan 17 22:00:00 supermario mythlogserver: mythbackend[1956]: E
HDHRStreamHandler hdhrstreamhandler.cpp:211 (UpdateFilters)
HDHRSH(13118BC4-0): UpdateFilters called in wrong tune mode
Jan 17 22:00:00 supermario mythlogserver: mythbackend[1956]: I TVRecEvent
tv_rec.cpp:830 (FinishedRecording) TVRec(1):
FinishedRecording(2611_2013-01-18T03:01:00Z) damaged recq:<RecordingQuality
overall_score="0" key="2611_2013-01-18T03:01:00Z">#012    <Gap
start="2013-01-18T03:01:01Z" end="2013-01-18T04:00:00Z" duration="3538"
/>#012</RecordingQuality>
Jan 17 22:00:00 supermario mythlogserver: mythbackend[1956]: I CoreContext
scheduler.cpp:655 (UpdateRecStatus) Updating status for Elementary:"Flight
Risk" on cardid 1 (Recording => Recorded)

I'm unsure what to do next to further debug at this point.  Anyone have any
ideas?
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.mythtv.org/pipermail/mythtv-users/attachments/20130118/93d4a245/attachment.html>