Modify

Opened 18 months ago

Last modified 2 weeks ago

#12772 infoneeded_new Bug Report - Crash

Crash in Recorded.getProgram() for recordings without bookmark after upgrade to 0.28

Reported by: Fred Fettinger <fettinge@…> Owned by: rsiddons
Priority: minor Milestone: unknown
Component: Bindings - Python Version: 0.28.0
Severity: medium Keywords:
Cc: Ticket locked: no

Description

My backend is running on a banana pi, I'm using the compiled myth packages from deb-multimedia.org: deb http://www.deb-multimedia.org jessie main non-free deb http://www.deb-multimedia.org jessie-backports main

mythtv-backend and related packages all have the version 0.28-dmo6~bpo8+2

I encountered this crash after upgrading from 0.27 to 0.28 in a script I use which exports shows as a video and then deletes the original program, since Recorded.delete() calls Recorded.getProgram(). But, you can essentially simplify this down to the following, which will fail for any recording where a bookmark has not been set.

db = MythDB()
rec = Recorded((chanid, starttime), db=db)
rec.getProgram()

I get the following error message:

  File "/etc/mythtv/mythvidexport.py", line 71, in __init__
    self.rec.getProgram()
  File "/usr/lib/python2.7/dist-packages/MythTV/dataheap.py", line 377, in getProgram
    return Program.fromRecorded(self)
  File "/usr/lib/python2.7/dist-packages/MythTV/mythproto.py", line 946, in fromRecorded
    return be.getRecording(rec.chanid, rec.starttime)
  File "/usr/lib/python2.7/dist-packages/MythTV/mythproto.py", line 647, in getRecording
    return Program(res[1:], db=self.db)
  File "/usr/lib/python2.7/dist-packages/MythTV/mythproto.py", line 875, in __init__
    DictData.__init__(self, raw)
  File "/usr/lib/python2.7/dist-packages/MythTV/altdict.py", line 147, in __init__
    data = self._process(data)
  File "/usr/lib/python2.7/dist-packages/MythTV/altdict.py", line 164, in _process
    data[i] = self._trans[self._field_type[i]](v)
  File "/usr/lib/python2.7/dist-packages/MythTV/altdict.py", line 103, in <lambda>
    lambda x: datetime.fromtimestamp(x, datetime.UTCTZ())\
  File "/usr/lib/python2.7/dist-packages/MythTV/utility/dt.py", line 304, in fromtimestamp
    obj = super(datetime, cls).fromtimestamp(float(timestamp), tz)
ValueError: timestamp out of range for platform time_t

As of MYTH_PROTO_VERSION 88, bookmarkupdate is the last item in the response to QUERY_RECORDING TIMESLOT. For some reason, this is always '4294967295' (0xffffffff) for any recordings without bookmarks on my setup, despite the fact that the bookmarkupdate column is 0 for these programs in the database.

Is there any logging that I can enable in mythbackend to find the cause? I did a quick check of the libmyth source code but I didn't see anything suspicious.

Attachments (0)

Change History (6)

comment:1 Changed 18 months ago by Richard Fearn <richardfearn@…>

I am also affected by this, since doing a double Ubuntu upgrade to 16.04 a couple of weeks ago.

In my case, I'm using my mythcal script, and getting the list of upcoming recordings fails with the "timestamp out of range" error.

I will try and figure out what the problem might be as and when I have time.

comment:2 Changed 18 months ago by Richard Fearn <richardfearn@…>

I looked into this tonight. The backend is returning data to the Python bindings that looks like this:

0[]:[]1[]:[]Wallander[]:[]A Lesson in Love[]:[]Detective drama. The body of a woman is discovered in the forest. When it transpires that the victim's daughter is missing, Wallander must act quickly.[]:[]0[]:[]0[]:[]0[]:[][]:[]Drama[]:[]1001[]:[]1[]:[]BBC ONE Oxford[]:[]BBC ONE Oxford[]:[][]:[]0[]:[]1464552000[]:[]1464557400[]:[]0[]:[]mythtv[]:[]1[]:[]1[]:[]1[]:[]0[]:[]-1[]:[]1257[]:[]1[]:[]15[]:[]8[]:[]1464552000[]:[]1464557400[]:[]0[]:[]Default[]:[][]:[]fp.bbc.co.uk/nuj0fe[]:[]fp.bbc.co.uk/1ftwy6[]:[][]:[]1464546156[]:[]0[]:[][]:[]Default[]:[]0[]:[]0[]:[]Default[]:[]33[]:[]66[]:[]0[]:[]0[]:[]0[]:[]0[]:[]2[]:[]0[]:[]~[]:[]4294967295

The last value 4294967295 is the bookmarkupdate field. This value makes its way through the Python bindings to the _process function in altdict.py, so I've temporarily patched {{altdict.py}} to handle this value:

--- altdict.py.ORIGINAL	2016-04-13 04:15:30.000000000 +0100
+++ altdict.py	2016-05-29 19:32:01.198800782 +0100
@@ -160,7 +160,10 @@
                 if v == '':
                     data[i] = None
                 else:
-                    data[i] = self._trans[self._field_type[i]](v)
+                    if (self._field_order[i] == "bookmarkupdate") and (v == "4294967295"):
+                        data[i] = None
+                    else:
+                        data[i] = self._trans[self._field_type[i]](v)
         return dict(zip(self._field_order,data))
 
     def _deprocess(self):

comment:3 Changed 18 months ago by Fred Fettinger <fettinge@…>

That's pretty much what I ended up doing as a workaround also. Since I wasn't sure whether this bug was specific to bookmarkupdate or not, I patched the general timestamp handler as shown below.

mythtv/bindings/python/MythTV/altdict.py
@@ -83,41 +83,41 @@ class OrdDict( dict ):
     _trans = [  int,
                 locale.atof,
                 bool,
                 lambda x: x,
-                lambda x: datetime.fromtimestamp(x, datetime.UTCTZ())\
+                lambda x: datetime.fromtimestamp(x if x != '4294967295' else '0', datetime.UTCTZ())\
                                   .astimezone(datetime.localTZ()),
                 lambda x: date(*[int(y) for y in x.split('-')]),
                 lambda x: datetime.fromRfc(x, datetime.UTCTZ())\

comment:4 Changed 6 months ago by rsiddons

  • Status changed from new to infoneeded_new

Is this still an issue with 0.28/fixes ?

Sounds like it could be a duplicate of #12947, (tested with MySql 5.7.18)

comment:5 Changed 6 months ago by rsiddons

  • Owner changed from wagnerrp to rsiddons

comment:6 Changed 2 weeks ago by Richard Fearn <richardfearn@…>

This still seems to be a problem with MythTV 29. I upgraded yesterday to Ubuntu 17.04. altdict.py, which I had manually patched, was reset to the version shipped in the libmyth-python package, and this problem came back.

#12947 is different because that seems to be about storing a row in the database, where 0 is an invalid value for bookmarkupdate:

MythTV.exceptions.MythDBError: MySQL error 1292: Incorrect datetime value: '0' for column 'bookmarkupdate' at row 1

In this case though, data is being read from the database, and the backend seems to be returning the value 4294967295 when the bookmarkupdate value is 0000-00-00 00:00:00.

I guess this is due to something trying to store -1 in an unsigned 32-bit integer.

While diagnosing this I put these two lines in DictData.__init__ in altdict.py:

print self._field_order
print self._field_type
print data

which shows that the last item of data is bookmarkupdate, the type is 4, and the value is u'4294967295'.

In the database, the bookmarkupdate column in the recorded table has this definition:

+-----------------+------------------+------+-----+---------------------+-----------------------------+
| Field           | Type             | Null | Key | Default             | Extra                       |
+-----------------+------------------+------+-----+---------------------+-----------------------------+
| bookmarkupdate  | timestamp        | NO   |     | 0000-00-00 00:00:00 |                             |
+-----------------+------------------+------+-----+---------------------+-----------------------------+

so the value can't be NULL. Most of the rows in there have that default value, 0000-00-00 00:00:00.

I'm not sure how the backend reads data from the database and returns it to the Python bindings, but it looks like somehow 0000-00-00 00:00:00 is being converted to -1, then held as an unsigned integer, and becomes 4294967295 by the time it gets to the Python bindings.

Add Comment

Modify Ticket

Action
as infoneeded_new The owner will remain rsiddons.
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.