[mythtv-users] writeStringList error no data written on writeBlock (Python bindings?)

Thu Sep 12 01:16:57 UTC 2013

//Snip//
On 9/8/2013 6:05 PM, Roger Siddons wrote:
I too have noticed these errors for a while on 0.26/fixes but they have no
adverse effect on my system so I have never got around to investigating.
However I've always had a worry/feeling that they are related to the silence
commflagging script. 

Tonight we watched a recording whilst it was in progress (something we
rarely do) and I was irritated to see that the adverts weren't being
skipped. Some cursory debugging showed that these errors were the the cause.
I had a brief chance to log the network (mythbackend --setverbose network)
and ominously saw;

Sep 8 20:13:16 htpc mythlogserver: mythbackend[1959]: I Socket
mythcorecontext.cpp:1203 (dispatch) MythEvent: SYSTEM_EVENT
CLIENT_DISCONNECTED HOSTNAME htpc SENDER htpc
Sep 8 20:13:16 htpc mythlogserver: mythbackend[1959]: I Socket
mythcorecontext.cpp:1203 (dispatch) MythEvent:
LOCAL_SLAVE_BACKEND_ENCODERS_OFFLINE
Sep 8 20:13:16 htpc mythlogserver: mythbackend[1959]: I Socket
mythcorecontext.cpp:1203 (dispatch) MythEvent: SYSTEM_EVENT
CLIENT_DISCONNECTED HOSTNAME htpc SENDER htpc
Sep 8 20:13:16 htpc mythlogserver: mythbackend[1959]: I Socket
mythcorecontext.cpp:1203 (dispatch) MythEvent:
LOCAL_SLAVE_BACKEND_ENCODERS_OFFLINE
Sep 8 20:13:16 htpc mythlogserver: mythbackend[1959]: E CoreContext
mythsocket.cpp:375 (writeStringList) MythSocket(11d1750:209):
writeStringList: Error, No data written on writeB
lock (812 errors)
starts with: 660 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE UPDATE[]:[...

I believe these events relate to slave backends but I have none.

[Mark] I also have no slave backends.

Your dropbox link no longer works but I also see lots of;

Sep 8 19:26:07 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Playback
Sep 8 19:26:07 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1397 (HandleAnnounce) adding: htpc as a client (events: 0)
Sep 8 19:26:07 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Monitor
Sep 8 19:26:07 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1397 (HandleAnnounce) adding: htpc as a client (events: 1)
Sep 8 19:26:10 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Playback
Sep 8 19:26:10 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1397 (HandleAnnounce) adding: htpc as a client (events: 0)
Sep 8 19:26:10 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Monitor
Sep 8 19:26:10 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1397 (HandleAnnounce) adding: htpc as a client (events: 1)
Sep 8 19:26:19 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Playback
Sep 8 19:26:19 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1397 (HandleAnnounce) adding: htpc as a client (events: 0)
Sep 8 19:26:19 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1395 (HandleAnnounce) MainServer::ANN Monitor
Sep 8 19:26:19 htpc mythlogserver: mythbackend[1959]: I ProcessRequest
mainserver.cpp:1397 (HandleAnnounce) adding: htpc as a client (events: 1)
Sep 8 19:26:24 htpc mythlogserver: mythbackend[1959]: E CoreContext
mythsocket.cpp:375 (writeStringList) MythSocket(1128f00:207):
writeStringList: Error, No data written on writeBlock (815 errors)
starts with: 100816 BACKEND_MESSAGE[]:[]GENERATED_PIXMAP[]:[]OK[]:[]1005...

which do seem closely related to the start of commflagging.

[Mark]  Thanks for the response Roger, greatly appreciated. And yes you are
100% spot on I am getting quite a significant number of those info messages
(>1000 on rough guess) MainServer::ANN Monitor / MainServer::ANN Playback /
adding: xxxxx as a client. I didn't understand the significance of those
messages but yes I am a heavy user of the silence commflagging script
(essentially for all my commflagging). And I have allowed up to 3 concurrent
jobs so I could quite easily have 3 real time commflag jobs in progress at
the same time.

The errors all stopped when some recordings finish. I had 3 concurrent
recordings at the time so I wonder if multiple commflagging jobs are a
factor in it.

My initial hypothesis is that the commflagging messages are being
interpreted as a slave backend repeatedly connecting/disconnecting, which is
overloading Myth's sockets somehow. I haven't seen any of your "socket
unconnected" errors, but they arise from the same area.

I don't have time/opportunity to investigate further at the moment but, if
it's screwing your system, I'd suggest you simply disable the commflag
messages and see if the errors re-occur. Just comment out the line
containing "be.backendCommand" (and the following "if") in silence.py. Your
programmes will still be commflagged but, if you watch in-progress
recordings, you'll have to stop and restart playback to pick up the
skiplist.

[Mark] There is a definite improvement in the situation from 0.26 to 0.27.
In nearly 3 weeks since upgrading this situation has only happened once
compared with 4 or more times a day on 0.26. Perhaps there is a code change
in there somewhere that allows more sockets or better handles more sockets?
Just guessing. We regularly watch in progress recordings so I'll hold off on
the change suggested for now (as it would be nice for the commercial
skipping to happen without having to stop / restart) however you are also
100% correct that I have also had trouble with the automatic commercial
skipping while watching in progress recordings (our behaviour is to give a
recording a 15min head start before starting to watch so can just skip
through the commercials). Although last night it all 'just worked' which was
terribly pleasing as it was probably the first time we have managed to sit
down, watch TV, have the adds automatically skipped and then turn off
without me having to grab the keyboard and do something. Certainly improves
WAF.

And if Mr Wagner is watching, can he offer any advice on how to send
occasional messages from a python script to the backend ? The full script is
at
http://www.mythtv.org/wiki/Commercial_detection_with_silence_for_UK_freeview
HD#silence.py
<http://www.mythtv.org/wiki/Commercial_detection_with_silence_for_UK_freevie
wHD>  but the relevant code is;

db = MythTV.MythDB()
be = MythTV.BECache(None, False, db)

# send advert skiplist to MythPlayers
tuplelist = [(str(x) + ':' + str(rec.markup.MARK_COMM_START), str(y) + ':' +
str(rec.markup.MARK_COMM_END)) for x, y in rec.markup.getskiplist()]
mesg = 'COMMFLAG_UPDATE ' + progId + ' ' + ','.join([x for tuple in
tuplelist for x in tuple])
result = be.backendCommand("MESSAGE[]:[]" + mesg)

Not great code but it was my first attempt at Python and I couldn't find any
examples to copy...

[Mark] So IIUIC the hypothesis is that each time silence.py updates the
skiplist and flags that an update has been made it gets a new socket to the
database.  But that socket doesn't automatically close immediately after the
write so the number of open sockets increases until the number of permitted
sockets is reached then things start to fail (which of course happens
quicker if multiple instances of silence.py are running all calling their
own sockets - or if other MythTV elements are trying to also access the
database). So two possible solutions would be to either work out how to
reuse a socket so that only one was needed per execution of the silence.py
script or work out how to close a socket immediately after it has been used
so that there is not too many open at the same time?

I did notice http://www.gossamer-threads.com/lists/mythtv/dev/548233 but
it's probably the way I'm using the bindings.

[Mark]  Thanks again for your response, it has given me much to think about
which is far better than staring at the screen and scratching my head.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.mythtv.org/pipermail/mythtv-users/attachments/20130912/debe858b/attachment.html>