Mailing List Archive: MythTV: Dev

FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change

Index | Next | Previous | View Threaded

angela.schmid at wolke7

Apr 8, 2012, 5:08 AM

Post #1 of 11 (424 views)
Permalink

FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change

Hi Daniel,
I pulled and activated the patch. A 0 byte file was created at 05:10,
however the logs show only ASK_RECORDING 30 seconds before. I think not
everything get logged, EIT debug messages overwrite the channel changing
messages. The frontend loosed connection and I had to ctrl-c the gdb'ed
backend. Attached is the dbg.txt and mythbackend.log.

Angela

2012-04-08 05:16:17.836800 E ThemeInfo: The theme
(myth://Temp [at] 127/remotethemes/trunk/Arclight) is missing a
themeinfo.xml file.
2012-04-08 05:16:27.829562 E MythSocket(28e6dc0:32): readStringList:
Error, timed out after 30000 ms.
2012-04-08 05:16:27.829600 C Protocol version check failure.
The response to MYTH_PROTO_VERSION was empty.
This happens when the backend is too busy to
respond,
or has deadlocked in due to bugs or hardware
failure.
2012-04-08 05:16:27.829607 E RemoteFile::openSocket(control socket):
Failed validation to server 127.0.0.1:6543
2012-04-08 06:16:17.834741 E ThemeInfo: The theme
(myth://Temp [at] 127/remotethemes/trunk/Arclight) is missing a
themeinfo.xml file.
2012-04-08 06:16:27.829810 E MythSocket(28a1710:32): readStringList:
Error, timed out after 30000 ms.
2012-04-08 06:16:27.829848 C Protocol version check failure.
The response to MYTH_PROTO_VERSION was empty.
This happens when the backend is too busy to
respond,
or has deadlocked in due to bugs or hardware
failure.
2012-04-08 06:16:27.829855 E RemoteFile::openSocket(control socket):
Failed validation to server 127.0.0.1:6543
2012-04-08 07:16:17.836478 E ThemeInfo: The theme
(myth://Temp [at] 127/remotethemes/trunk/Arclight) is missing a
themeinfo.xml file.
2012-04-08 07:16:27.832667 E MythSocket(2317e20:32): readStringList:
Error, timed out after 30000 ms.
2012-04-08 07:16:27.832703 C Protocol version check failure.
The response to MYTH_PROTO_VERSION was empty.
This happens when the backend is too busy to
respond,
or has deadlocked in due to bugs or hardware
failure.
2012-04-08 07:16:27.832710 E RemoteFile::openSocket(control socket):
Failed validation to server 127.0.0.1:6543

--
Ticket URL: <http://code.mythtv.org/trac/ticket/10541#comment:3>
MythTV <http://code.mythtv.org/trac>
MythTV Media Center

_______________________________________________
mythtv-dev mailing list
mythtv-dev [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-dev

angela.schmid at wolke7

Apr 8, 2012, 8:47 AM

Post #2 of 11 (410 views)
Permalink

Re: FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change [In reply to]

> Hi Daniel,
> I pulled and activated the patch. A 0 byte file was created at 05:10,
> however the logs show only ASK_RECORDING 30 seconds before. I think not
> everything get logged, EIT debug messages overwrite the channel changing
> messages. The frontend loosed connection and I had to ctrl-c the gdb'ed
> backend. Attached is the dbg.txt and mythbackend.log.
>
> Angela
>
> 2012-04-08 05:16:17.836800 E ThemeInfo: The theme
> (myth://Temp [at] 127/remotethemes/trunk/Arclight) is missing a
> themeinfo.xml file.
> 2012-04-08 05:16:27.829562 E MythSocket(28e6dc0:32): readStringList:
> Error, timed out after 30000 ms.
> 2012-04-08 05:16:27.829600 C Protocol version check failure.
> The response to MYTH_PROTO_VERSION was empty.
> This happens when the backend is too busy to
> respond,
> or has deadlocked in due to bugs or hardware
> failure.
> 2012-04-08 05:16:27.829607 E RemoteFile::openSocket(control socket):
> Failed validation to server 127.0.0.1:6543
> 2012-04-08 06:16:17.834741 E ThemeInfo: The theme
> (myth://Temp [at] 127/remotethemes/trunk/Arclight) is missing a
> themeinfo.xml file.
> 2012-04-08 06:16:27.829810 E MythSocket(28a1710:32): readStringList:
> Error, timed out after 30000 ms.
> 2012-04-08 06:16:27.829848 C Protocol version check failure.
> The response to MYTH_PROTO_VERSION was empty.
> This happens when the backend is too busy to
> respond,
> or has deadlocked in due to bugs or hardware
> failure.
> 2012-04-08 06:16:27.829855 E RemoteFile::openSocket(control socket):
> Failed validation to server 127.0.0.1:6543
> 2012-04-08 07:16:17.836478 E ThemeInfo: The theme
> (myth://Temp [at] 127/remotethemes/trunk/Arclight) is missing a
> themeinfo.xml file.
> 2012-04-08 07:16:27.832667 E MythSocket(2317e20:32): readStringList:
> Error, timed out after 30000 ms.
> 2012-04-08 07:16:27.832703 C Protocol version check failure.
> The response to MYTH_PROTO_VERSION was empty.
> This happens when the backend is too busy to
> respond,
> or has deadlocked in due to bugs or hardware
> failure.
> 2012-04-08 07:16:27.832710 E RemoteFile::openSocket(control socket):
> Failed validation to server 127.0.0.1:6543

Mythfrontend hung once again.
Angela

_______________________________________________
mythtv-dev mailing list
mythtv-dev [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-dev

angela.schmid at wolke7

Apr 8, 2012, 9:21 AM

Post #3 of 11 (411 views)
Permalink

Re: FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change [In reply to]

> > Hi Daniel,
> > I pulled and activated the patch. A 0 byte file was created at 05:10,
> > however the logs show only ASK_RECORDING 30 seconds before. I think not
> > everything get logged, EIT debug messages overwrite the channel changing
> > messages. The frontend loosed connection and I had to ctrl-c the gdb'ed
> > backend. Attached is the dbg.txt and mythbackend.log.
> >
> > Angela
> >
> > 2012-04-08 05:16:17.836800 E ThemeInfo: The theme
> > (myth://Temp [at] 127/remotethemes/trunk/Arclight) is missing a
> > themeinfo.xml file.
> > 2012-04-08 05:16:27.829562 E MythSocket(28e6dc0:32): readStringList:
> > Error, timed out after 30000 ms.
> > 2012-04-08 05:16:27.829600 C Protocol version check failure.
> > The response to MYTH_PROTO_VERSION was empty.
> > This happens when the backend is too busy to
> > respond,
> > or has deadlocked in due to bugs or hardware
> > failure.
> > 2012-04-08 05:16:27.829607 E RemoteFile::openSocket(control socket):
> > Failed validation to server 127.0.0.1:6543
> > 2012-04-08 06:16:17.834741 E ThemeInfo: The theme
> > (myth://Temp [at] 127/remotethemes/trunk/Arclight) is missing a
> > themeinfo.xml file.
> > 2012-04-08 06:16:27.829810 E MythSocket(28a1710:32): readStringList:
> > Error, timed out after 30000 ms.
> > 2012-04-08 06:16:27.829848 C Protocol version check failure.
> > The response to MYTH_PROTO_VERSION was empty.
> > This happens when the backend is too busy to
> > respond,
> > or has deadlocked in due to bugs or hardware
> > failure.
> > 2012-04-08 06:16:27.829855 E RemoteFile::openSocket(control socket):
> > Failed validation to server 127.0.0.1:6543
> > 2012-04-08 07:16:17.836478 E ThemeInfo: The theme
> > (myth://Temp [at] 127/remotethemes/trunk/Arclight) is missing a
> > themeinfo.xml file.
> > 2012-04-08 07:16:27.832667 E MythSocket(2317e20:32): readStringList:
> > Error, timed out after 30000 ms.
> > 2012-04-08 07:16:27.832703 C Protocol version check failure.
> > The response to MYTH_PROTO_VERSION was empty.
> > This happens when the backend is too busy to
> > respond,
> > or has deadlocked in due to bugs or hardware
> > failure.
> > 2012-04-08 07:16:27.832710 E RemoteFile::openSocket(control socket):
> > Failed validation to server 127.0.0.1:6543
>
> Mythfrontend hung once again.
> Angela
>
Saw your v2 patch in the mean time. I will inform you.
Angela

_______________________________________________
mythtv-dev mailing list
mythtv-dev [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-dev

angela.schmid at wolke7

Apr 9, 2012, 1:42 PM

Post #4 of 11 (393 views)
Permalink

Re: FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change [In reply to]

> > > Hi Daniel,
> > > I pulled and activated the patch. A 0 byte file was created at
> > > 05:10, however the logs show only ASK_RECORDING 30 seconds
> > > before. I think not everything get logged, EIT debug messages
> > > overwrite the channel changing messages. The frontend loosed
> > > connection and I had to ctrl-c the gdb'ed backend. Attached is the dbg.txt and mythbackend.log.
> >
> Saw your v2 patch in the mean time. I will inform you.
> Angela

Mythbackend didn't hang today. I observed only one time a situation where EIT was updating and a recording started, however it had a
strange starting time (18:41) and I didn't see a recording with this date. Will keep you informed.

I think not everything is logged (I think I have seen many occasions). I use the configuration /etc/rsyslog.d/40-mythtv.conf from
http://www.mythtv.org/wiki/Rsyslog_Configuration
Just wonder if other people observe the same ? Is logging threadsafe ?

Angela

_______________________________________________
mythtv-dev mailing list
mythtv-dev [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-dev

angela.schmid at wolke7

Apr 12, 2012, 1:10 PM

Post #5 of 11 (362 views)
Permalink

Re: FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change [In reply to]

> > > > Hi Daniel,
> > > > I pulled and activated the patch. A 0 byte file was created at
> > > > 05:10, however the logs show only ASK_RECORDING 30 seconds
> > > > before. I think not everything get logged, EIT debug messages
> > > > overwrite the channel changing messages. The frontend loosed
> > > > connection and I had to ctrl-c the gdb'ed backend. Attached is the dbg.txt and mythbackend.log.
> > >
> > Saw your v2 patch in the mean time. I will inform you.
> > Angela
>
> Mythbackend didn't hang today. I observed only one time a situation
> where EIT was updating and a recording started, however it had a
> strange starting time (18:41) and I didn't see a recording with this date. Will keep you informed.
>
> I think not everything is logged (I think I have seen many occasions).
> I use the configuration /etc/rsyslog.d/40-mythtv.conf from
> http://www.mythtv.org/wiki/Rsyslog_Configuration
> Just wonder if other people observe the same ? Is logging threadsafe ?

In the last 4 days I had only one occasion, which was handled by the patch successful. However, the recording started 1.5 minutes
later, as you can see from the log http://code.mythtv.org/trac/ticket/10541 . Why does the recording earliest start, when the DB
writing is finished ?

Angela

_______________________________________________
mythtv-dev mailing list
mythtv-dev [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-dev

gjhurlbu at gmail

Apr 12, 2012, 3:20 PM

Post #6 of 11 (361 views)
Permalink

Re: FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change [In reply to]

On Mon, Apr 9, 2012 at 1:42 PM, Angela Schmid <angela.schmid [at] wolke7> wrote:
> I think not everything is logged (I think I have seen many occasions). I use the configuration /etc/rsyslog.d/40-mythtv.conf from
> http://www.mythtv.org/wiki/Rsyslog_Configuration
> Just wonder if other people observe the same ? Is logging threadsafe ?

Yes, logging is threadsafe. If you are using logging via syslog,
however, the timestamps are when syslog received the message, not when
it was actually emitted by the code. On a non-heavily loaded system,
the times should track reasonably well though.
_______________________________________________
mythtv-dev mailing list
mythtv-dev [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-dev

angela.schmid at wolke7

Apr 15, 2012, 9:52 AM

Post #7 of 11 (349 views)
Permalink

Re: FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change [In reply to]

>> Mythbackend didn't hang today. I observed only one time a situation
>> where EIT was updating and a recording started, however it had a
>> strange starting time (18:41) and I didn't see a recording with this
date. Will keep you informed.
>>
>> I think not everything is logged (I think I have seen many occasions).
>> I use the configuration /etc/rsyslog.d/40-mythtv.conf from
>> http://www.mythtv.org/wiki/Rsyslog_Configuration
>> Just wonder if other people observe the same ? Is logging threadsafe ?
>
>In the last 4 days I had only one occasion, which was handled by the patch
successful. However, the recording started 1.5 minutes
>later, as you can see from the log
http://code.mythtv.org/trac/ticket/10541 . Why does the recording earliest
start, when the DB
>writing is finished ?

Hello

No crashes anymore. However I see mythbackend hanging, which I have seen in
the past also without this patch.
I restarted mythbackend. EIT passive scanning started (17:39:26). A
recording was asked (17:39:39). EIT writing from 17:40:01 till 17:43:16.
During this time mythweb was not responding. Socket errors were protocolied
at 17:43:31. Recording was canceled 17:43:32. Mythweb did not respond. A yet
started mythfrontend had a long time to scan the recordings in watch
recordings. Had to restart mythbackend.

During "EITCache: Wrote 14 modified entries of 252 for channel 1002 to
database" messages, I think mythbackend comes unresponsive, this behaviour
has been seen before, also without this patch.
This time the recording has been canceled. In my previous comment, the
recording started 1.5 minutes later.

Run with " /usr/bin/mythbackend --syslog local7 --user mythtv -v eit,general
--loglevel debug".
Attached mythbackend.zip and gdb1.txt (gdb -p <pid>).
Why does mythbackend hang.

Angela

p.s. Why does MythTV not reuse prepared statements ? For each
insert/update/delete as far as I have seen, the SQL command is prepared on
each call. Why not preparing it once and reuse it. Sure needs some
re-preparing when the connection has to be re-astablished. Writing 2000 EIT
records needs 3 Minutes, which is in my eyes very long. This is on a Sandy
Bridge 2600K.

_______________________________________________
mythtv-dev mailing list
mythtv-dev [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-dev

danielk at cuymedia

Apr 15, 2012, 9:58 AM

Post #8 of 11 (347 views)
Permalink

Re: FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change [In reply to]

On Sun, 2012-04-15 at 18:52 +0200, Angela wrote:
> No crashes anymore. However I see mythbackend hanging, which I have seen in
> the past also without this patch.

The hangs you reported were the reason I didn't try to apply this before
the 0.25 release.

> During "EITCache: Wrote 14 modified entries of 252 for channel 1002 to
> database" messages, I think mythbackend comes unresponsive, this behaviour
> has been seen before, also without this patch.
> This time the recording has been canceled. In my previous comment, the
> recording started 1.5 minutes later.
> p.s. Why does MythTV not reuse prepared statements ? For each
> insert/update/delete as far as I have seen, the SQL command is prepared on
> each call. Why not preparing it once and reuse it. Sure needs some
> re-preparing when the connection has to be re-astablished. Writing 2000 EIT
> records needs 3 Minutes, which is in my eyes very long. This is on a Sandy
> Bridge 2600K.

I think the hangs and your slow database may be related. The non-reuse
of prepared statements is historic. The code was written when Qt didn't
support prepared statements. But even so your database seems to be
running like it's writing to a floppy and not a hard disk. What is the
formatting of the partition containing the database? If it is xfs or
ext4 does adding nobarriers to the mount fix the hanging?

-- Daniel

_______________________________________________
mythtv-dev mailing list
mythtv-dev [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-dev

angela.schmid at wolke7

Apr 15, 2012, 11:21 AM

Post #9 of 11 (358 views)
Permalink

Re: FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change [In reply to]

>On Sun, 2012-04-15 at 18:52 +0200, Angela wrote:
>> No crashes anymore. However I see mythbackend hanging, which I have seen
in
>> the past also without this patch.
>
>The hangs you reported were the reason I didn't try to apply this before
>the 0.25 release.
>
>> During "EITCache: Wrote 14 modified entries of 252 for channel 1002 to
>> database" messages, I think mythbackend comes unresponsive, this
behaviour
>> has been seen before, also without this patch.
>> This time the recording has been canceled. In my previous comment, the
>> recording started 1.5 minutes later.
>> p.s. Why does MythTV not reuse prepared statements ? For each
>> insert/update/delete as far as I have seen, the SQL command is prepared
on
>> each call. Why not preparing it once and reuse it. Sure needs some
>> re-preparing when the connection has to be re-astablished. Writing 2000
EIT
>> records needs 3 Minutes, which is in my eyes very long. This is on a
Sandy
>> Bridge 2600K.
>
> I think the hangs and your slow database may be related. The non-reuse
> of prepared statements is historic. The code was written when Qt didn't
> support prepared statements. But even so your database seems to be
> running like it's writing to a floppy and not a hard disk. What is the
> formatting of the partition containing the database? If it is xfs or
> ext4 does adding nobarriers to the mount fix the hanging?

Dear Daniel,

Had this:
/dev/sda2 on / type ext4 (rw,errors=remount-ro)
UUID=8d6b1917-e239-43f0-a957-a5aa181e0255 / ext4
errors=remount-ro 0 1

Changed to:
UUID=8d6b1917-e239-43f0-a957-a5aa181e0255 / ext4
errors=remount-ro,nobarrier 0 1

Having now:
/dev/sda2 on / type ext4 (rw,errors=remount-ro,nobarrier)

By the way, I installed a new disk this week and reinstalled with 12.04. The
behavior seems to be the same. The new disks seems to be fine, moved music
data from an almost 10 year old PC over Gigabit LAN with 70MB/sec today.
However I had some warnings during a recording:

W TFWWrite ThreadedFileWriter.cpp:499 (DiskLoop)
TFW(/home/store/recordings/1009_20120415133000.mpg:34): write(57904) cnt 11
total 649352 -- took a long time, 1092 ms

This is MAGIC, wrote 2180 EIT messages within one second, 350 EIT messages
also in one second and 4000 EIT messages within 2 seconds.

I always use InnoDB, having nobarrier should be save for MySQL I think, in
case electricity fails. Losing parts of a recording does not matter. Any
other thoughts ?

Keeping an eye on the issue further.
Thanks, Angela

_______________________________________________
mythtv-dev mailing list
mythtv-dev [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-dev

danielk at cuymedia

Apr 15, 2012, 1:34 PM

Post #10 of 11 (347 views)
Permalink

Re: FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change [In reply to]

On Sun, 2012-04-15 at 20:21 +0200, Angela wrote:

> This is MAGIC, wrote 2180 EIT messages within one second, 350 EIT messages
> also in one second and 4000 EIT messages within 2 seconds.
>
> I always use InnoDB, having nobarrier should be save for MySQL I think, in
> case electricity fails. Losing parts of a recording does not matter. Any
> other thoughts ?

You can lose data consistency with nobarrier on power loss, especially
with ext4. As I understand it you will mostly lose data on expanding
files, so database files are fairly safe. However, MythTV should work
with barriers enabled, I just want to see if your lockups go away after
a week running this way. If that is the case I know to look at how we
handle the DB in EIT scanning vs looking for the problem elsewhere.

-- Daniel

_______________________________________________
mythtv-dev mailing list
mythtv-dev [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-dev

angela.schmid at wolke7

Apr 18, 2012, 12:25 PM

Post #11 of 11 (339 views)
Permalink

Re: FW: Ticket #10541: SIGSEGV when EIT updating DB and channel change [In reply to]

>> This is MAGIC, wrote 2180 EIT messages within one second, 350 EIT
>> messages also in one second and 4000 EIT messages within 2 seconds.
>>
>> I always use InnoDB, having nobarrier should be save for MySQL I
>> think, in case electricity fails. Losing parts of a recording does not
>> matter. Any other thoughts ?
>
>You can lose data consistency with nobarrier on power loss, especially with
ext4. As I understand it you will mostly lose data on expanding files, so
database files are fairly safe. However, MythTV should work with barriers
enabled, I >just want to see if your lockups go away after a week running
this way. If that is the case I know to look at how we handle the DB in EIT
scanning vs looking for the problem elsewhere.

Adding nobarrier to mount the ext4 FS where the MySQL DB is located fixed
the delay writing to the DB from up to 2 minutes to less than one second.

I had 8 events where the fix showed it works fine and doesn't crash
mythbackend anymore. Thanks Daniel.

When I had the long DB delays, it was still strange that recordings started
after finishing the EIT DB writing or even got cancelled. This shouldn't be
weighted to high, as I got the DB writing delay fixed.

Hope to see the patch in fixes/0.25.
Angela

_______________________________________________
mythtv-dev mailing list
mythtv-dev [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-dev

Index | Next | Previous | View Threaded

Interested in having your list archived? Contact Gossamer Threads