Modify
Warning Please read the Ticket HowTo before creating or commenting on a ticket. Failure to do so may cause your ticket to be rejected or result in a slower response.

Opened 2 years ago

Closed 2 years ago

Last modified 23 months 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@… 2 years ago.
gdb.txt
mythbackend.log.zip (81.0 KB) - added by angela.schmid@… 2 years ago.
mythbackend.log
10541-v1.2.patch (1.9 KB) - added by danielk 2 years ago.
gdb_hang.txt (192.6 KB) - added by angela.schmid@… 2 years ago.
gdb.txt
mythbackend.log.2.zip (135.3 KB) - added by angela.schmid@… 2 years ago.
mythbackend.log.zip
10541-v2.patch (2.4 KB) - added by danielk 2 years ago.
mythbackend.log (31.4 KB) - added by angela.schmid@… 2 years ago.
mythbackend.log showing 1.5min delay
mythbackend.zip (53.4 KB) - added by angela.schmid@… 2 years ago.
gdb1.txt (39.6 KB) - added by angela.schmid@… 2 years ago.

Download all attachments as: .zip

Change History (21)

Changed 2 years ago by angela.schmid@…

gdb.txt

Changed 2 years ago by angela.schmid@…

mythbackend.log

comment:1 Changed 2 years ago by beirdo

  • Type changed from Bug Report - General to Bug Report - Crash

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

Changed 2 years ago by danielk

comment:2 Changed 2 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 2 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 2 years ago by angela.schmid@…

gdb.txt

Changed 2 years ago by angela.schmid@…

mythbackend.log.zip

Changed 2 years ago by danielk

comment:4 Changed 2 years ago by danielk

Angela, please try this new patch.

comment:5 Changed 2 years ago by danielk

  • Milestone changed from 0.25 to 0.26
  • Priority changed from major to minor
  • Severity changed from high to low
  • Status changed from new to infoneeded_new

comment:6 Changed 2 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 2 years ago by angela.schmid@…

mythbackend.log showing 1.5min delay

Changed 2 years ago by angela.schmid@…

Changed 2 years ago by angela.schmid@…

comment:7 Changed 2 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 2 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 2 years ago by Daniel Kristjansson <danielk@…>

  • Resolution set to fixed
  • Status changed from infoneeded_new to closed

In a1d9015924480bb8a733452e294fb72ebbfce94a/mythtv:

Fixes #10541. Fix EIT scanning deadlock.

comment:10 Changed 2 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 23 months ago by Daniel Kristjansson <danielk@…>

In 6dce025ee1ac69e5a78c2e270b06aeff852765e7/mythtv:

Fixes #10541. Fix EIT scanning deadlock.

comment:12 Changed 23 months 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.

Add Comment

Modify Ticket

Action
as closed .
The resolution will be deleted. Next status will be 'new'.
Author


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

 
Note: See TracTickets for help on using tickets.