[mythtv-users] ugraded to 0.29, cannot connect to backend

Fri May 25 19:33:41 UTC 2018

On 25/05/18 18:33, Greg Woods wrote:
> This issue has occurred on both a desktop frontend and a frontend 
> running on the BE system itself. When I fire up mythfrontend after the 
> upgrade, I get the display showing that it is trying to connect to the 
> backend, which eventually fails, as to any retries. As far as I can see, 
> connections to the DB are good; "netstat --tcp" shows several 
> connections from the frontend systems to the Mariadb server, and I can 
> also connect manually and poke around and it all looks good as far as I 
> can tell. I think the schema has already been upgraded, since I tried to 
> connect from a frontend still on 0.28 and got the screen saying that the 
> schema was not what was expected.
> 
> Is there something I can do to troubleshoot this? I've done lots of Myth 
> upgrades before (I started on 0.16) and haven't seen this particular 
> symptom.
> 
> I am running on Fedora 26, the full version number of the Myth packages is
> 29.1-17.19.20180510.g0849e99596.fc26.x86_64. I have also completely 
> disabled the firewall on both the desktop and the BE system so that I 
> can rule out firewall issues. In the setup, the DB host was set to the 
> IP address of the BE. I tried using the hostname, but that made no 
> difference (no surprise there since the DB connections look OK).
> 
> Here's the tail of the FE log:
> 
> 
> 2018-05-25 11:27:07.185346 I  Start up testing connections. DB 
> mongoliad.gregandeva.net <http://mongoliad.gregandeva.net>, BE , attempt 
> 2, status beAwake
> 2018-05-25 11:27:12.202041 I  Start up testing connections. DB 
> mongoliad.gregandeva.net <http://mongoliad.gregandeva.net>, BE , attempt 
> 3, status beAwake
> 2018-05-25 11:27:17.216581 I  Start up testing connections. DB 
> mongoliad.gregandeva.net <http://mongoliad.gregandeva.net>, BE , attempt 
> 4, status beAwake
> 2018-05-25 11:27:22.229820 I  Start up testing connections. DB 
> mongoliad.gregandeva.net <http://mongoliad.gregandeva.net>, BE , attempt 
> 5, status beAwake
> 2018-05-25 11:27:27.244218 I  Start up testing connections. DB 
> mongoliad.gregandeva.net <http://mongoliad.gregandeva.net>, BE , attempt 
> 6, status beAwake
> 2018-05-25 11:27:32.263358 I  Start up testing connections. DB 
> mongoliad.gregandeva.net <http://mongoliad.gregandeva.net>, BE , attempt 
> 7, status beAwake
> 2018-05-25 11:27:37.284150 I  Start up testing connections. DB 
> mongoliad.gregandeva.net <http://mongoliad.gregandeva.net>, BE , attempt 
> 8, status beAwake
> 2018-05-25 11:27:42.297133 I  Start up testing connections. DB 
> mongoliad.gregandeva.net <http://mongoliad.gregandeva.net>, BE , attempt 
> 9, status beAwake
> 2018-05-25 11:27:47.310539 I  Start up testing connections. DB 
> mongoliad.gregandeva.net <http://mongoliad.gregandeva.net>, BE , attempt 
> 10, status beAwake
> 2018-05-25 11:27:52.325031 I  Start up failure. host 
> mongoliad.gregandeva.net <http://mongoliad.gregandeva.net>, status 
> beAwakeFail
> 
> Here is the tail of the BE log:
> 
> 2018-05-25 11:26:26.886773 E [23866/24604] MythSocketThread(-1) 
> mythsocket.cpp:827 (ReadStringListReal) - MythSocket(20d8010:214):
> ReadStringList: Error, timed out after 30000 ms.
> 2018-05-25 11:26:26.886896 W [23866/24604] MythSocketThread(-1) 
> mainserver.cpp:7704 (connectionClosed) - MainServer: Unknown socket
>   closing MythSocket(0x20d8010)
> 2018-05-25 11:26:26.887006 E [23866/23866] CoreContext 
> mythsocket.cpp:369 (SendReceiveStringList) - MythSocket(20d8010:-1): No resp
> onse.
> 2018-05-25 11:26:26.887021 E [23866/23866] CoreContext 
> mainserver.cpp:8040 (reconnectTimeout) - MainServer: Failed to open master s
> erver socket, timeout
> 2018-05-25 11:26:26.887896 I [23866/24609] MythSocketThread(215) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20df930) dis
> connected
> 2018-05-25 11:26:26.887960 I [23866/24608] MythSocketThread(214) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20dcf20) dis
> connected
> 2018-05-25 11:26:26.888101 I [23866/24610] MythSocketThread(217) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20e07c0) disconnected
> 2018-05-25 11:26:26.888328 C [23866/23906] ProcessRequest 
> mainserver.cpp:1614 (HandleVersion) - MainServer: 
> MainServer::HandleVersion - Client speaks protocol version 88 but we 
> speak 91!
> 2018-05-25 11:26:26.888548 I [23866/24611] MythSocketThread(219) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20e16e0) disconnected
> 2018-05-25 11:26:27.862295 N [23866/23866] CoreContext 
> mainserver.cpp:7991 (reconnectTimeout) - MainServer: Connecting to 
> master server: 192.168.1.33:6543 <http://192.168.1.33:6543>
> 2018-05-25 11:26:27.862820 N [23866/23866] CoreContext 
> mainserver.cpp:8002 (reconnectTimeout) - MainServer: Connected successfully
> 2018-05-25 11:26:57.886824 E [23866/24612] MythSocketThread(-1) 
> mythsocket.cpp:827 (ReadStringListReal) - MythSocket(20ddb90:217): 
> ReadStringList: Error, timed out after 30000 ms.
> 2018-05-25 11:26:57.886943 W [23866/24612] MythSocketThread(-1) 
> mainserver.cpp:7704 (connectionClosed) - MainServer: Unknown socket 
> closing MythSocket(0x20ddb90)
> 2018-05-25 11:26:57.887052 E [23866/23866] CoreContext 
> mythsocket.cpp:369 (SendReceiveStringList) - MythSocket(20ddb90:-1): No 
> response.
> 2018-05-25 11:26:57.887067 E [23866/23866] CoreContext 
> mainserver.cpp:8040 (reconnectTimeout) - MainServer: Failed to open 
> master server socket, timeout
> 2018-05-25 11:26:57.888022 I [23866/24618] MythSocketThread(217) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20db0a0) disconnected
> 2018-05-25 11:26:57.888107 I [23866/24619] MythSocketThread(219) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20e38b0) disconnected
> 2018-05-25 11:26:57.888199 I [23866/24620] MythSocketThread(222) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20e46b0) disconnected
> 2018-05-25 11:26:57.888606 C [23866/23906] ProcessRequest 
> mainserver.cpp:1614 (HandleVersion) - MainServer: 
> MainServer::HandleVersion - Client speaks protocol version 88 but we 
> speak 91!
> 2018-05-25 11:26:57.888904 I [23866/24621] MythSocketThread(224) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20e54e0) disconnected
> 2018-05-25 11:26:58.862398 N [23866/23866] CoreContext 
> mainserver.cpp:7991 (reconnectTimeout) - MainServer: Connecting to 
> master server: 192.168.1.33:6543 <http://192.168.1.33:6543>
> 2018-05-25 11:26:58.862925 N [23866/23866] CoreContext 
> mainserver.cpp:8002 (reconnectTimeout) - MainServer: Connected successfully
> 2018-05-25 11:27:28.886960 E [23866/24622] MythSocketThread(-1) 
> mythsocket.cpp:827 (ReadStringListReal) - MythSocket(20dfed0:222): 
> ReadStringList: Error, timed out after 30000 ms.
> 2018-05-25 11:27:28.887081 W [23866/24622] MythSocketThread(-1) 
> mainserver.cpp:7704 (connectionClosed) - MainServer: Unknown socket 
> closing MythSocket(0x20dfed0)
> 2018-05-25 11:27:28.887191 E [23866/23866] CoreContext 
> mythsocket.cpp:369 (SendReceiveStringList) - MythSocket(20dfed0:-1): No 
> response.
> 2018-05-25 11:27:28.887206 E [23866/23866] CoreContext 
> mainserver.cpp:8040 (reconnectTimeout) - MainServer: Failed to open 
> master server socket, timeout
> 2018-05-25 11:27:28.888300 I [23866/24626] MythSocketThread(222) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20e0b70) disconnected
> 2018-05-25 11:27:28.888365 I [23866/24627] MythSocketThread(224) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20e7640) disconnected
> 2018-05-25 11:27:28.888411 I [23866/24628] MythSocketThread(227) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20e8430) disconnected
> 2018-05-25 11:27:28.888785 C [23866/24548] ProcessRequest 
> mainserver.cpp:1614 (HandleVersion) - MainServer: 
> MainServer::HandleVersion - Client speaks protocol version 88 but we 
> speak 91!
> 2018-05-25 11:27:28.889044 I [23866/24629] MythSocketThread(229) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20ec470) disconnected
> 2018-05-25 11:27:29.862612 N [23866/23866] CoreContext 
> mainserver.cpp:7991 (reconnectTimeout) - MainServer: Connecting to 
> master server: 192.168.1.33:6543 <http://192.168.1.33:6543>
> 2018-05-25 11:27:29.863119 N [23866/23866] CoreContext 
> mainserver.cpp:8002 (reconnectTimeout) - MainServer: Connected successfully
> 2018-05-25 11:27:59.886704 E [23866/24630] MythSocketThread(-1) 
> mythsocket.cpp:827 (ReadStringListReal) - MythSocket(20e7990:229): 
> ReadStringList: Error, timed out after 30000 ms.
> 2018-05-25 11:27:59.886825 W [23866/24630] MythSocketThread(-1) 
> mainserver.cpp:7704 (connectionClosed) - MainServer: Unknown socket 
> closing MythSocket(0x20e7990)
> 2018-05-25 11:27:59.886934 E [23866/23866] CoreContext 
> mythsocket.cpp:369 (SendReceiveStringList) - MythSocket(20e7990:-1): No 
> response.
> 2018-05-25 11:27:59.886950 E [23866/23866] CoreContext 
> mainserver.cpp:8040 (reconnectTimeout) - MainServer: Failed to open 
> master server socket, timeout
> 2018-05-25 11:27:59.887970 I [23866/24636] MythSocketThread(229) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20e6380) disconnected
> 2018-05-25 11:27:59.888039 I [23866/24637] MythSocketThread(230) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20f1e50) disconnected
> 2018-05-25 11:27:59.888089 I [23866/24638] MythSocketThread(232) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(20f2d50) disconnected
> 2018-05-25 11:27:59.888326 I [23866/24639] MythSocketThread(229) 
> mainserver.cpp:7693 (connectionClosed) - Control sock(210cac0) disconnected
> 2018-05-25 11:28:00.862318 N [23866/23866] CoreContext 
> mainserver.cpp:7991 (reconnectTimeout) - MainServer: Connecting to 
> master server: 192.168.1.33:6543 <http://192.168.1.33:6543>
> 2018-05-25 11:28:00.862920 N [23866/23866] CoreContext 
> mainserver.cpp:8002 (reconnectTimeout) - MainServer: Connected successfully
> 
> Thanks,
> --Greg

The 'obvious' problem seems to me to be

> 2018-05-25 11:27:28.888785 C [23866/24548] ProcessRequest mainserver.cpp:1614 (HandleVersion) - MainServer: MainServer::HandleVersion - Client speaks protocol version 88 but we speak 91!

My frontend, recent master, has protocol 91.  It looks as if your 
upgrade didn't complete.

John  P