[mythtv-commits] Ticket #4101: MythSocket breaks

MythTV mythtv at cvs.mythtv.org
Wed Dec 26 06:57:15 UTC 2007 

#4101: MythSocket breaks
---------------------------------+------------------------------------------
 Reporter:  majost at lagparty.org  |        Owner:  ijr    
     Type:  defect               |       Status:  new    
 Priority:  minor                |    Milestone:  unknown
Component:  mythtv               |      Version:  head   
 Severity:  medium               |   Resolution:         
  Mlocked:  0                    |  
---------------------------------+------------------------------------------
Description changed by nigel:

Old description:

> I apparently had a misconfigured tuner with the default audio capture
> sample rate of 32kHz. It seems when myth attempts to use this tuner in
> live tv mode, it would reconfigure the the sample rate as shown in the
> log, and the socket would break. The only way to fix the socket
> connection is to restart the frontend, and sometimes the backend as well.
>
> The backend version is from the multirec branch, however this issue has
> been seen in trunk as well.
>
> sudo -u mythtv mythbackend -v socket
> 2007-10-23 18:17:21.187 Using runtime prefix = /usr
> 2007-10-23 18:17:21.247 New DB connection, total: 1
> 2007-10-23 18:17:21.252 Connected to database 'mythconverg' at host:
> localhost
> 2007-10-23 18:17:21.256 Current Schema Version: 1199
> Starting up as the master server.
> 2007-10-23 18:17:21.278 New DB connection, total: 2
> 2007-10-23 18:17:21.279 Connected to database 'mythconverg' at host:
> localhost
> 2007-10-23 18:17:21.282 New DB connection, total: 3
> 2007-10-23 18:17:21.282 Connected to database 'mythconverg' at host:
> localhost
> 2007-10-23 18:17:22.568 New DB connection, total: 4
> 2007-10-23 18:17:22.569 Connected to database 'mythconverg' at host:
> localhost
> 2007-10-23 18:17:22.570 New DB connection, total: 5
> 2007-10-23 18:17:22.571 Connected to database 'mythconverg' at host:
> localhost
> 2007-10-23 18:17:22.572 New DB connection, total: 6
> 2007-10-23 18:17:22.572 Connected to database 'mythconverg' at host:
> localhost
> 2007-10-23 18:17:40.023 New DB scheduler connection
> 2007-10-23 18:17:40.024 Connected to database 'mythconverg' at host:
> localhost
> 2007-10-23 18:17:41.365 Main::Registering HttpStatus Extension
> 2007-10-23 18:17:41.366 mythbackend version: 0.21.20070918-98
> www.mythtv.org
> 2007-10-23 18:17:41.366 Enabled verbose msgs:  important general socket
> 2007-10-23 18:17:41.366 AutoExpire: Found max recording rate of 355
> MB/min
> 2007-10-23 18:17:41.368 AutoExpire: CalcParams(): Required Free Space:
> 3.0 GB w/freq: 5 min
> 2007-10-23 18:17:43.029 Reschedule requested for id -1.
> 2007-10-23 18:18:04.759 MythSocket(b0e0f1c8:18): new socket
> 2007-10-23 18:18:04.759 MythSocket(b0e0f1c8:18): setSocket: 17
> 2007-10-23 18:18:04.760 MythSocket(b0e0f1c8:17): state change Idle ->
> Connected
> 2007-10-23 18:18:04.760 MythSocket(b0e0f1c8:17): UpRef: 1
> 2007-10-23 18:18:04.760 MythSocket: readyread thread start
> 2007-10-23 18:18:04.760 MythSocket(b0e0f1c8:17): socket is readable
> 2007-10-23 18:18:04.760 MythSocket(b0e0f1c8:17): cb->readyRead()
> 2007-10-23 18:18:04.760 MythSocket(b0e0f1c8:17): UpRef: 2
> 2007-10-23 18:18:04.761 MythSocket(b0e0f1c8:17): DownRef: 1
> 2007-10-23 18:18:04.763 MythSocket(b0e0f1c8:17): socket is readable
> 2007-10-23 18:18:04.763 MythSocket(b0e0f1c8:17): cb->readyRead()
> 2007-10-23 18:18:04.763 MythSocket(b0e0f1c8:17): UpRef: 2
> 2007-10-23 18:18:04.763 MainServer::HandleAnnounce Monitor
> 2007-10-23 18:18:04.764 adding: ryans-laptop-unique-identifier as a
> client (events: 0)
> 2007-10-23 18:18:04.764 MythSocket(b0e0f1c8:17): DownRef: 1
> 2007-10-23 18:18:04.765 MythSocket(b0e0b700:21): new socket
> 2007-10-23 18:18:04.765 MythSocket(b0e0b700:21): setSocket: 20
> 2007-10-23 18:18:04.765 MythSocket(b0e0b700:20): state change Idle ->
> Connected
> 2007-10-23 18:18:04.765 MythSocket(b0e0b700:20): UpRef: 1
> 2007-10-23 18:18:04.765 MythSocket(b0e0b700:20): socket is readable
> 2007-10-23 18:18:04.765 MythSocket(b0e0b700:20): cb->readyRead()
> 2007-10-23 18:18:04.765 MythSocket(b0e0b700:20): UpRef: 2
> 2007-10-23 18:18:04.766 MainServer::HandleAnnounce Monitor
> 2007-10-23 18:18:04.766 adding: ryans-laptop-unique-identifier as a
> client (events: 1)
> 2007-10-23 18:18:04.766 MythSocket(b0e0b700:20): DownRef: 1
> 2007-10-23 18:18:04.767 MythSocket(b0e0f1c8:17): socket is readable
> 2007-10-23 18:18:04.767 MythSocket(b0e0f1c8:17): cb->readyRead()
> 2007-10-23 18:18:04.767 MythSocket(b0e0f1c8:17): UpRef: 2
> 2007-10-23 18:18:04.768 MythSocket(b0e0f1c8:17): DownRef: 1
> 2007-10-23 18:18:04.768 MythSocket(b0e0f1c8:17): socket is readable
> 2007-10-23 18:18:04.769 MythSocket(b0e0f1c8:17): cb->readyRead()
> 2007-10-23 18:18:04.769 MythSocket(b0e0f1c8:17): UpRef: 2
> 2007-10-23 18:18:04.770 MythSocket(b0e0f1c8:17): DownRef: 1
> 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:22): new socket
> 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:22): setSocket: 21
> 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): state change Idle ->
> Connected
> 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): UpRef: 1
> 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): socket is readable
> 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): cb->readyRead()
> 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): UpRef: 2
> 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): DownRef: 1
> 2007-10-23 18:18:04.779 MythSocket(b0e0ee60:21): socket is readable
> 2007-10-23 18:18:04.779 MythSocket(b0e0ee60:21): cb->readyRead()
> 2007-10-23 18:18:04.779 MythSocket(b0e0ee60:21): UpRef: 2
> 2007-10-23 18:18:04.779 MainServer::HandleAnnounce Playback
> 2007-10-23 18:18:04.780 adding: ryans-laptop-unique-identifier as a
> client (events: 0)
> 2007-10-23 18:18:04.780 MythSocket(b0e0ee60:21): DownRef: 1
> 2007-10-23 18:18:04.782 MythSocket(b0e0ee60:21): socket is readable
> 2007-10-23 18:18:04.782 MythSocket(b0e0ee60:21): cb->readyRead()
> 2007-10-23 18:18:04.783 MythSocket(b0e0ee60:21): UpRef: 2
> 2007-10-23 18:18:04.784 TVRec(1): Changing from None to WatchingLiveTV
> 2007-10-23 18:18:04.935 TVRec(1): HW Tuner: 1->1
> 2007-10-23 18:18:08.756 MythSocket(b0e0f1c8:17): UpRef: 2
> 2007-10-23 18:18:08.756 MythSocket(b0e0f1c8:17): DownRef: 1
> 2007-10-23 18:18:08.756 MythSocket(b0e0b700:20): UpRef: 2
> 2007-10-23 18:18:08.756 MythSocket(b0e0b700:20): DownRef: 1
> 2007-10-23 18:18:08.756 MythSocket(b0e0ee60:21): UpRef: 3
> 2007-10-23 18:18:08.756 MythSocket(b0e0ee60:21): DownRef: 2
> 2007-10-23 18:18:10.570 MythSocket(b0e0f1c8:17): UpRef: 2
> 2007-10-23 18:18:10.570 MythSocket(b0e0f1c8:17): DownRef: 1
> 2007-10-23 18:18:10.571 MythSocket(b0e0b700:20): UpRef: 2
> 2007-10-23 18:18:10.571 MythSocket(b0e0b700:20): DownRef: 1
> 2007-10-23 18:18:10.571 MythSocket(b0e0ee60:21): UpRef: 3
> 2007-10-23 18:18:10.571 MythSocket(b0e0ee60:21): DownRef: 2
> 2007-10-23 18:18:12.283 MythSocket(b0e0f1c8:17): UpRef: 2
> 2007-10-23 18:18:12.283 MythSocket(b0e0f1c8:17): DownRef: 1
> 2007-10-23 18:18:12.283 MythSocket(b0e0b700:20): UpRef: 2
> 2007-10-23 18:18:12.283 MythSocket(b0e0b700:20): DownRef: 1
> 2007-10-23 18:18:12.283 MythSocket(b0e0ee60:21): UpRef: 3
> 2007-10-23 18:18:12.283 MythSocket(b0e0ee60:21): DownRef: 2
> 2007-10-23 18:18:12.298 MythSocket(b0e0ee60:21): state change Connected
> -> Idle
> 2007-10-23 18:18:12.299 MythSocket(b0e0ee60:-1): cb->connectionClosed()
> 2007-10-23 18:18:12.308 MPEGRec(/dev/video0) Warning: Audio sample rate
> 32000 Hz
>                         is not supported by ivtv driver, using 48000 Hz
> instead.
> 2007-10-23 18:18:12.581 TVRec(1): Changing from WatchingLiveTV to None
> 2007-10-23 18:18:13.041 Finished recording Flip That House "David":
> channel 1036
> 2007-10-23 18:18:13.057 MythSocket(b0e0f1c8:17): UpRef: 2
> 2007-10-23 18:18:13.058 MythSocket(b0e0f1c8:17): DownRef: 1
> 2007-10-23 18:18:13.058 MythSocket(b0e0b700:20): UpRef: 2
> 2007-10-23 18:18:13.058 MythSocket(b0e0b700:20): DownRef: 1
> 2007-10-23 18:18:13.058 MythSocket(b0e0f1c8:17): UpRef: 2
> 2007-10-23 18:18:13.058 MythSocket(b0e0f1c8:17): DownRef: 1
> 2007-10-23 18:18:13.058 MythSocket(b0e0b700:20): UpRef: 2
> 2007-10-23 18:18:13.058 MythSocket(b0e0b700:20): DownRef: 1
> 2007-10-23 18:18:13.058 MythSocket(b0e0f1c8:17): UpRef: 2
> 2007-10-23 18:18:13.059 MythSocket(b0e0f1c8:17): DownRef: 1
> 2007-10-23 18:18:13.059 MythSocket(b0e0b700:20): UpRef: 2
> 2007-10-23 18:18:13.059 MythSocket(b0e0b700:20): DownRef: 1
> 2007-10-23 18:18:13.064 MythSocket(b0e0ee60:-1): writeStringList: Error,
> socket went unconnected.
> 2007-10-23 18:18:13.064 MythSocket(b0e0ee60:-1): DownRef: 1
> 2007-10-23 18:18:13.618 cache_is_same_program: 22536
> 2007-10-23 18:18:13.652 Scheduled 1715 items in 30.6 = 26.38 match + 4.24
> place
> 2007-10-23 18:18:13.654 Seem to be woken up by USER
> 2007-10-23 18:18:13.656 MythSocket(b0e0f1c8:17): UpRef: 2
> 2007-10-23 18:18:13.656 MythSocket(b0e0f1c8:17): DownRef: 1
> 2007-10-23 18:18:13.656 MythSocket(b0e0b700:20): UpRef: 2
> 2007-10-23 18:18:13.656 MythSocket(b0e0b700:20): DownRef: 1

New description:

 I apparently had a misconfigured tuner with the default audio capture
 sample rate of 32kHz. It seems when myth attempts to use this tuner in
 live tv mode, it would reconfigure the the sample rate as shown in the
 log, and the socket would break. The only way to fix the socket connection
 is to restart the frontend, and sometimes the backend as well.

 The backend version is from the multirec branch, however this issue has
 been seen in trunk as well.
 {{{
 sudo -u mythtv mythbackend -v socket
 2007-10-23 18:17:21.187 Using runtime prefix = /usr
 2007-10-23 18:17:21.247 New DB connection, total: 1
 2007-10-23 18:17:21.252 Connected to database 'mythconverg' at host:
 localhost
 2007-10-23 18:17:21.256 Current Schema Version: 1199
 Starting up as the master server.
 2007-10-23 18:17:21.278 New DB connection, total: 2
 2007-10-23 18:17:21.279 Connected to database 'mythconverg' at host:
 localhost
 2007-10-23 18:17:21.282 New DB connection, total: 3
 2007-10-23 18:17:21.282 Connected to database 'mythconverg' at host:
 localhost
 2007-10-23 18:17:22.568 New DB connection, total: 4
 2007-10-23 18:17:22.569 Connected to database 'mythconverg' at host:
 localhost
 2007-10-23 18:17:22.570 New DB connection, total: 5
 2007-10-23 18:17:22.571 Connected to database 'mythconverg' at host:
 localhost
 2007-10-23 18:17:22.572 New DB connection, total: 6
 2007-10-23 18:17:22.572 Connected to database 'mythconverg' at host:
 localhost
 2007-10-23 18:17:40.023 New DB scheduler connection
 2007-10-23 18:17:40.024 Connected to database 'mythconverg' at host:
 localhost
 2007-10-23 18:17:41.365 Main::Registering HttpStatus Extension
 2007-10-23 18:17:41.366 mythbackend version: 0.21.20070918-98
 www.mythtv.org
 2007-10-23 18:17:41.366 Enabled verbose msgs:  important general socket
 2007-10-23 18:17:41.366 AutoExpire: Found max recording rate of 355 MB/min
 2007-10-23 18:17:41.368 AutoExpire: CalcParams(): Required Free Space: 3.0
 GB w/freq: 5 min
 2007-10-23 18:17:43.029 Reschedule requested for id -1.
 2007-10-23 18:18:04.759 MythSocket(b0e0f1c8:18): new socket
 2007-10-23 18:18:04.759 MythSocket(b0e0f1c8:18): setSocket: 17
 2007-10-23 18:18:04.760 MythSocket(b0e0f1c8:17): state change Idle ->
 Connected
 2007-10-23 18:18:04.760 MythSocket(b0e0f1c8:17): UpRef: 1
 2007-10-23 18:18:04.760 MythSocket: readyread thread start
 2007-10-23 18:18:04.760 MythSocket(b0e0f1c8:17): socket is readable
 2007-10-23 18:18:04.760 MythSocket(b0e0f1c8:17): cb->readyRead()
 2007-10-23 18:18:04.760 MythSocket(b0e0f1c8:17): UpRef: 2
 2007-10-23 18:18:04.761 MythSocket(b0e0f1c8:17): DownRef: 1
 2007-10-23 18:18:04.763 MythSocket(b0e0f1c8:17): socket is readable
 2007-10-23 18:18:04.763 MythSocket(b0e0f1c8:17): cb->readyRead()
 2007-10-23 18:18:04.763 MythSocket(b0e0f1c8:17): UpRef: 2
 2007-10-23 18:18:04.763 MainServer::HandleAnnounce Monitor
 2007-10-23 18:18:04.764 adding: ryans-laptop-unique-identifier as a client
 (events: 0)
 2007-10-23 18:18:04.764 MythSocket(b0e0f1c8:17): DownRef: 1
 2007-10-23 18:18:04.765 MythSocket(b0e0b700:21): new socket
 2007-10-23 18:18:04.765 MythSocket(b0e0b700:21): setSocket: 20
 2007-10-23 18:18:04.765 MythSocket(b0e0b700:20): state change Idle ->
 Connected
 2007-10-23 18:18:04.765 MythSocket(b0e0b700:20): UpRef: 1
 2007-10-23 18:18:04.765 MythSocket(b0e0b700:20): socket is readable
 2007-10-23 18:18:04.765 MythSocket(b0e0b700:20): cb->readyRead()
 2007-10-23 18:18:04.765 MythSocket(b0e0b700:20): UpRef: 2
 2007-10-23 18:18:04.766 MainServer::HandleAnnounce Monitor
 2007-10-23 18:18:04.766 adding: ryans-laptop-unique-identifier as a client
 (events: 1)
 2007-10-23 18:18:04.766 MythSocket(b0e0b700:20): DownRef: 1
 2007-10-23 18:18:04.767 MythSocket(b0e0f1c8:17): socket is readable
 2007-10-23 18:18:04.767 MythSocket(b0e0f1c8:17): cb->readyRead()
 2007-10-23 18:18:04.767 MythSocket(b0e0f1c8:17): UpRef: 2
 2007-10-23 18:18:04.768 MythSocket(b0e0f1c8:17): DownRef: 1
 2007-10-23 18:18:04.768 MythSocket(b0e0f1c8:17): socket is readable
 2007-10-23 18:18:04.769 MythSocket(b0e0f1c8:17): cb->readyRead()
 2007-10-23 18:18:04.769 MythSocket(b0e0f1c8:17): UpRef: 2
 2007-10-23 18:18:04.770 MythSocket(b0e0f1c8:17): DownRef: 1
 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:22): new socket
 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:22): setSocket: 21
 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): state change Idle ->
 Connected
 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): UpRef: 1
 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): socket is readable
 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): cb->readyRead()
 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): UpRef: 2
 2007-10-23 18:18:04.774 MythSocket(b0e0ee60:21): DownRef: 1
 2007-10-23 18:18:04.779 MythSocket(b0e0ee60:21): socket is readable
 2007-10-23 18:18:04.779 MythSocket(b0e0ee60:21): cb->readyRead()
 2007-10-23 18:18:04.779 MythSocket(b0e0ee60:21): UpRef: 2
 2007-10-23 18:18:04.779 MainServer::HandleAnnounce Playback
 2007-10-23 18:18:04.780 adding: ryans-laptop-unique-identifier as a client
 (events: 0)
 2007-10-23 18:18:04.780 MythSocket(b0e0ee60:21): DownRef: 1
 2007-10-23 18:18:04.782 MythSocket(b0e0ee60:21): socket is readable
 2007-10-23 18:18:04.782 MythSocket(b0e0ee60:21): cb->readyRead()
 2007-10-23 18:18:04.783 MythSocket(b0e0ee60:21): UpRef: 2
 2007-10-23 18:18:04.784 TVRec(1): Changing from None to WatchingLiveTV
 2007-10-23 18:18:04.935 TVRec(1): HW Tuner: 1->1
 2007-10-23 18:18:08.756 MythSocket(b0e0f1c8:17): UpRef: 2
 2007-10-23 18:18:08.756 MythSocket(b0e0f1c8:17): DownRef: 1
 2007-10-23 18:18:08.756 MythSocket(b0e0b700:20): UpRef: 2
 2007-10-23 18:18:08.756 MythSocket(b0e0b700:20): DownRef: 1
 2007-10-23 18:18:08.756 MythSocket(b0e0ee60:21): UpRef: 3
 2007-10-23 18:18:08.756 MythSocket(b0e0ee60:21): DownRef: 2
 2007-10-23 18:18:10.570 MythSocket(b0e0f1c8:17): UpRef: 2
 2007-10-23 18:18:10.570 MythSocket(b0e0f1c8:17): DownRef: 1
 2007-10-23 18:18:10.571 MythSocket(b0e0b700:20): UpRef: 2
 2007-10-23 18:18:10.571 MythSocket(b0e0b700:20): DownRef: 1
 2007-10-23 18:18:10.571 MythSocket(b0e0ee60:21): UpRef: 3
 2007-10-23 18:18:10.571 MythSocket(b0e0ee60:21): DownRef: 2
 2007-10-23 18:18:12.283 MythSocket(b0e0f1c8:17): UpRef: 2
 2007-10-23 18:18:12.283 MythSocket(b0e0f1c8:17): DownRef: 1
 2007-10-23 18:18:12.283 MythSocket(b0e0b700:20): UpRef: 2
 2007-10-23 18:18:12.283 MythSocket(b0e0b700:20): DownRef: 1
 2007-10-23 18:18:12.283 MythSocket(b0e0ee60:21): UpRef: 3
 2007-10-23 18:18:12.283 MythSocket(b0e0ee60:21): DownRef: 2
 2007-10-23 18:18:12.298 MythSocket(b0e0ee60:21): state change Connected ->
 Idle
 2007-10-23 18:18:12.299 MythSocket(b0e0ee60:-1): cb->connectionClosed()
 2007-10-23 18:18:12.308 MPEGRec(/dev/video0) Warning: Audio sample rate
 32000 Hz
                         is not supported by ivtv driver, using 48000 Hz
 instead.
 2007-10-23 18:18:12.581 TVRec(1): Changing from WatchingLiveTV to None
 2007-10-23 18:18:13.041 Finished recording Flip That House "David":
 channel 1036
 2007-10-23 18:18:13.057 MythSocket(b0e0f1c8:17): UpRef: 2
 2007-10-23 18:18:13.058 MythSocket(b0e0f1c8:17): DownRef: 1
 2007-10-23 18:18:13.058 MythSocket(b0e0b700:20): UpRef: 2
 2007-10-23 18:18:13.058 MythSocket(b0e0b700:20): DownRef: 1
 2007-10-23 18:18:13.058 MythSocket(b0e0f1c8:17): UpRef: 2
 2007-10-23 18:18:13.058 MythSocket(b0e0f1c8:17): DownRef: 1
 2007-10-23 18:18:13.058 MythSocket(b0e0b700:20): UpRef: 2
 2007-10-23 18:18:13.058 MythSocket(b0e0b700:20): DownRef: 1
 2007-10-23 18:18:13.058 MythSocket(b0e0f1c8:17): UpRef: 2
 2007-10-23 18:18:13.059 MythSocket(b0e0f1c8:17): DownRef: 1
 2007-10-23 18:18:13.059 MythSocket(b0e0b700:20): UpRef: 2
 2007-10-23 18:18:13.059 MythSocket(b0e0b700:20): DownRef: 1
 2007-10-23 18:18:13.064 MythSocket(b0e0ee60:-1): writeStringList: Error,
 socket went unconnected.
 2007-10-23 18:18:13.064 MythSocket(b0e0ee60:-1): DownRef: 1
 2007-10-23 18:18:13.618 cache_is_same_program: 22536
 2007-10-23 18:18:13.652 Scheduled 1715 items in 30.6 = 26.38 match + 4.24
 place
 2007-10-23 18:18:13.654 Seem to be woken up by USER
 2007-10-23 18:18:13.656 MythSocket(b0e0f1c8:17): UpRef: 2
 2007-10-23 18:18:13.656 MythSocket(b0e0f1c8:17): DownRef: 1
 2007-10-23 18:18:13.656 MythSocket(b0e0b700:20): UpRef: 2
 2007-10-23 18:18:13.656 MythSocket(b0e0b700:20): DownRef: 1
 }}}

--

-- 
Ticket URL: <http://svn.mythtv.org/trac/ticket/4101#comment:4>
MythTV <http://svn.mythtv.org/trac>
MythTV

More information about the mythtv-commits mailing list