Opened 12 years ago

Closed 12 years ago

Last modified 12 years ago

#10541 closed Bug Report - Crash (fixed)

SIGSEGV when EIT updating DB and channel change

Reported by: angela.schmid@… Owned by: danielk
Priority: minor Milestone: 0.26
Component: MythTV - DVB Version: Master Head
Severity: low Keywords:
Cc: Ticket locked: no

Description

I have a reproducible problem and tried several 0.25-pre versions since the beginning of march. On a channel change for a recording and a running (or maybe just ending) EIT update to the DB I get a SIGSEGV, almost every second day. Sometimes empty files are created prior the crash of mythbackend.

Reply from Michael: Got a chance to look over the back trace and it's definitely a bug in our code--the EIT scanner is not being shut down properly and is trying to change channel on a null TVRec. It may be related to http://code.mythtv.org/trac/ticket/10016 , but at this point it makes sense to just create a new ticket for it. Please attach your log file and back trace to the ticket (or let me know if it refuses to let you due to the spam filter--which might not be working properly after the move to the new server--and I can upload them for you).

Attachments (9)

gdb.txt (68.7 KB) - added by angela.schmid@… 12 years ago.
gdb.txt
mythbackend.log.zip (81.0 KB) - added by angela.schmid@… 12 years ago.
mythbackend.log
10541-v1.2.patch (1.9 KB) - added by danielk 12 years ago.
gdb_hang.txt (192.6 KB) - added by angela.schmid@… 12 years ago.
gdb.txt
mythbackend.log.2.zip (135.3 KB) - added by angela.schmid@… 12 years ago.
mythbackend.log.zip
10541-v2.patch (2.4 KB) - added by danielk 12 years ago.
mythbackend.log (31.4 KB) - added by angela.schmid@… 12 years ago.
mythbackend.log showing 1.5min delay
mythbackend.zip (53.4 KB) - added by angela.schmid@… 12 years ago.
gdb1.txt (39.6 KB) - added by angela.schmid@… 12 years ago.

Download all attachments as: .zip

Change History (21)

Changed 12 years ago by angela.schmid@…

Attachment: gdb.txt added

gdb.txt

Changed 12 years ago by angela.schmid@…

Attachment: mythbackend.log.zip added

mythbackend.log

comment:1 Changed 12 years ago by beirdo

Type: Bug Report - GeneralBug Report - Crash

Please don't set the milestone, priority or severity.

Changed 12 years ago by danielk

Attachment: 10541-v1.2.patch added

comment:2 Changed 12 years ago by danielk

It looks line EITScanner::StopActiveScan?() doesn't wait for the activeScan to actually stop before setting rec to NULL. The attached patch should fix it, but it isn't tested and I do want to write a nicer patch before applying to master.

comment:3 Changed 12 years ago by angela.schmid@…

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@127.0.0.1/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@127.0.0.1/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@127.0.0.1/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

Changed 12 years ago by angela.schmid@…

Attachment: gdb_hang.txt added

gdb.txt

Changed 12 years ago by angela.schmid@…

Attachment: mythbackend.log.2.zip added

mythbackend.log.zip

Changed 12 years ago by danielk

Attachment: 10541-v2.patch added

comment:4 Changed 12 years ago by danielk

Angela, please try this new patch.

comment:5 Changed 12 years ago by danielk

Milestone: 0.250.26
Priority: majorminor
Severity: highlow
Status: newinfoneeded_new

comment:6 Changed 12 years ago by angela.schmid@…

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. Why does the recording earliest start, when the DB writing is finished ?

Changed 12 years ago by angela.schmid@…

Attachment: mythbackend.log added

mythbackend.log showing 1.5min delay

Changed 12 years ago by angela.schmid@…

Attachment: mythbackend.zip added

Changed 12 years ago by angela.schmid@…

Attachment: gdb1.txt added

comment:7 Changed 12 years ago by angela.schmid@…

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 log 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.

comment:8 Changed 12 years ago by angela.schmid@…

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

comment:9 Changed 12 years ago by Daniel Kristjansson <danielk@…>

Resolution: fixed
Status: infoneeded_newclosed

In a1d9015924480bb8a733452e294fb72ebbfce94a/mythtv:

Fixes #10541. Fix EIT scanning deadlock.

comment:10 Changed 12 years ago by danielk

The commit message should have said this fixes a crash. The deadlock mentioned was introduced in an earlier version of the patch and removed in a later version of the patch.

comment:11 Changed 12 years ago by Daniel Kristjansson <danielk@…>

In 6dce025ee1ac69e5a78c2e270b06aeff852765e7/mythtv:

Fixes #10541. Fix EIT scanning deadlock.

comment:12 Changed 12 years ago by Daniel Kristjansson <danielk@…>

In a9edae22461ff7ef6749abaed21603fc8bf98cb7/mythtv:

Refs #10771. Revert "Fixes #10541. Fix EIT scanning deadlock."

This appears to be _causing_ a deadlock for warpme.

This reverts commit 6dce025ee1ac69e5a78c2e270b06aeff852765e7.

Note: See TracTickets for help on using tickets.