Opened 8 years ago

Closed 8 years ago

#12612 closed Bug Report - General (Fixed)

New installs die after a few days fixes/0.27 (v0.27 (v0.27.5-71-ga62fc0d)

Reported by: singogli@… Owned by: Karl Egly
Priority: minor Milestone: 0.27.7
Component: MythTV - General Version: 0.27.5
Severity: medium Keywords:
Cc: Ticket locked: no

Description (last modified by sphery)

New installs die after a few days ruuning fixes/0.27 (v0.27 (v0.27.5-71-ga62fc0d) with all updates per ticket #12611. System built on January 18th works correctly until January 21st. Symptom is- after scheduling and recording over days suddenly Media Library-Watch Recordings shows no recordings available. Backend log shows backend is continuing to record previously scheduled programs. Only backend error message around that time is:

Jan 21 13:47:00 mythbuntu64-2 mythbackend: mythbackend[2315]: E MythSocketThread(73) mythsocket.cpp:745 (WriteStringListReal) MythSocket(2603380:-1): WriteStringList: Error, called with unconnected socket  

Frontend errors around that time are:

Jan 21 13:45:38 mythbuntu64-2 mythfrontend.real: mythfrontend[2359]: E ProgramInfoLoader remoteutil.cpp:184 (RemoteGetRecordingList) RemoteGetRecordingList() list size appears to be incorrect.

Jan 21 13:45:39 mythbuntu64-2 mythfrontend.real: mythfrontend[2359]: W CoreContext playbackbox.cpp:1800 (UpdateUILists) PlaybackBox: SortedList is Empty

Memory usage seems high:

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
steve     2359  2.9  6.0 5797776 491308 ?      Sl   13:45  12:31 /usr/bin/mythfrontend.real --syslog local7
mythtv    4171 24.2  0.9 1131292 75680 ?       SNl  20:05   9:43 /usr/bin/mythcommflag -j 102 --noprogress --verbose general --loglevel info --quiet --syslog local7
root      1362  0.0  0.8 336112 73416 tty7     Ssl+ 13:43   0:09 /usr/bin/X -core :0 -seat seat0 -auth /var/run/lightdm/root/:0 -nolisten tcp vt7 -novtswitch
mythtv    2315  4.8  0.8 4379796 68420 ?       Ssl  13:44  20:28 /usr/bin/mythbackend --syslog local7 --user mythtv --daemon
mysql     1187  0.2  0.6 1879336 50588 ?       Ssl  13:43   0:51 /usr/sbin/mysqld

Livetv continues to work fine.

A remote frontend running an earlier version connects to this backend and also shows an empty media library.

This symptom has occurred on multiple install attempts on different hardware with various tuners.

Attachments (7)

mythbackend.log (9.5 KB) - added by singogli 8 years ago.
mythfrontend.log (43.8 KB) - added by singogli@… 8 years ago.
mythbackend.log.new (1.5 KB) - added by singogli@… 8 years ago.
mythfrontend.log.new (1.9 KB) - added by singogli@… 8 years ago.
mythfrontend.log.withhostname (21.0 KB) - added by singogli@… 8 years ago.
errors resulting from changing hostname on backend
offending_channel_string (1.8 KB) - added by singogli@… 8 years ago.
snoop.output2 (45.6 KB) - added by Steve Ingoglia <singogli@…> 8 years ago.

Download all attachments as: .zip

Change History (36)

comment:1 Changed 8 years ago by sphery

Description: modified (diff)
Priority: criticalminor
Status: newinfoneeded_new

[Reset ticket defaults and fixed formatting]

Almost definitely one or more null characters in data for one or more channels or in program data for one or more recordings. See http://www.gossamer-threads.com/lists/mythtv/users/562355#562355 and http://www.gossamer-threads.com/lists/mythtv/users/562373#562373 and http://www.gossamer-threads.com/lists/mythtv/users/562405#562405 .

While this is uncommon, to prevent issues due to bad (or just plain nasty) data from broadcasters and listings suppliers, we'd need to scrub any channel data discovered in channel scans or "Fetch channels from listings provider" downloads, as well as data from EIT and data downloaded from listings providers and remove--at minimum--any null bytes.

Please inspect your data in your database and see if you can identify any null bytes. Also, please attach full log files showing the errors you get when entering Watch Recordings. See https://www.mythtv.org/wiki/Posting_Logs

comment:2 Changed 8 years ago by sphery

You can identify null bytes in your varchar columns with queries such as:

SELECT * FROM channel WHERE callsign LIKE '%\0%';

You should probably check at minimum the following tables/columns:

channel table:

  • callsign
  • name
  • icon

program table:

  • title
  • subtitle
  • description
  • category
  • category_type
  • seriesid
  • programid
  • syndicatedepisodenumber

where the most likely location of the bad data is in channel's callsign or name or in program's title, subtitle, or description.

comment:3 Changed 8 years ago by sphery

Seems EIT data is being checked, already. Ref #8707 .

singogli, please also let us know what you are using for program listings (EIT, XMLTV, Schedules Direct).

Changed 8 years ago by singogli

Attachment: mythbackend.log added

Changed 8 years ago by singogli@…

Attachment: mythfrontend.log added

comment:4 Changed 8 years ago by singogli@…

Attached frontend and backend logs for this event. Backend setup has both local and master server ip set to 192.168.10.128 Frontend setup is also set to 192.168.10.128

I am using schedulesdirect for all program information. EIT scan is not enabled in backend sources setup.

searching the channel table as you suggested:

mysql search SELECT * FROM channel WHERE name LIKE '%\0%'; revealed a NULL in columns finetune and iptvid

Browsing database mythconverg with phpmyadmin revealed all NULL in these two columns

None of the program table columns you suggested showed any NULL

Browsing program table with phpmyadmin shows many NULL in originalairdate column but running SELECT * FROM program WHERE originalairdate LIKE '%\0%'; in mysql returns: Empty set, 1 warning (0.02 sec)

What would I replace NULL with if I tried editing the tables directly?

Is there a mysql command to do that?

comment:5 Changed 8 years ago by singogli@…

The NULL entries in the program table seem to be limited to originalairdate column. This is a date column not a varchar cloumn. I have been unsuccessful in finding a mysql search and replace command for this datatype that will work with a NULL character. There are thousands of these entries so editing manually is not an option. Can anyone specify a mysql command that will locate the NULL(s) in this column and replace them with 0000-00-00 to see if this will fix things?

Changed 8 years ago by singogli@…

Attachment: mythbackend.log.new added

Changed 8 years ago by singogli@…

Attachment: mythfrontend.log.new added

comment:6 Changed 8 years ago by singogli@…

All NULL characters in program table were type date. Finally found a command for updating NULL date fields. The commands to modify date type NULL characters: USE mythconverg; UPDATE program SET originalairdate = "0000-00-00" WHERE originalairdate IS NULL;

To modify channel table: UPDATE channel SET iptvid ="" WHERE iptvid IS NULL; This results in the number 0 in the table fields. The finetune NULL(s) were changed to 0 with phpmyadmin as I don't have that many channels. Rebooted and restarted backend and frontend. There are now no null characters in either table.

None of this changed anything

I have attached the logs *end.log.new

The first line of mythfrontend.log now contains "ConnectCommandSocket?) Connection to master server timed out... mythtv-settings does not contain the proper IP address" The IP address was set correctly in both the General backend settings and the General frontend settings and was working fine for the first 24 or 48 hours. Is this another bug?

I don't know why the frontend is complaining it does eventually connect: (ConnectCommandSocket?) MythCoreContext?: Connecting to backend server: 192.168.10.128:6543 (try 1 of 1)

Still the same error RemoteGetRecordingList?() list size appears to be incorrect. and (UpdateUILists) PlaybackBox?: SortedList? is Empty

Bug is still there : Watch Recordings- No recordings available in Media Library. This makes the system unusable.

comment:7 in reply to:  6 Changed 8 years ago by Jonatan Lindblad

Replying to singogli@…:

The first line of mythfrontend.log now contains "ConnectCommandSocket?) Connection to master server timed out... mythtv-settings does not contain the proper IP address" The IP address was set correctly in both the General backend settings and the General frontend settings and was working fine for the first 24 or 48 hours. Is this another bug?

I don't know why the frontend is complaining it does eventually connect: (ConnectCommandSocket?) MythCoreContext?: Connecting to backend server: 192.168.10.128:6543 (try 1 of 1)

That seems to be because your hostname flips from mythbuntu64-2 to localhost and back to mythbuntu64-2. There is a log entry that says that fe80::d63d:7eff:fef0:1fde%eth0 no longer exists which could be related.

Another thing is that some ports are already in use which could mean that you have another mythfrontend instance running, but this should not affect the behavior of Watch Recordings being empty.

comment:8 Changed 8 years ago by sphery

MySQL NULL values in columns (even in VARCHAR columns) are not a problem--and should not be changed (those you've changed in program listings will expire within a few weeks, but you should fix the ones you changed in channel--or reconfigure you channels as described at http://www.gossamer-threads.com/lists/mythtv/users/264034#264034 ). Having a null character in a VARCHAR column--which is very different--is a problem. MySQL uses a special value called NULL to indicate that a column has no value within it, and this is appropriate for some columns in some records in your database. However, a VARCHAR column can hold any characters, including the null character ('\0' or ASCII character 0), which our code doesn't generally handle. This will cause problems. However, this does not seem to be your problem.

I addition to fixing the hostname issue Jonathan mentioned, please, also, see:

https://www.mythtv.org/wiki/Frequently_Asked_Questions#Why_aren.27t_my_new_recordings_showing_up_in_Watch_Recordings.3F

You may well have changed the displayed recording group and have the setting:

Save current group filter when changed
If enabled, remember the last selected filter instead of displaying the default filter whenever you enter the playback screen.

enabled (it is by default). Then, if you go back into Watch Recordings after recordings in that group are gone, you will get an empty list of recordings. If this is the case, you need to change the filter to show all recordings (and may want to disable saving the last-selected filter). Since there are no related errors shown when you get the empty list of recordings, it does not seem to be a MythTV error, which indicates that it is likely showing what it is supposed to show, even if that's not what you're expecting it to show.

comment:9 Changed 8 years ago by singogli@…

I have edited <Host></Host> in : /home/mythtv/config.xml /etc/mythtv/config.xml /home/steve/.mythtv/config.xml to <Host>192.168.10.128</Host>

And rebooted. I am still getting the Jan 25 22:53:21 mythbuntu64-2 mythbackend: mythbackend[2164]: N CoreContext? mythcontext.cpp:504 (LoadDatabaseSettings?) Empty LocalHostName?.

Is there any other place to specify the hostname?

Anyway changing the hostname as above produces a whole new set of frontend error messages. See mythfrontend.log.withhostname

Why would the frontend now complain "No address defined for host: localhost" unless it is also looking somewhere else other than the stated config files?

I have never changed the displayed recording group setting and it is still set to "All Programs"

I am expecting all the recorded programs to not disappear from the Media Library and programs that have been marked for recording to still reflect they are marked for recording when the program guide is revisited. That's the way it worked in mythbuntu 12.04, has that changed?

Changed 8 years ago by singogli@…

errors resulting from changing hostname on backend

comment:10 Changed 8 years ago by singogli@…

Well I finally solved this and am posting the details. The actual problem was hidden null characters in the database. Specifically the name field in the channel table and the service_name field in the channelscan_channel table. The actual mysql commands needed were: UPDATE channel SET name=REPLACE(name,'\0); and UPDATE channelscan_channel SET service_name=REPLACE(service_name'\0',); What obscured the solution were two things. First, the database works properly for a while. Only when a particular channel is selected for recording does the frontend lose contact with the backend. In my case since updates were coming through on an almost daily basis for the first week after the original build I would check the system in the morning and find that the error had occurred overnight. This was coincidental with having scheduled a recording overnight of a program on the problem channel.

Secondly, these null bytes do not appear in the table when examined with PHPMyAdmin. The only way to discover them I could find was to backup the entire database with mysqldump and then search the entire database with gedit for the offending \0 byte. Once the problem is identified this way than the mysql replace commands do the fixes.

Unfortunately the suggestions on how to locate null bytes did not work for me, mysql always reported a problem with the search string example: SELECT * FROM channel WHERE callsign LIKE '%\0%'; And the tools for fixing a corrupt database always indicated the database was O.K. All the null characters that appeared with PHPMyAdmin were in fact irrelevant so I kept looking for a problem elsewhere. Apparently there is no "sanity check" on this raw channel data import. Perhaps in a future update? The channel that caused this is an Albuquerque OTA channel 21.3.

What allowed me to solve this was a closed thread: Recordings suddenly gone?

http://ubuntuforums.org/showthread.p...rtedList+Empty

Scroll down to # 13 from BookofJarom?.

comment:12 in reply to:  10 Changed 8 years ago by Karl Egly

Replying to singogli@…:

The only way to discover them I could find was to backup the entire database with mysqldump and then search the entire database with gedit for the offending \0 byte. Once the problem is identified this way than the mysql replace commands do the fixes.

...

The channel that caused this is an Albuquerque OTA channel 21.3.

Lets see if we can get closer to the root cause.

Was that a NULL character at the end of the string? What was the complete string?

"Albuquerque OTA channel 21.3" sounds like US ATSC?

Is that an import of channels from Schedules Direct, an OTA channel scan with mythtv-setup or some XMLTV import?

I'm wondering if we have to strip trailing NULL characters from strings that come over the air in our string decoding functions.

comment:13 Changed 8 years ago by Karl Egly

I have taken a peek at the "Bit Stream Syntax for the Multiple String Structure" in "A65/2013". That is quite complex. It would help if you could capture the TVCT of the channel with the bad string and post the hexdump and full decode from dvbsnoop.

If anyone wants to take a peek, it starts on page 79 of A65/2013 and combines segments of uncompressed characters and characters compressed with one of two Huffman tables.

Changed 8 years ago by singogli@…

Attachment: offending_channel_string added

comment:14 Changed 8 years ago by singogli@…

Responding to dekarl: Yes the offending byte was the last of the string. I have attached the mysql string as a file: offending_channel_string. Indeed this was a US ATSC channel.

As I recall this problem occurred with the original build using schedulesdirect and another attempt using the OTA data but I don't recall if the OTA attempt was a fresh install or just changing the setup option. I don't know if changing the option would purge the bad byte/character? If I had to guess I would say both th OTA and the schedulesdirect data contain the bad byte.

Wouldn't it be a good idea to validate all 3rd party data streams and strip all unneeded null bytes?

Are there any published specification for this data? Should I notify the station or schedulesdirect?

comment:15 Changed 8 years ago by singogli@…

Responding to dekarl comment13: This is how I generated the attached snoop.output file. I used a different backend system to do this as my main backend is busy but the results should be the same. If I have it wrong let me know:

Created initial channels.conf with: w_scan -fa -A1 -c US -X > ~/.azap/channels.conf ran azap in seperate window: azap -r 'KYNM Albuquerque, N' azap returns: using '/dev/dvb/adapter0/frontend0' and '/dev/dvb/adapter0/demux0' tuning to 515000000 Hz video pid 0x0051, audio pid 0x0054

with azap running: sudo dvbsnoop 0x0051 -pd 9-ph 4 > snoop.output Let me know if you make any sense out of this.

comment:16 Changed 8 years ago by Karl Egly

That sounds good. I think the -pd and -ph can be left away as the default is ok.

Can you peek at PID 0x1FFB instead of 0x0051? That is where the Terrestrial Virtual Channel Table should be.

(btw, it appears as if the attachment did not get attached)

Changed 8 years ago by Steve Ingoglia <singogli@…>

Attachment: snoop.output2 added

comment:17 Changed 8 years ago by Steve Ingoglia <singogli@…>

How can I examine the schedulesdirect data for the problem?

comment:18 in reply to:  17 Changed 8 years ago by Karl Egly

Status: infoneeded_newnew

Replying to Steve Ingoglia <singogli@…>:

How can I examine the schedulesdirect data for the problem?

I do not know, but the last attachment contains the relevant specimen starting at line 83.

00a0:  xx xx xx xx xx xx xx xx  xx xx xx 14 4b 59 4e 4d   ./...eng....KYNM
00b0:  20 41 6c 62 75 71 75 65  72 71 75 65 2c 20 4e 00    Albuquerque, N.

0x14 => the following 20 bytes are the string, and the last of these 20 bytes is \0.

With that sample I can add a local fixup in MythTV. But it is something that the engineers of the station might want to fix.

comment:19 Changed 8 years ago by Karl Egly

Owner: set to Karl Egly
Status: newaccepted

comment:20 in reply to:  17 Changed 8 years ago by Bill Meek <keemllib@…>

comment:21 Changed 8 years ago by Karl Egly

See also #10046 which contains a patch to trim non-null trailing whitespace.

comment:22 Changed 8 years ago by Karl Dietz <dekarl@…>

In 3834c7479fb4f50c71f14f346e882f616eb40fde/mythtv:

add unit test for trailing \0 characters in US channel names

Refs #12612

comment:23 Changed 8 years ago by Karl Dietz <dekarl@…>

comment:24 Changed 8 years ago by Karl Dietz <dekarl@…>

In d847d55f18315175d6f8b46f821e936d459ebd9d/mythtv:

avoid \0 characters in ATSC strings, also simplify them

Refs #10046
Refs #12612

comment:25 Changed 8 years ago by Karl Dietz <dekarl@…>

In fdc94ef2465f0b596bd785dd9d39029c811f1ec6/mythtv:

update unit test for ATSC channel names after fixes

Refs #10046
Refs #12612

comment:26 Changed 8 years ago by Richard Hulme <peper03@…>

In 5df201428950408e736683069a68050c212889fd/mythtv:

Fix broken Blu-ray bookmarks by adding proper support instead of assuming a Blu-ray is a video file.

Currently just the playback position and angle are bookmarked.

This commit also includes a couple of unrelated database ToDos? to keep the number of database updates down.

Refs #12612

comment:27 Changed 8 years ago by Richard Hulme <peper03@…>

In eae4279058be76d7761b3ee53f8650be48b3f7b8/mythtv:

Fix broken Blu-ray bookmarks by adding proper support instead of assuming a Blu-ray is a video file.

Currently just the playback position and angle are bookmarked.

This commit also includes a couple of unrelated database ToDos? to keep the number of database updates down.

Refs #12612
(cherry picked from commit 5df201428950408e736683069a68050c212889fd)

comment:28 Changed 8 years ago by Karl Dietz <dekarl@…>

In aba4858bd6b3f9abe9ba19adf8c833ba37150d61/mythtv:

avoid \0 characters in ATSC strings, also simplify them

Refs #10046
Refs #12612

(cherry picked from commit d847d55f18315175d6f8b46f821e936d459ebd9d)

comment:29 Changed 8 years ago by Karl Egly

Milestone: unknown0.27.7
Resolution: Fixed
Status: acceptedclosed

singogli, I have merged the fix into fixes/0.27. A new setup should not contain \0 in channel names anymore, starting from the next daily build.

Note: See TracTickets for help on using tickets.