0 byte fan art causes segmentation fault

[jflatt@…]

2016-02-14 13:41:18.056598 E  FileRingBuf(/mnt/store/Videos/FanArt//Rick and Morty Season 2_fanart.jpg): OpenFile(): File too small (0B).
2016-02-14 13:41:18.058308 E  MainServer: Can't open /mnt/store/Videos/FanArt//Rick and Morty Season 2_fanart.jpg
2016-02-14 13:41:18.058737 I  FileTransfer sock(10279c0) disconnected
2016-02-14 13:41:18.059313 C  Received Segmentation fault: Code 1, PID 113, UID 0, Value 0x00000000
Segmentation fault

[Roger Siddons]

This is reproducible on Master as of 10-Apr (2e98fb583) and is related to 98bec5c83.

When the File Transfer fails, HandleAnnounce deletes the FileTransfer (decrements to 0). However a socket disconnection always occurs and MainServer::connectionClosed also tries to clean it up because it is still in the fileTransferList.

If HandleAnnounce really needs to delete ft then it should also remove it from fileTransferList.

However it seems simpler to leave it to the be cleaned up by the disconnection. Attached patch does this and prevents the crash.

With patch:

Frontend log

20:30:06.930006 I  RemoteFile::FindFile(): looking for '/tmdb3.py_10693_coverart.jpg' on 'study' in group 'Coverart' (useregex: 0, allowfallback: 0)
20:30:06.969346 E  RemoteFile::openSocket(file data socket): Failed to open socket, error was filetransfer_unable_to_open_file

20:30:06.975010 D  RemoteFile(myth://Coverart@study/tmdb3.py_10693_coverart.jpg)
20:30:06.975045 I  RemoteFile::Exists(): looking for remote file: myth://Coverart@study/tmdb3.py_10693_coverart.jpg}}}

Backend log:

20:30:06.957294 I  MainServer: LocalFilePath(/tmdb3.py_10693_coverart.jpg 'tmdb3.py_10693_coverart.jpg'), found file through exhaustive search at '/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg'
20:30:06.967560 E  FileRingBuf(/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg): OpenFile(): File too small (0B).
20:30:06.967610 I  FileRingBuf(/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg): OpenFile() made 1 attempts in 10 ms
20:30:06.967632 I  RingBuf(/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg): CalcReadAheadThresh(8000 Kb)
			 -> threshhold(3584 KB) min read(320 KB) blk size(128 KB)
20:30:06.968531 E  MainServer: Can't open /home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg
20:30:06.969095 I  FileTransfer sock(172a260) disconnected
20:30:06.969124 I  calling StopReads()
20:30:06.969140 I  RingBuf(/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg): StopReads()

20:30:06.975895 I  Playback sock(173ead0) 'study' disconnected
20:30:06.976508 D  SG(Coverart): FindFile: Searching for 'tmdb3.py_10693_coverart.jpg'
20:30:06.976528 D  SG(Coverart): FindFileDir: Checking '/home/archive/myth/recordings' for '/home/archive/myth/recordings/tmdb3.py_10693_coverart.jpg'
20:30:06.976564 D  SG(Coverart): FindFile: Found '/home/archive/myth/recordings/tmdb3.py_10693_coverart.jpg'

[Roger Siddons]

Previous analysis was incomplete and elected for the wrong solution. Ignore previous patch.

Prior to 916e43bb52ba the socket wasn't added to the fileTransferList until the file had been opened successfully. That commit adds the socket to the list but doesn't remove it when deleting the failed File Transfer, leading to the disconnection event also trying to delete it.

Proper solution is to reinstate previous behaviour of only adding successful File Transfers to the list.

With new patch:

Frontend:

2016-04-11 11:02:11.768981 D  No menu file /home/roger/.mythtv/videomenu.xml
2016-04-11 11:02:17.868498 I  RemoteFile::FindFile(): looking for '/tmdb3.py_10693_coverart.jpg' on 'study' in group 'Coverart' (useregex: 0, allowfallback: 0)
2016-04-11 11:02:17.906931 E  RemoteFile::openSocket(file data socket): Failed to open socket, error was filetransfer_unable_to_open_file
2016-04-11 11:02:17.907733 D  RemoteFile(myth://Coverart@study/tmdb3.py_10693_coverart.jpg)
2016-04-11 11:02:17.907777 I  RemoteFile::Exists(): looking for remote file: myth://Coverart@study/tmdb3.py_10693_coverart.jpg

Backend:

2016-04-11 11:02:17.868962 I  MainServer: Looking for file '/tmdb3.py_10693_coverart.jpg' on host 'study' in group 'Coverart' (useregex: 0, allowfallback: 1
2016-04-11 11:02:17.868982 I  MainServer: Checking local host 'study' for file
2016-04-11 11:02:17.875999 D  SG(Coverart): FindFile: Searching for '/tmdb3.py_10693_coverart.jpg'
2016-04-11 11:02:17.876028 D  SG(Coverart): FindFileDir: Checking '/home/archive/myth/recordings' for '/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg'
2016-04-11 11:02:17.876100 D  SG(Coverart): FindFile: Found '/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg'
2016-04-11 11:02:17.876154 I  MainServer: File 0 was found at: 'myth://Coverart@study/tmdb3.py_10693_coverart.jpg'
2016-04-11 11:02:17.887966 I  MainServer: MainServer::ANN Playback
2016-04-11 11:02:17.887990 I  MainServer: adding: study(2331da0) as a client (events: 0)
2016-04-11 11:02:17.894675 D  SG(Coverart): FindFile: Searching for '/tmdb3.py_10693_coverart.jpg'
2016-04-11 11:02:17.894701 D  SG(Coverart): FindFileDir: Checking '/home/archive/myth/recordings' for '/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg'
2016-04-11 11:02:17.894750 D  SG(Coverart): FindFile: Found '/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg'
2016-04-11 11:02:17.894769 I  MainServer: LocalFilePath(/tmdb3.py_10693_coverart.jpg 'tmdb3.py_10693_coverart.jpg'), found file through exhaustive search at '/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg'
2016-04-11 11:02:17.905111 E  FileRingBuf(/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg): OpenFile(): File too small (0B).
2016-04-11 11:02:17.905166 I  FileRingBuf(/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg): OpenFile() made 1 attempts in 10 ms
2016-04-11 11:02:17.905186 I  RingBuf(/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg): CalcReadAheadThresh(8000 Kb)
			 -> threshhold(3584 KB) min read(320 KB) blk size(128 KB)
2016-04-11 11:02:17.906151 E  MainServer: Can't open /home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg
2016-04-11 11:02:17.906358 I  calling StopReads()
2016-04-11 11:02:17.906416 I  RingBuf(/home/archive/myth/recordings//tmdb3.py_10693_coverart.jpg): StopReads()
2016-04-11 11:02:17.906709 W  MainServer: Unknown socket closing MythSocket(0x2372f10)
2016-04-11 11:02:17.907598 I  Playback sock(2331da0) 'study' disconnected
2016-04-11 11:02:17.908802 D  SG(Coverart): FindFile: Searching for 'tmdb3.py_10693_coverart.jpg'
2016-04-11 11:02:17.908819 D  SG(Coverart): FindFileDir: Checking '/home/archive/myth/recordings' for '/home/archive/myth/recordings/tmdb3.py_10693_coverart.jpg'
2016-04-11 11:02:17.908851 D  SG(Coverart): FindFile: Found '/home/archive/myth/recordings/tmdb3.py_10693_coverart.jpg'

[Roger Siddons <rsiddons@…>]

In ea5fdd45bdab01aa6f3d577db7e344a90aae98a6/mythtv:

Error: Processor CommitTicketReference failed

GIT backend not available

[Roger Siddons <rsiddons@…>]

In 850acd1f5d0d787f949ebd5c26b5d5d0ea1b6214/mythtv:

Error: Processor CommitTicketReference failed

GIT backend not available