Opened 13 years ago

Closed 13 years ago

Last modified 13 years ago

#3186 closed defect (invalid)

Recording doesn't end

Reported by: anonymous Owned by: Isaac Richards
Priority: major Milestone: 0.21
Component: mythtv Version: head
Severity: medium Keywords:
Cc: Ticket locked: no

Description

After running MythTV (letting it watch LiveTV and record a show once in a while) for a while I notice that the backend shows: This recording will end at xx:yy

Where xx:yy is a time in the past (several hours ago).

I posted logs to mythtv-users. Some here:

007-03-10 08:14:00.968 Finished recording The fairytaler "Het lelijke eendje": channel 3 2007-03-10 08:14:01.063 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:14:01.077 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:14:01.166 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:14:01.253 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. [mpegts @ 0x452aa6d0]Parser not found for Codec Id: 94211 ! 0: start_time: 4153.071 duration: 8589.927 1: start_time: 4153.032 duration: 0.013 2: start_time: 4153.029 duration: 0.011 stream: start_time: 46144.768 duration: 95444.100 bitrate=0 kb/s 2007-03-10 08:14:01.411 AFD: Opened codec 0x8d0b8b0, id(MPEG2VIDEO) type(Video) 2007-03-10 08:14:01.429 TVRec(1): RingBufferChanged?() 2007-03-10 08:14:01.455 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:14:01.458 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:14:01.490 Finished recording The fairytaler "Het lelijke eendje": channel 3 2007-03-10 08:14:01.438 AFD: Opened codec 0x8d0bc10, id(MP3) type(Audio) 2007-03-10 08:14:01.509 NVP: Recording does not have position map.

Run 'mythcommflag --file 3_20070310075032.mpg

--rebuild' to fix 2007-03-10 08:14:01.746 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:14:01.777 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:14:01.779 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:14:01.781 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:00.420 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:00.422 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:00.527 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:00.556 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:00.575 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:00.577 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:00.591 Finished recording Z@pp: channel 3 2007-03-10 08:15:00.640 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:00.649 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:00.674 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:00.677 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. [mpegts @ 0x452aa6d0]Parser not found for Codec Id: 94211 ! 0: start_time: 4279.798 duration: 8589.931 1: start_time: 4279.781 duration: 0.013 2: start_time: 4279.764 duration: 0.022 stream: start_time: 47552.928 duration: 95444.060 bitrate=0 kb/s 2007-03-10 08:15:00.795 AFD: Opened codec 0x8d0bd90, id(MPEG2VIDEO) type(Video) 2007-03-10 08:15:00.797 AFD: Opened codec 0x8d6bd50, id(MP3) type(Audio) 2007-03-10 08:15:01.141 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:01.148 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:01.151 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:01.154 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:01.618 TVRec(1): RingBufferChanged?() 2007-03-10 08:15:01.634 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:01.636 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:15:01.661 Finished recording Z@pp: channel 3 2007-03-10 08:16:01.311 Expiring 17 MBytes for 3 @ Sat Mar 10 08:14:00 2007 => Z@pp 2007-03-10 08:16:01.333 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:16:01.335 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:16:04.359 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:16:04.363 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:16:08.385 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:16:08.395 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:40:00.668 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:40:00.713 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:40:01.712 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:40:01.713 MythSocket?(a9468720:-1): writeStringList: Error, called with unconnected socket. 2007-03-10 08:40:02.835 MythSocket?(8376a88:-1): writeStringList: Error, called with unconnected socket. (and more loads of these errors)

Change History (14)

comment:1 Changed 13 years ago by anonymous

Milestone: unknown0.21

How can I help debug? More logging? Different logging? Different kernel?

comment:2 Changed 13 years ago by anonymous

Appears to be fixed after updating to more recent svn from Ramses Smeyers' rpm repo.

comment:3 Changed 13 years ago by anonymous

What is fixed are the socket errors. THe backend status is still sometimes showing a time in the past (this recoridng will end at xx:yy where xx:yy is in the past)

comment:4 Changed 13 years ago by anonymous

Severity: mediumhigh

Yesterday's most recent svn: 2007-03-17 11:55:02.274 Finished recording Nioscoop: channel 2 2007-03-17 11:55:02.240 AFD: Opened codec 0x8932ca0, id(MP3) type(Audio) 2007-03-17 11:55:02.299 NVP: GetScreenGrabAtFrame?: Recording does not have position map so we will be unable to grab the desired frame.

2007-03-17 11:55:02.301 Run 'mythcommflag --file 2_20070317112731.mpg --rebuild' to fix. 2007-03-17 11:55:02.305 If that does not work and this is a .mpg file, try 'mythtranscode --mpeg2 --buildindex --allkeys -c 2 -s 20070317112731'. 2007-03-17 12:15:45.022 unknown socket 2007-03-17 12:15:49.367 MainServer::HandleVersion? - Client speaks protocol version 15 but we speak 33! 2007-03-17 12:15:49.372 MainServer::HandleVersion? - Client speaks protocol version 15 but we speak 33! 2007-03-17 12:15:49.410 MainServer::HandleAnnounce? Playback 2007-03-17 12:15:49.412 adding: MythTvPlayer? as a client (events: 0) 2007-03-17 12:15:49.413 MainServer::HandleAnnounce? FileTransfer? 2007-03-17 12:15:49.414 adding: MythTvPlayer? as a remote file transfer 2007-03-17 12:35:56.226 unknown socket 2007-03-17 12:35:56.292 MainServer::HandleVersion? - Client speaks protocol version 15 but we speak 33! 2007-03-17 12:35:56.298 MainServer::HandleVersion? - Client speaks protocol version 15 but we speak 33! 2007-03-17 12:35:56.303 MainServer::HandleAnnounce? Playback 2007-03-17 12:35:56.304 adding: MythTvPlayer? as a client (events: 0) 2007-03-17 12:35:56.306 MainServer::HandleAnnounce? FileTransfer? 2007-03-17 12:35:56.307 adding: MythTvPlayer? as a remote file transfer 2007-03-17 14:57:48.653 unknown socket 2007-03-17 14:57:49.129 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:57:50.134 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:57:51.136 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:57:52.140 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:57:53.152 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:57:54.155 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:57:55.162 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:57:56.167 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:57:57.171 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:57:58.174 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:57:59.178 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:00.182 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:01.193 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:02.197 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:03.202 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:04.204 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:05.208 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:06.212 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:07.216 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:08.219 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:09.223 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:10.237 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:11.240 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:12.242 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:13.246 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:14.250 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:15.254 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:16.257 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:17.261 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:18.269 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:19.277 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:20.280 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:21.284 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:22.287 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:23.291 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:24.295 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:25.298 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:26.302 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. 2007-03-17 14:58:27.310 MythSocket?(8350d38:-1): writeStringList: Error, called with unconnected socket. (etc)

comment:5 Changed 13 years ago by Isaac Richards

Priority: majorminor
Resolution: invalid
Severity: highmedium
Status: newclosed

"Client speaks protocol version 15 but we speak 33!"

You have something seriously wrong on your system.

comment:6 in reply to:  5 Changed 13 years ago by anonymous

Priority: minormajor
Resolution: invalid
Status: closedreopened

Replying to ijr:

"Client speaks protocol version 15 but we speak 33!"

You have something seriously wrong on your system.

Nope. Client is external, srunning MythTvPlayer? on a win2k system. See the log. MythTV is all on the same level. Recent svn.

comment:7 Changed 13 years ago by danielk

Resolution: invalid
Status: reopenedclosed

External clients are not supported by us. You must talk directly with whoever wrote this program. From the looks of it this program is no longer supported or you have a very old version installed.

comment:8 Changed 13 years ago by anonymous

So we immediately know for sure it is the 'fault' of the external player?

comment:9 Changed 13 years ago by anonymous

Resolution: invalid
Status: closedreopened

The author of MythTv? Player explains:

The "Client speaks protocol version 15 but we speak 33!" is not the problem. Everytime MythTv? Player connects to the backend it first connect using protocol version 15.. the backend will then reject and in the reply have the real protocol version (In this process, the backend log the message). THEN, MythTv? Player connects with the correct protocol version.

comment:10 Changed 13 years ago by anonymous

2007-03-18 16:40:21.018 AFD: Opened codec 0x8d06fa0, id(MPEG2VIDEO) type(Video) 2007-03-18 16:40:21.019 AFD: Opened codec 0x8c05410, id(MP3) type(Audio) 2007-03-18 16:40:23.113 MainServer::HandleAnnounce? Monitor 2007-03-18 16:40:23.122 adding: recorder as a client (events: 0) 2007-03-18 16:56:21.314 Expiring 513 MBytes for 2 @ Thu Mar 8 19:25:00 2007 => Taxi 2007-03-18 16:56:21.421 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 16:56:29.095 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:05:01.015 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:05:01.071 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:05:01.192 Finished recording Omega Code "Jozef": channel 3 2007-03-18 17:05:01.194 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:05:01.365 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:05:01.437 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. [mpegts @ 0x4a2c96d0]Parser not found for Codec Id: 94211 ! 0: start_time: 489.975 duration: 0.018 1: start_time: 489.943 duration: 0.013 2: start_time: 489.851 duration: 0.097 stream: start_time: 5442.786 duration: 1.582 bitrate=331 kb/s 2007-03-18 17:05:01.523 AFD: Opened codec 0x8c91e40, id(MPEG2VIDEO) type(Video) 2007-03-18 17:05:01.531 AFD: Opened codec 0x8c87110, id(MP3) type(Audio) 2007-03-18 17:05:01.860 TVRec(1): RingBufferChanged?() 2007-03-18 17:05:01.889 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:05:01.909 Finished recording Omega Code "Jozef": channel 3 2007-03-18 17:05:02.092 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:05:02.108 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:06:22.219 Expiring 636 MBytes for 2 @ Thu Mar 8 20:50:00 2007 => Twee voor twaalf 2007-03-18 17:06:22.306 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:06:29.847 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:15:00.832 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:15:00.921 Finished recording Omega Helden "Jozef (2)": channel 3 2007-03-18 17:15:00.922 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:15:00.996 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:15:01.012 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:15:01.084 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:15:01.088 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:15:01.144 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. [mpegts @ 0x4a2c96d0]Parser not found for Codec Id: 94211 ! 0: start_time: 635.772 duration: 0.011 1: start_time: 635.743 duration: 0.013 2: start_time: 635.644 duration: 0.104 stream: start_time: 7062.706 duration: 1.542 bitrate=340 kb/s 2007-03-18 17:15:01.168 AFD: Opened codec 0x8c05920, id(MPEG2VIDEO) type(Video) 2007-03-18 17:15:01.169 AFD: Opened codec 0x8c87010, id(MP3) type(Audio) 2007-03-18 17:15:01.754 TVRec(1): RingBufferChanged?() 2007-03-18 17:15:01.774 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:15:01.791 Finished recording Omega Helden "Jozef (2)": channel 3 2007-03-18 17:43:00.666 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:01.674 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:02.683 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:03.684 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:04.688 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:05.692 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:06.697 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:07.699 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:08.703 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:09.707 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:10.714 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:11.718 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:12.722 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. 2007-03-18 17:43:13.726 MythSocket?(a8800870:-1): writeStringList: Error, called with unconnected socket. (etc)

comment:11 Changed 13 years ago by Isaac Richards

Resolution: invalid
Status: reopenedclosed

Repro this with mythfrontend, not an external player, then reopen (with logs)

comment:12 Changed 13 years ago by anonymous

Resolution: invalid
Status: closedreopened

a) MythTv? Player closed the sockets in a way that was not correct. Fixed in v0.3.5. b) MythTV itself does not handle this situation very gracefully and spits the log full of the socket errors after a while.

comment:13 Changed 13 years ago by Isaac Richards

Resolution: invalid
Status: reopenedclosed

Unsure as to why this was reopened, as this still hasn't been demonstrated happening with mythfrontend.

comment:14 Changed 13 years ago by Mikkel

I think the problem is existing when using any external program such as dsmyth, MythTv? Player etc, so you might want to consider it. (I do not not with xmbc-script and tapeworm). I have digged into the problem and found out why and when it happens so I am writing it here such that you know.

The problem is when you have a connection which receive events and you close the connection with the "DONE" command. In this case, the socket is closed but it remains in the list which receives events. It is never removed from this list, so there just keep coming more and more broken connections. Maybe a socket should be removed from the list when the "DONE" command is sent, and sockets removed from the list when they turn out to be unresponsive. Actually, I think that all connections which are ended with "DONE" seems to be kept in the list - also when they do not have the "wantEvent" flag set. This will keep the list expanding, consume memory and make iterating the list slower Even though it is not happening with the mythfrontend, I still think it would be stability fix, and quite easy by removing a socket from the list when "DONE" is called.

\Mikkel [Developer of MythTv? Player]

Note: See TracTickets for help on using tickets.