Mythbuntu 8.10 Scheduling Woes

This is the second time I've encountered this and I ended up going through a long charade before finding the solution again. The main problem is that my MythTV backend didn't record the episode of Heroes that aired earlier tonight. I figured I'd watch the episode using MythTV's Live TV viewing feature but that didn't work either. I had other work to take care of so I figured I'd get to it later in the night which happens to be 30 minutes ago.

The symptoms of the problem are that checking the schedule of upcoming recordings from the commandline returns nothing.

root@backend0:~# mythbackend --printsched
2009-04-20 23:23:55.207 Using runtime prefix = /usr
2009-04-20 23:23:55.208 Empty LocalHostName.
2009-04-20 23:23:55.208 Using localhost value of backend0
2009-04-20 23:23:55.806 Cannot find default UPnP backend
2009-04-20 23:23:55.811 New DB connection, total: 1
2009-04-20 23:23:55.814 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:23:55.815 Closing DB connection named 'DBManager0'
2009-04-20 23:23:55.815 Deleting UPnP client...
2009-04-20 23:23:56.490 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:23:56.491 New DB connection, total: 2
2009-04-20 23:23:56.491 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:23:56.492 Current Schema Version: 1214
2009-04-20 23:23:56.493 New DB DataDirect connection
2009-04-20 23:23:56.494 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:23:56.496 Connecting to backend server: 192.168.2.12:6543 (try 1 of 5)
2009-04-20 23:23:56.499 Using protocol version 40
Retrieving Schedule from Master backend.
--- print list start ---
Title - Subtitle Ch Station Day Start End S C I T N Pri
--- print list end ---

However, testing the scheduling functionality returns a list of all shows that would have been recorded.

root@backend0:~# mythbackend --testsched | more
2009-04-20 23:25:54.768 Using runtime prefix = /usr
2009-04-20 23:25:54.768 Empty LocalHostName.
2009-04-20 23:25:54.769 Using localhost value of backend0
2009-04-20 23:25:55.185 Cannot find default UPnP backend
2009-04-20 23:25:55.190 New DB connection, total: 1
2009-04-20 23:25:55.194 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:25:55.195 Closing DB connection named 'DBManager0'
2009-04-20 23:25:55.195 Deleting UPnP client...
2009-04-20 23:25:56.247 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:25:56.248 New DB connection, total: 2
2009-04-20 23:25:56.248 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:25:56.249 Current Schema Version: 1214
2009-04-20 23:25:56.250 New DB DataDirect connection
2009-04-20 23:25:56.251 Connected to database 'mythconverg' at host: localhost
Calculating Schedule from database.
Inputs, Card IDs, and Conflict info may be invalid if you have multiple tuners.
2009-04-20 23:25:56.317 Speculative scheduled 45 items in 0.1 = 0.01 match + 0.06 place
--- print list start ---
Title - Subtitle Ch Station Day Start End S C I T N Pri
Sesame Street - "The Cookie To 67.1 MPTHD 21 09:30-10:30 1 5 5 w 5 -2/0
Charlie Rose 67.1 MPTHD 21 12:35-13:32 1 5 5 C 5 0/0
Two and a Half Men - "Best H.O 13.1 PN-2 21 20:30-21:00 1 5 5 C 5 0/0
Fringe - "Bad Dreams" 45.1 FOX45 H 21 21:01-22:00 1 5 5 C 5 0/0
The Mentalist - "Paint It Red" 13.1 PN-2 21 22:00-23:00 1 5 5 C 5 0/0
.
.
.
Dollhouse - "Briar Rose" 45.1 FOX45 H 01 21:01-22:00 1 5 5 C 5 0/0
Boston Legal - "Smile" 2.1 PN-7 02 23:35-00:35 1 5 5 C 5 0/0
Jericho - "Reconstruction" 54.1 WNUV HD 03 18:30-19:30 1 5 5 C 5 0/0
Desperate Housewives - "Bargai 2.1 PN-7 03 21:00-22:01 1 5 5 C 5 0/0
--- print list end ---

This puzzled me to no end. Lots of posts online talk about ensuring your mythbackend IP isn't set to 127.0.0.1 and to redo the entire setup of tuners and lineups for the backend. I checked the former and wasn't interested in the latter. I even ran mysqlrepair on the mythconverg database just in case - I found nothing.

It turns out there's a way to increase logging for specific aspects of the MythTV backend. I modified the /etc/default/mythtv-backend file by uncommenting the EXTRA_ARGS variable and setting it to:

EXTRA_ARGS="--verbose schedule"

I restarted the MythTV backend while tailing /var/log/mythtv/mythbackend.log and found this little nugget:

2009-04-20 23:41:39.464 Using runtime prefix = /usr
2009-04-20 23:41:39.465 Empty LocalHostName.
2009-04-20 23:41:39.465 Using localhost value of backend0
2009-04-20 23:41:39.472 New DB connection, total: 1
2009-04-20 23:41:39.476 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:41:39.477 Closing DB connection named 'DBManager0'
2009-04-20 23:41:39.478 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:41:39.479 New DB connection, total: 2
2009-04-20 23:41:39.480 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:41:39.481 Current Schema Version: 1214
Starting up as the master server.
2009-04-20 23:41:40.494 HDHRChan(10114243/0), Error: device not found
2009-04-20 23:41:41.506 HDHRChan(10114243/1), Error: device not found
ERROR: no valid capture cards are defined in the database.
Perhaps you should read the installation instructions?
2009-04-20 23:41:41.513 New DB connection, total: 3
2009-04-20 23:41:41.514 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:41:42.725 Main::Registering HttpStatus Extension
2009-04-20 23:41:42.725 mythbackend version: 0.21.20080304-1 www.mythtv.org
2009-04-20 23:41:42.727 Enabled verbose msgs: important general schedule
2009-04-20 23:41:42.728 AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
2009-04-20 23:41:51.927 UPnpMedia: BuildMediaMap VIDEO scan starting in :/var/lib/mythtv/videos:
2009-04-20 23:41:54.489 UPnpMedia: BuildMediaMap Done. Found 8257 objects
2009-04-20 23:43:01.513 AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min

It turns out my HDHomerun wasn't being properly recognized. The lights seemed to indicate it was on the network but I power cycled it just in case. A restart of the MythTV backend revealed:

2009-04-20 23:43:18.272 Using runtime prefix = /usr
2009-04-20 23:43:18.273 Empty LocalHostName.
2009-04-20 23:43:18.273 Using localhost value of backend0
2009-04-20 23:43:18.279 New DB connection, total: 1
2009-04-20 23:43:18.283 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:43:18.284 Closing DB connection named 'DBManager0'
2009-04-20 23:43:18.285 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:43:18.286 New DB connection, total: 2
2009-04-20 23:43:18.286 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:43:18.287 Current Schema Version: 1214
Starting up as the master server.
2009-04-20 23:43:18.293 HDHRChan(10114243/0): device found at address 192.168.2.13
2009-04-20 23:43:18.295 New DB connection, total: 3
2009-04-20 23:43:18.295 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:43:18.366 HDHRChan(10114243/1): device found at address 192.168.2.13
2009-04-20 23:43:18.428 New DB scheduler connection
2009-04-20 23:43:18.428 Connected to database 'mythconverg' at host: localhost
2009-04-20 23:43:19.637 Main::Registering HttpStatus Extension
2009-04-20 23:43:19.637 mythbackend version: 0.21.20080304-1 www.mythtv.org
2009-04-20 23:43:19.637 Enabled verbose msgs: important general schedule
2009-04-20 23:43:19.638 AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
2009-04-20 23:43:21.431 Reschedule requested for id -1.
Query 0: /record.search = :NRST AND program.manualid = 0 AND program.title = record.title
2009-04-20 23:43:21.433 |-- Start DB Query 0...
2009-04-20 23:43:21.438 |-- -1 results in 0.004817 sec.
2009-04-20 23:43:21.438 +-- Done.
2009-04-20 23:43:21.440 BuildWorkList...
2009-04-20 23:43:21.440 AddNewRecords...
2009-04-20 23:43:21.451 |-- Start DB Query...
2009-04-20 23:43:21.478 |-- 160 results in 0.02642 sec. Processing...
2009-04-20 23:43:21.500 +-- Cleanup...
2009-04-20 23:43:21.501 AddNotListed...
2009-04-20 23:43:21.502 |-- Start DB Query...
2009-04-20 23:43:21.503 |-- 0 results in 0.000614 sec. Processing...
2009-04-20 23:43:21.503 Sort by time...
2009-04-20 23:43:21.503 PruneOverlaps...
2009-04-20 23:43:21.504 Sort by priority...
2009-04-20 23:43:21.504 BuildListMaps...
2009-04-20 23:43:21.505 SchedNewRecords...
2009-04-20 23:43:21.505 Scheduling:
+Charlie Rose 67.1 MPTHD 21 12:35-13:32 1 5 5 C 5 0/0
+Two and a Half Men - "Best H.O 13.1 PN-2 21 20:30-21:00 1 5 5 C 5 0/0
+Fringe - "Bad Dreams" 45.1 FOX45 H 21 21:01-22:00 1 5 5 C 5 0/0
+The Mentalist - "Paint It Red" 13.1 PN-2 21 22:00-23:00 1 5 5 C 5 0/0
+Charlie Rose 67.1 MPTHD 22 12:35-13:32 1 5 5 C 5 0/0
+Lie to Me - "Undercover" 45.1 FOX45 H 22 20:00-21:00 1 5 5 C 5 0/0
.
.
.
+Dollhouse - "Briar Rose" 45.1 FOX45 H 01 21:01-22:00 1 5 5 C 5 0/0
+Boston Legal - "Smile" 2.1 PN-7 02 23:35-00:35 1 5 5 C 5 0/0
+Jericho - "Reconstruction" 54.1 WNUV HD 03 18:30-19:30 1 5 5 C 5 0/0
+Desperate Housewives - "Bargai 2.1 PN-7 03 21:00-22:01 1 5 5 C 5 0/0
+The Big Comfy Couch - "Gimme G 67.1 MPTHD 27 05:00-05:30 1 5 5 C 5 -1/0
+Sesame Street - "The Cookie To 67.1 MPTHD 21 09:30-10:30 1 5 5 w 5 -2/0
+Sesame Street - "Firefly Show" 67.1 MPTHD 27 09:30-10:30 1 5 5 w 5 -2/0
2009-04-20 23:43:21.549 SchedPreserveLiveTV...
2009-04-20 23:43:21.549 ClearListMaps...
2009-04-20 23:43:21.550 Sort by time...
2009-04-20 23:43:21.550 PruneRedundants...
2009-04-20 23:43:21.551 Sort by time...
2009-04-20 23:43:21.552 ClearWorkList...
2009-04-20 23:43:21.554 Scheduler: Update next_record for 28
2009-04-20 23:43:21.554 Scheduler: Update next_record for 36
--- print list start ---
Title - Subtitle Ch Station Day Start End S C I T N Pri
Sesame Street - "The Cookie To 67.1 MPTHD 21 09:30-10:30 1 5 5 w 5 -2/0
Charlie Rose 67.1 MPTHD 21 12:35-13:32 1 5 5 C 5 0/0
Two and a Half Men - "Best H.O 13.1 PN-2 21 20:30-21:00 1 5 5 C 5 0/0
Fringe - "Bad Dreams" 45.1 FOX45 H 21 21:01-22:00 1 5 5 C 5 0/0
The Mentalist - "Paint It Red" 13.1 PN-2 21 22:00-23:00 1 5 5 C 5 0/0
.
.
.
Dollhouse - "Briar Rose" 45.1 FOX45 H 01 21:01-22:00 1 5 5 C 5 0/0
Boston Legal - "Smile" 2.1 PN-7 02 23:35-00:35 1 5 5 C 5 0/0
Jericho - "Reconstruction" 54.1 WNUV HD 03 18:30-19:30 1 5 5 C 5 0/0
Desperate Housewives - "Bargai 2.1 PN-7 03 21:00-22:01 1 5 5 C 5 0/0
--- print list end ---
2009-04-20 23:43:21.631 Scheduled 45 items in 0.1 = 0.01 match + 0.11 place
2009-04-20 23:43:21.634 Seem to be woken up by USER
2009-04-20 23:43:28.830 UPnpMedia: BuildMediaMap VIDEO scan starting in :/var/lib/mythtv/videos:
2009-04-20 23:43:31.404 UPnpMedia: BuildMediaMap Done. Found 8257 objects
2009-04-20 23:44:38.430 AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min

In other words, sweet, sweet victory :) While the whole teardown/setup of the backend would probably have caught the tuner issue as well I find checking the tuners to be an easier solution with fewer hair pulls required :)

Implementing a Web Downloader in bash

While looking for a pure bash implementation of wget or curl I came across this post at LinuxQuestions.org. I haven't tried it yet but I'm trying to figure out if there's a more system-agnostic way of doing the same thing. Keen readers will notice the script uses the /dev/tcp/hostname/port "file" to make a connection to a remote host. Based on what I know that's a Solaris-specific way of connecting to a remote host. I'm thinking of something using telnet and the like that can download binary files as well. I have a couple of ideas and I'll update once I've either found a solution or given up and switched to perl.

The Digg Bar Bookmarklet

Digg just launched the "Digg Bar" as an interesting product that shortens URLs and allows users to digg or submit the current site right from the site itself. Seeing this, I decided to create a little bookmarklet that'll make this process easier. Bookmark this link as and when you're on a site you want to use the Digg bar on, click on the bookmark and there it shall be. I've only tested this out on Firefox under Linux so your mileage may vary.

Enjoy!

Sprint EVDO Mobile Broadband on Ubuntu

So I just got a Sprint EVDO USB stick to allow connectivity when there's no WiFi around. I did some quick Google searches and it looks like it's supported. Little did I know how well :) I plugged in the device to a USB port and the kernel started loading appropriate modules and gave me the /dev/ttyUSB0 through /dev/ttyUSB3 ports. At this point I thought I'd pick it up at home.

I couldn't resist one last Google search, however, and it was worth it :) While the box for the device (a Sierra Wireless 598U) doesn't mention Linux by name, Sprint provides a full installation guide for Ubuntu (Fedora and others are there too). I was very pleasantly surprised. Everything just works!

Multi-Column Database Indices in Sqlite3 and Ruby on Rails

In my previous post about database indices in Sqlite3 and Ruby on Rails, I'd observed that Sqlite didn't seem to support multi-column indices properly. It turns out that while Sqlite does support them, I was using syntax in my Rails model which had the effect of ensuring that both the columns in my index were checked separately for uniqueness. Assuming you have the category_id and name fields in a table such that the combination of those two fields has to be unique, the correct way to do multi-column indices is as follows:
In your database migration,

add_index :contests, [:category_id, :name], :unique => true

In your data model,

validates_uniqueness_of :name, :scope => :category_id

That last line in the model is key. Syntax similar to the add_index line above won't work when using the validates_uniqueness_of validator.

The Magic SysRq Key - Commandline Edition

So earlier today I was stuck trying to bounce a remote host that had a Software RAID volume. It turns out for some reason (I still suspect a faulty volume in the RAID1 volume) nothing was able to write to the mounted RAID volume. All processes kept getting hung and drove the load up to 25. Responsiveness was still good since this load was actually due to I/O waiting processes that kept getting some CPU time and not CPU-intensive processes trying to share a couple of processors.

In any case, after manually failing the partition that was causing problems with the RAID volume I still wasn't able to bounce the box since the RAID volume won't stop or sync and actually halted the shutdown process. I thought about the magic SysRq but realized I was ssh'ed in and that won't work. For some reason I didn't think of searching for a way too invoke the magic SysRq processes from the commandline. I looked for a way to force a shutdown and found this blog. It worked like a charm!

Intriguingly enough, when the host came back up the RAID volume remounted and both partitions that formed the RAID volume were fine as reported by mdadm. What's more all seemed well with the mounted volume and I was able to read/write to it just fine. I'll be keeping an eye on that for a bit.

A Scientific View on Database Indices

I've been playing with Ruby on Rails by seeing how easy (or difficult) it would be for me to re-write an existing mod_perl2 application within RoR. While the original application uses PostgreSQL as its backend database (numerous reasons but the top few are: timestamptz, multiple columns in a table that can default to now(), support for transactions - even nested ones), I decided to use sqlite3 for the initial prototype of the application before it grew beyond 2-3 models.

It seems that either sqlite3 or RoR 2.0.5 doesn't support multi-column indices on a table. One of those two converts a single two-column index into 2 one-column indices - not quite the behavior I wanted. I'll try to switch to PostgreSQL to see if the behavior re-surfaces.

While I was scouring Google for sqlite3's limitations, however, I came across this interesting article that details the kind of scientific analysis that should be conducted on your data to determine the order of columns in a multi-column index. Very informative.