Opened 18 years ago

Closed 18 years ago

#1147 closed defect (fixed)

preview: permissions problem -> coredump

Reported by: Cougar <cougar@…> Owned by: danielk
Priority: minor Milestone: 0.20
Component: mythtv Version: head
Severity: medium Keywords: playback coredump
Cc: Ticket locked: no

Description

Mostly I got core dump when leaving playback. Now I updated to [8736] and hoped that #1047 fixed this problem but right now I got core dump again. This time when leaving from delete recordings menu but looks like this is the same problem.

Here is log output:

2006-01-29 22:54:16.157 Using runtime prefix = /usr
2006-01-29 22:54:16.651 New DB connection, total: 1
2006-01-29 22:54:16.833 Total desktop dim: 1024x768, with 1 screen[s].
2006-01-29 22:54:16.854 Using screen 0, 1024x768 at 0,0
2006-01-29 22:54:16.913 Current Schema Version: 1122
2006-01-29 22:54:16.913 mythfrontend version: 0.19.20060121-2 www.mythtv.org
2006-01-29 22:54:16.913 Enabled verbose msgs:  important general
2006-01-29 22:54:18.394 lang0: est
2006-01-29 22:54:18.394 lang: est
2006-01-29 22:54:18.418 lang1: eng
2006-01-29 22:54:18.418 lang: eng
2006-01-29 22:54:18.942 Total desktop dim: 1024x768, with 1 screen[s].
2006-01-29 22:54:18.950 Using screen 0, 1024x768 at 0,0
2006-01-29 22:54:18.954 Switching to square mode (nuvola)
2006-01-29 22:54:20.241 Registering Internal as a media playback plugin.
2006-01-29 22:54:36.362 Connecting to backend server: x.x.x.x:6543 (try 1 of 5)
2006-01-29 22:54:36.384 Using protocol version 26
2006-01-29 22:56:06.428 Default
2006-01-29 22:56:13.665 New DB connection, total: 2
0: start_time: 0.029 duration: 122.324
1: start_time: 0.027 duration: 122.293
stream: start_time: 0.296 duration: 1359.188 bitrate=4961 kb/s
2006-01-29 22:56:14.949 AFD: Opened codec 0x834d3d0, id(MPEG2VIDEO) type(Video)
2006-01-29 22:56:15.018 AFD: Opened codec 0x8db3cd0, id(MP2) type(Audio)
[mpeg2video @ 0x40bdb9a4]invalid mb type in I Frame at 1 25
[mpeg2video @ 0x40bdb9a4]invalid mb type in I Frame at 0 26
[mpeg2video @ 0x40bdb9a4]invalid mb type in I Frame at 0 27
[mpeg2video @ 0x40bdb9a4]invalid mb type in I Frame at 0 28
[mpeg2video @ 0x40bdb9a4]skipped MB in I frame at 1 29
[mpeg @ 0x40904360]Parser not found for Codec Id: 94210 !
0: start_time: 0.036 duration: 242.687
1: start_time: 1856.893 duration: 242.688
2: start_time: 0.029 duration: 242.691
stream: start_time: 0.321 duration: 23328.356 bitrate=618 kb/s
2006-01-29 22:56:20.851 AFD: Opened codec 0x8f856c0, id(MPEG2VIDEO) type(Video)
2006-01-29 22:56:20.851 AFD: Opened codec 0x8e6b460, id(MP2) type(Audio)
[mpeg @ 0x40904360]Parser not found for Codec Id: 94210 !
0: start_time: 0.036 duration: 89.082
1: start_time: 1393.823 duration: 89.142
2: start_time: 0.029 duration: 89.091
stream: start_time: 0.321 duration: 16477.070 bitrate=321 kb/s
2006-01-29 22:56:35.172 AFD: Opened codec 0x834d3d0, id(MPEG2VIDEO) type(Video)
2006-01-29 22:56:35.172 AFD: Opened codec 0x8f856c0, id(MP2) type(Audio)
Segmentation fault (core dumped)

and here is gdb backtrace:

#0  0x41525dec in QMutex::lock () from /usr/lib/libqt-mt.so.3
(gdb) bt 
#0  0x41525dec in QMutex::lock () from /usr/lib/libqt-mt.so.3
#1  0x406677ad in PreviewGenerator::disconnectSafe (this=0x43303418)
    at qmutex.h:96
#2  0x08084bfe in ~PlaybackBox (this=0xbfd1965c) at playbackbox.cpp:320
#3  0x080624ea in startDelete () at main.cpp:204
#4  0x0806c6e5 in TVMenuCallback (data=0x81d68a0, selection=@0x1c)
    at main.cpp:338
#5  0x40d5f09c in ThemedMenuPrivate::handleAction (this=0x8293a68, 
    action=@0x828d170) at themedmenu.cpp:2508
#6  0x40d5ff20 in ThemedMenuPrivate::keyPressHandler (this=0x8293a68, 
    e=0xbfd1a3e0) at themedmenu.cpp:2336
#7  0x40d601ab in ThemedMenu::keyPressEvent (this=0x821c938, e=0xbfd1a3e0)
    at themedmenu.cpp:2714
#8  0x412be3f9 in QWidget::event () from /usr/lib/libqt-mt.so.3
#9  0x41224d41 in QApplication::internalNotify () from /usr/lib/libqt-mt.so.3
#10 0x41225bbf in QApplication::notify () from /usr/lib/libqt-mt.so.3
#11 0x411b90dc in QETWidget::translateKeyEvent () from /usr/lib/libqt-mt.so.3
#12 0x411bea05 in QApplication::x11ProcessEvent () from /usr/lib/libqt-mt.so.3
#13 0x411d2bea in QEventLoop::processEvents () from /usr/lib/libqt-mt.so.3
#14 0x4123bc53 in QEventLoop::enterLoop () from /usr/lib/libqt-mt.so.3
#15 0x412246bf in QApplication::enter_loop () from /usr/lib/libqt-mt.so.3
#16 0x40dd367d in MythDialog::exec (this=0x821c938) at mythdialogs.cpp:1047
#17 0x0806401d in RunMenu (themedir=@0xbfd1ab18) at main.cpp:498
---Type <return> to continue, or q <return> to quit---
#18 0x0806a81a in main (argc=1, argv=0xbfd1abc4) at main.cpp:1062

Attachments (5)

gdb.txt (17.8 KB) - added by Cougar <cougar@…> 18 years ago.
1147.patch (8.0 KB) - added by danielk 18 years ago.
possible fix
gdb.2.txt (38.2 KB) - added by Cougar <cougar@…> 18 years ago.
gdb log as wiki suggests
gdb2.txt (2.0 KB) - added by Cougar <cougar@…> 18 years ago.
gdb log with "thread apply all bt"
myth.log (16.5 KB) - added by Cougar <cougar@…> 18 years ago.
-v playback

Download all attachments as: .zip

Change History (26)

comment:1 Changed 18 years ago by anonymous

Owner: changed from Isaac Richards to danielk

comment:2 Changed 18 years ago by Cougar <cougar@…>

OK, the same problem when doublepressing ESC when leaving from playback to playback menu and trying go back to main menu

#0  0x41525dec in QMutex::lock () from /usr/lib/libqt-mt.so.3
#1  0x406677ad in PreviewGenerator::disconnectSafe (this=0x8298268)
    at qmutex.h:96
#2  0x08084bfe in ~PlaybackBox (this=0xbfa75afc) at playbackbox.cpp:320
#3  0x08062457 in startPlayback () at main.cpp:194
#4  0x0806c69a in TVMenuCallback (data=0x81d68a0, selection=@0x310020)
    at main.cpp:334
#5  0x40d5f09c in ThemedMenuPrivate::handleAction (this=0x823e6b0, 
    action=@0x822a658) at themedmenu.cpp:2508
#6  0x40d5ff20 in ThemedMenuPrivate::keyPressHandler (this=0x823e6b0, 
    e=0xbfa76880) at themedmenu.cpp:2336
#7  0x40d601ab in ThemedMenu::keyPressEvent (this=0x82a0a50, e=0xbfa76880)
    at themedmenu.cpp:2714
#8  0x412be3f9 in QWidget::event () from /usr/lib/libqt-mt.so.3
#9  0x41224d41 in QApplication::internalNotify () from /usr/lib/libqt-mt.so.3
#10 0x41225bbf in QApplication::notify () from /usr/lib/libqt-mt.so.3
#11 0x411b90dc in QETWidget::translateKeyEvent () from /usr/lib/libqt-mt.so.3
#12 0x411bea05 in QApplication::x11ProcessEvent () from /usr/lib/libqt-mt.so.3
#13 0x411d2bea in QEventLoop::processEvents () from /usr/lib/libqt-mt.so.3
#14 0x4123bc53 in QEventLoop::enterLoop () from /usr/lib/libqt-mt.so.3
#15 0x412246bf in QApplication::enter_loop () from /usr/lib/libqt-mt.so.3
#16 0x40dd367d in MythDialog::exec (this=0x82a0a50) at mythdialogs.cpp:1047
#17 0x0806401d in RunMenu (themedir=@0xbfa76fb8) at main.cpp:498
---Type <return> to continue, or q <return> to quit---
#18 0x0806a81a in main (argc=1, argv=0xbfa77064) at main.cpp:1062

I don't use priview video but image.

Here is what happened in backend during this time

2006-01-29 23:06:32.237 MainServer::HandleAnnounce Playback
2006-01-29 23:06:32.237 adding: t42 as a client (events: 0)
2006-01-29 23:06:32.253 MainServer::HandleAnnounce FileTransfer
2006-01-29 23:06:32.253 adding: t42 as a remote file transfer
2006-01-29 23:06:32.253 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  6 retries remaining.
2006-01-29 23:06:32.757 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  5 retries remaining.
2006-01-29 23:06:33.261 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  4 retries remaining.
2006-01-29 23:06:33.765 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  3 retries remaining.
2006-01-29 23:06:34.269 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  2 retries remaining.
2006-01-29 23:06:34.773 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  1 retries remaining.
2006-01-29 23:06:35.277 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  0 retries remaining.
2006-01-29 23:06:35.793 RingBuf(/media/mythstorage/1001_20060129224001.mpg.png) Error: Invalid file descriptor in 'safe_read()'

I just found why this error happened. This is how backend server sees these files:

-rw-r--r--  1 cougar users 1213655968 Jan 29 23:10 /media/mythstorage/1001_20060129224001.mpg
-rw-------  1   1000 users      26417 Jan 29 23:06 /media/mythstorage/1001_20060129224001.mpg.png

but as this storage is mounted over NFS to frontend, in frontend there are different UID and these files look:

-rw-r--r--  1    500 users 1289366512 Jan 29 23:12 /media/mythstorage/1001_20060129224001.mpg
-rw-------  1 cougar users      26417 Jan 29 23:06 /media/mythstorage/1001_20060129224001.mpg.png

Looks like frontend created this preview image but with umask that is not readable for backend server. Maybe this is the reason of core dump?

comment:3 Changed 18 years ago by danielk

Priority: majorminor
Summary: core dump when moving back in menuscore dump with

Cougar, I don't believe your broken UID setup and broken umask had anything to do with the crash. But can you fix those problems just to see if that makes any difference. (If you don't know how and google doesn't provide the info you need, e-mail me at the cuymedia account.)

comment:4 Changed 18 years ago by danielk

Resolution: duplicate
Status: newclosed
Summary: core dump withcore dump when moving back in menus

I didn't mean to change the title earlier, so I've changed it back.

Cougar, it looks like this was fixed in the last few days. Can you make absolutely sure that you have the latest SVN installed on all your frontends and backends, and that there is only one set of mythtv libraries installed (i.e. not one set in /usr/lib and another in /usr/local/lib and another in /opt/mythtv/lib, etc.)

This command will tell you what you are linking to:

ldd /usr/local/bin/mythfrontend

I'm marking this as a duplicate of #1078, if you can repeat this after making sure the latest SVN is installed on all your machines, reopen #1078 with logs made with the latest SVN.

comment:5 Changed 18 years ago by Cougar <cougar@…>

Ok, I'll make a new on when I'm at home. 100% sure that it was [8736] ruuning at that time. At the same time I couldn't reproduce this behaviour after I made all files readable for everybody. I'll try to reproduce this crash with and without read permissions. Right now looks like it has something to do with read permission.

comment:6 Changed 18 years ago by Cougar <cougar@…>

Resolution: duplicate
Status: closedreopened

Checked now with [8763]. I opened recordings menu, selected recording, played it, returned to menu and trying to leav this menu. Here are results:

  • storage not mounted and permissions ok for backend: OK
  • storage not mounted and no permissions for backend: OK (but no preview image)
  • storage mounted and permissions OK (frontend R/W, backend R/O): OK
  • storage mounted and no permissions for backend (frontend R/W, backend -): core dump

Maybe this helps more.

comment:7 Changed 18 years ago by Cougar <cougar@…>

Last post went out too quickly..

Checked now with [8785]. Here is hot this happens:

1. go to media library
2. go to recordings
3. select recording
3a. wait for server timeout when thumbnail reading problem)
4. press ESC

Then it goes back to media library menu and crashes after that.

Here are results of different tests:

- storage not mounted and permissions ok for backend: OK
- storage not mounted and no permissions for backend: OK (but no preview image)
- storage mounted and permissions OK (frontend R/W, backend R/O): OK
- storage mounted and no permissions for backend (frontend R/W, backend -): core dump

Also, I don't see any good reason why to try to open file 6 times when there is permission problem. It just hangs a frontend for a long period.

2006-01-30 13:48:04.782 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  6 retries remaining.
2006-01-30 13:48:05.285 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  5 retries remaining.
2006-01-30 13:48:05.789 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  4 retries remaining.
2006-01-30 13:48:06.293 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  3 retries remaining.
2006-01-30 13:48:06.797 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  2 retries remaining.
2006-01-30 13:48:07.301 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  1 retries remaining.
2006-01-30 13:48:07.805 Could not open /media/mythstorage/1001_20060129224001.mpg.png.  0 retries remaining.
2006-01-30 13:48:08.321 RingBuf(/media/mythstorage/1001_20060129224001.mpg.png) Error: Invalid file descriptor in 'safe_read()'

comment:8 Changed 18 years ago by danielk

Milestone: 0.190.20
Summary: core dump when moving back in menuspermissions problem -> coredump

It looks like it may in fact be a permissions problem.

The multiple retries are because we need to retry when the file is something like a recording that is just starting and we are trying to read it. We never check for a permission problems, since normally a permissions problem like this would make the program completely unusable.

But even so, MythTV shouldn't crash on this.

comment:9 Changed 18 years ago by anonymous

Milestone: 0.200.19

Even then I can't agree with your when you move milestone from 0.19 to 0.20 and let this problem open in 0.19. Segmentation fault type crash is a coding problem and should be always fixed ASAP IMHO. This kind of coding style is very dangerous, specially when you write code that works in network (even if the network is somehow closed).

comment:10 Changed 18 years ago by danielk

Milestone: 0.190.20

I am working on fixing this right now. But this is a serious configuration problem causing a segfault, it does not need to be fixed before 0.19. You could also cause a segfault by redirecting /dev/random into your recordings.

comment:11 Changed 18 years ago by danielk

(In [8789]) References #1147.

  • Checks for invalid file permissions in the RingBuffer? so we can avoid trying to open a file we will never be able to open.
  • Checks if the RingBuffer? succeeded in opening the file before starting an NVP.

MythTV should now tell you if it doesn't have permission to read the recordings or the previews so you would at least know you had a configuration problem if you looked at the logs.

The latter missing check may have caused the segfault, but I wasn't able to reproduce it; the posted segfault is for an earlier revision, and that particular segfault should aleady be fixed in SVN.

Cougar, can you confirm this fixes the problem for you?

comment:12 Changed 18 years ago by Cougar <cougar@…>

In [8789] server logs now permission problem and it doesn't take this many second in browse mode. This behavior looks much better now.

2006-01-30 20:54:54.619 MainServer::HandleAnnounce Playback
2006-01-30 20:54:54.619 adding: t42 as a client (events: 0)
2006-01-30 20:54:54.635 MainServer::HandleAnnounce FileTransfer
2006-01-30 20:54:54.635 adding: t42 as a remote file transfer
2006-01-30 20:54:54.635 RingBuf(/media/mythstorage/1001_20060129224001.mpg.png) Error: File exists but is not readable by MythTV!
2006-01-30 20:54:54.647 RingBuf(/media/mythstorage/1001_20060129224001.mpg.png) Error: Invalid file descriptor in 'safe_read()'

Frontent still crashes with core dump.

#0  0x4152cdec in QMutex::lock () from /usr/lib/libqt-mt.so.3
#1  0x4066cbcd in PreviewGenerator::disconnectSafe (this=0x432249e0)
    at qmutex.h:96
#2  0x08084e0e in ~PlaybackBox (this=0xbff92758) at playbackbox.cpp:315
#3  0x080623d7 in startPlayback () at main.cpp:194
#4  0x0806c61a in TVMenuCallback (data=0x81e4670, selection=@0x300030)
    at main.cpp:334

Also with new recordings, frontend creates preview images itself but don't use them. Instead backend tries to serve file but can't read as expected. Question is why backend doesn't let frontend to use local file like this is done with recordings. In case backend should serve all content I don't understand why does frontend create preview image instead of backend.

comment:13 Changed 18 years ago by danielk

Please use "Attach File" to attach a full backtrace as described in the backtrace link in the TicketHowTo.

comment:14 Changed 18 years ago by Cougar <cougar@…>

First time it didn't crash. Then I came back to recordings menu and it it succeeded.. gdb.txt attached. In backend yesterday's [8789] was running, for frontend I just built [8797] with debug options. This doesn't happen always. Timing is important. Here is when and what I did:

[New Thread 1101502496 (LWP 15252)]
[New Thread 1107983280 (LWP 15257)]
 ... here I'm in main menu going to recordings ...
[New Thread 1125178288 (LWP 15258)]
 ... now I'm in  recordings, left this without crash and went back to this screen ...
[New Thread 1139694512 (LWP 15262)]
 ... I waited a little bit ...
[Thread 1125178288 (LWP 15258) exited]
[Thread 1139694512 (LWP 15262) exited]
 ... after both these threads finished (preview threads I think), I left menu and frontend crashed ...

So, the important thing is that this happens only if thread finished before leaving recordings menu. Also this doesn't happen when I leave menu before thread finishied and come back later. Everything is OK as long as thread doesn't finish in recordings screen. When this happens everything works only as long as I don't leave this screen.

Changed 18 years ago by Cougar <cougar@…>

Attachment: gdb.txt added

Changed 18 years ago by danielk

Attachment: 1147.patch added

possible fix

comment:15 Changed 18 years ago by danielk

(The frontend doesn't try to get the preview image locally because we didn't bother to implement that optimization for such a small file. The optimization is not intended to get around broken permissions but rather avoid streaming large video files over the network when they are available locally.)

That the threads need to finish for the crash is interesting. The PreviewGenerator? should notify the playback box before the class is deleted; if somehow that notification failed it could cause this problem.

Please try this again with '-v playback' with the latest svn. Attach the full output of the gdb session including a "thread apply all bt" after the segfault. The verbosity should let the Preview Generator tell us when it shuts down properly, while the GDB thread notifications should tell us when they actually shut down.

comment:16 Changed 18 years ago by Cougar <cougar@…>

I already afraid that you fixed the problem but it just took more time before 3rd thread existed this time. I used [8809] now. I'll attach here gdb.txt (done using wiki instruction ie "thread apply all bt full"), myth.log and I also created shorter backtrace with "thread apply all bt" as you suggested here.

Changed 18 years ago by Cougar <cougar@…>

Attachment: gdb.2.txt added

gdb log as wiki suggests

Changed 18 years ago by Cougar <cougar@…>

Attachment: gdb2.txt added

gdb log with "thread apply all bt"

Changed 18 years ago by Cougar <cougar@…>

Attachment: myth.log added

-v playback

comment:17 Changed 18 years ago by danielk

(In [8813]) Fixes #1173. References #1147.

This fixes #1173: isConnected should default to false, not true...

This also disables threading for the preview generator in the PlaybackBox?, which prevents the segfault in #1147. If someone wants the threading, just uncomment the USE_PRED_GEN_THREAD define in playbackbox.cpp.

comment:18 Changed 18 years ago by Cougar <cougar@…>

Default build of [8823] (without USE_PRED_GEN_THREAD) don't crash any more. Should I test USE_PRED_GEN_THREAD also or is separate preview thread going to be a history?

comment:19 Changed 18 years ago by anonymous

It won't be in 0.19, so no need to test now. I'll give another go at fixing it after the release, then you can test that.

comment:20 Changed 18 years ago by danielk

Summary: permissions problem -> coredumppreview: permissions problem -> coredump

comment:21 Changed 18 years ago by danielk

Resolution: fixed
Status: reopenedclosed

(In [9691]) Closes #1147. Adds limit to the number of times we try to generate the preview image.

The core problem in the ticket, segfault when permissions are broken, has already been fixed in svn. This fixes the other problem, which is that we try to regenerate the preview continously, even if something keeps preventing us from completing the procedure. This limits the number of retries to five, which should capture most of the real cases we should recreate the preview.

Note: See TracTickets for help on using tickets.