Opened 6 years ago

Closed 6 years ago

Last modified 6 years ago

#11777 closed Bug Report - General (fixed)

Frontend stops receiving Events from backend

Reported by: stuartm Owned by: stuartm
Priority: blocker Milestone: 0.27.1
Component: MythTV - General Version: Master Head
Severity: high Keywords:
Cc: Ticket locked: no

Description (last modified by stuartm)

This has been a issue for a while in master.

After a period of use the frontend no longer receives any events from the backend. It's as though it loses the event socket connection and doesn't try to re-establish it.

This manifests in the frontend not updating filesizes for in-progress recordings; failing to displaying new recordings or changes in recording status in the recording list; the guide not updating to reflect recording status after creating a new schedules. i.e. Any update in the frontend driven by a backend event fails to occur.

You can still use the frontend. Exiting and re-entering playbackbox causes the recording list to be reloaded but the issue with events isn't resolved unless you restart the frontend.

Change History (12)

comment:1 Changed 6 years ago by stuartm

Description: modified (diff)

comment:2 Changed 6 years ago by stuartm

Priority: majorcritical
Severity: mediumhigh

comment:3 Changed 6 years ago by stuartm

Priority: criticalblocker

I thought I was the only one seeing this, but Mario Limonciello (aka Superm - Ubuntu Packager) has reported seeing it too.

Consequently I'm postponing the release another 24-48 hours in the hope that we can fix this first. It has more than visual consequences, playback of in-progress recordings doesn't work properly because the seektable/duration updates aren't received.

comment:4 Changed 6 years ago by stuartm

A backtrace from Mario shows nothing of interest, there are no deadlocks and no sign that it's getting stuck somewhere in the event handling or socket code. At this point it's looking like a socket issue, possibly the event socket failing to reconnect if the control socket is maintained?

http://paste.ubuntu.com/6121211/

Last edited 6 years ago by stuartm (previous) (diff)

comment:5 Changed 6 years ago by Stuart Morgan <smorgan@…>

In fdd8f784a7774ad873992ea9d66e2645ae694c14/mythtv:

Fix event socket reconnections. Refs #11777

SafeConnectToMaster?() needlessly checked whether the control socket
was connected before calling ConnectToMasterServer?(). This broken
reconnection of the event socket in the event that the control socket
had remained connected.

This doesn't fix the root cause of #11777 but it should eventually
allow the frontend to recover.

comment:6 Changed 6 years ago by Stuart Morgan <smorgan@…>

In 914a7c60023bf4497731b563e3d690846f78e6a9/mythtv:

Fix event socket reconnections. Refs #11777

SafeConnectToMaster?() needlessly checked whether the control socket
was connected before calling ConnectToMasterServer?(). This broken
reconnection of the event socket in the event that the control socket
had remained connected.

This doesn't fix the root cause of #11777 but it should eventually
allow the frontend to recover.
(cherry picked from commit fdd8f784a7774ad873992ea9d66e2645ae694c14)

comment:7 Changed 6 years ago by Stuart Morgan <smorgan@…>

In cb8b4204808879e1e7205bdf900e89e71f3e08a2/mythtv:

Don't send ALLOW/BLOCK_SHUTDOWN on the event socket. Refs #11777

The event socket is a 'Monitor' connection it won't block shutdown so
there's nothing gained by sending these messages on it. Additionally
it's only ever used in conjunction with a control socket to the same
server (master) and we've just sent the message via that socket, so
it's redundant.

comment:8 Changed 6 years ago by stuartm

The underlying cause here seems to be a race condition.

Sep 17 18:19:46 mythfrontend[2409]: D MythSocketThread(-1) mythsocket.cpp:286 (CallReadyReadHandler) MythSocket(ffffffffabe25b10:60): calling m_callback->readyRead()
Sep 17 18:19:46 mythfrontend[2409]: I MythSocketThread(-1) mythsocket.cpp:908 (ReadStringListReal) MythSocket(ffffffffabe25b10:60): read  <- 60 2       OK
Sep 17 18:20:16 mythfrontend[2409]: E MythSocketThread(-1) mythsocket.cpp:776 (ReadStringListReal) MythSocket(ffffffffabe25b10:60): ReadStringList: Error, timed out after 30000 ms.
Sep 17 18:20:16 mythfrontend[2409]: D MythSocketThread(-1) mythsocket.cpp:265 (AboutToCloseHandler) MythSocket(fffffmythfrontend[2409]: D MythSocketThread(-1) mythsocket.cpp:258 (DisconnectHandler) MythSocket(ffffffffabe25b10:-1): calling m_callback->connectionClosed()
Sep 17 18:20:16 mythfrontend[2409]: N MythSocketThread(-1) mythcorecontext.cpp:1179 (connectionClosed) Event socket closed.  No connection to the backend.
Sep 17 18:20:16 mythfrontend[2409]: I MythSocketThread(-1) mythcorecontext.cpp:1240 (dispatch) MythEvent: BACKEND_SOCKETS_CLOSED

MythSocket::CallReadyReadHandler?() alludes to this possibility but in reverse:

    // Because the connection to this is a queued connection the
    // data may have already been read by the time this is called
    // so we check that there is still data to read before calling
    // the callback.

So what happens is this: SendReceiveStringList?() is called with ALLOW_SHUTDOWN, before it can read the reply the readRead() callback is triggered by the QTCPSocket readyRead() signal, the callback then reads the result, leaving zero bytes available for SendReceiveStringList?() which waits 30 seconds for data which isn't coming before it times out and closes the socket.

The problem is that an Event socket, which uses the callbacks, shouldn't be used by SendRecieveStringList?() and the specific instance in this log has now been fixed. A control socket does NOT use the callbacks and wouldn't be affected. There still needs to be a guard against this happening in the code, what I'm currently thinking about doing is checking whether the callbacks are set in SendReceiveStringList?() and throwing errors ("Programmer error") before returning without handling the request. However this may break something else so I'm uncertain of it's suitability for inclusion in 0.27.

comment:9 Changed 6 years ago by stuartm

Milestone: 0.270.27.1

comment:10 Changed 6 years ago by Stuart Morgan <smorgan@…>

Resolution: fixed
Status: newclosed

In 836eb11d96abfaa5986e7382103db69769b0ae47/mythtv:

Prevent the use of SendReceiveStringList?() on a socket with callbacks. Fixes #11777

comment:11 Changed 6 years ago by Stuart Morgan <smorgan@…>

In 6965146ec7a344aab5e9b1bc0ed8d631e740db57/mythtv:

Don't send ALLOW/BLOCK_SHUTDOWN on the event socket. Refs #11777

The event socket is a 'Monitor' connection it won't block shutdown so
there's nothing gained by sending these messages on it. Additionally
it's only ever used in conjunction with a control socket to the same
server (master) and we've just sent the message via that socket, so
it's redundant.
(cherry picked from commit cb8b4204808879e1e7205bdf900e89e71f3e08a2)

comment:12 Changed 6 years ago by Stuart Morgan <smorgan@…>

In 0095fd137188545ec18faa4116861fd524cbe81b/mythtv:

Prevent the use of SendReceiveStringList?() on a socket with callbacks. Fixes #11777
(cherry picked from commit 836eb11d96abfaa5986e7382103db69769b0ae47)

Note: See TracTickets for help on using tickets.