mm2 does not always reconnect electrums

[cipig]

Sometimes mm2 looses connection to all electrums and does not reconnect (electrums need to be restarted regularly and this happens on tuesday with cron).
I then get errors like this:
20 10:21:33, rpc:300] ERROR RPC error response: rpc:253] lp_ordermatch:3202] utxo_common:1999] utxo_common:175] JsonRpcError { client_info: "coin: DOGE", request: JsonRpcRequest { jsonrpc: "2.0", id: "768629", method: "blockchain.relayfee", params: [] }, error: Transport("rpc_clients:1210] All electrums are currently disconnected") }
In the meantime all 3 electrums are back online, but mm2 does not try to connect to them. Strange is that it does not happen with all coins, so hard to reproduce. Restart of mm2 "fixes" the problem.

[artemii235]

@cipig Thanks for opening the issue! Do you still have MM2 logs related to this problem? It's interesting to see what happens before and after the
20 10:21:33, rpc:300] ERROR RPC error response: rpc:253] lp_ordermatch:3202] utxo_common:1999] utxo_common:175] JsonRpcError { client_info: "coin: DOGE", request: JsonRpcRequest { jsonrpc: "2.0", id: "768629", method: "blockchain.relayfee", params: [] }, error: Transport("rpc_clients:1210] All electrums are currently disconnected") }

[cipig]

yes, i still have the logs... this is how it started

20 04:00:01, rpc_clients:1906] EOF fromelectrum1.cipig.net:10060
20 04:00:01, rpc_clients:1943] "electrum1.cipig.net:10060" connection dropped
20 04:00:01, rpc_clients:1879] "electrum1.cipig.net:10060" error Os { code: 111, kind: ConnectionRefused, message: "Connection refused" }
20 04:00:06, rpc_clients:1879] "electrum1.cipig.net:10060" error Os { code: 111, kind: ConnectionRefused, message: "Connection refused" }
20 04:00:15, utxo:1220] Electrum servers [ElectrumRpcRequest { url: "electrum1.cipig.net:10060", protocol: TCP, disable_cert_verification: false }, ElectrumRpcRequest { url: "electrum2.cipig.net:10060", protocol: TCP, disable_cert_verification: false }, ElectrumRpcRequest { url: "electrum3.cipig.net:10060", protocol: TCP, disable_cert_verification: false }] ping error JsonRpcError { client_info: "coin: DOGE", request: JsonRpcRequest { jsonrpc: "2.0", id: "747603", method: "server.ping", params: [] }, error: Transport("rpc_clients:1210] All electrums are currently disconnected") }
20 04:00:16, rpc_clients:1879] "electrum1.cipig.net:10060" error Os { code: 111, kind: ConnectionRefused, message: "Connection refused" }
20 04:07:15, utxo:1220] Electrum servers [ElectrumRpcRequest { url: "electrum1.cipig.net:10060", protocol: TCP, disable_cert_verification: false }, ElectrumRpcRequest { url: "electrum2.cipig.net:10060", protocol: TCP, disable_cert_verification: false }, ElectrumRpcRequest { url: "electrum3.cipig.net:10060", protocol: TCP, disable_cert_verification: false }] ping error JsonRpcError { client_info: "coin: DOGE", request: JsonRpcRequest { jsonrpc: "2.0", id: "747983", method: "server.ping", params: [] }, error: Transport("rpc_clients:1210] All electrums are currently disconnected") }

after this point in time there are no more Connection refused errors, only the All electrums are currently disconnected
the DOGE electrums are restarted like this
electrum1 tuesday 04:00 UTC
electrum2 tuesday 12:00 UTC
electrum3 tuesday 20:00 UTC
the restart takes couple minutes with DOGE...

[cipig]

new insights... mm2 does reconnect to the electrums, but some of them, like DOGE and DGB (related to size of chain) take longer to be fully responsive after a restart, so this happens:

27 20:03:16, rpc_clients:1883] Electrum client connected to electrum3.cipig.net:10060
27 20:04:16, rpc_clients:1831] Didn't receive any data since 1619553796. Shutting down the connection.
27 20:04:16, rpc_clients:1943] "electrum3.cipig.net:10060" connection dropped
27 20:04:16, utxo:1263] Electrum electrum3.cipig.net:10060 server.version error "JsonRpcError { client_info: "coin: DOGE", request: JsonRpcRequest { jsonrpc: "2.0", id: "73452", method: "server.version", params: [String("mpm GUI/MM2 1e08d3d9b"), Array([String("1.2"), String("1.4")])] }, error: Transport("rpc_clients:1253] rpc_clients:2027] common:1411] future timed out") }". Remove the connection

so after electrumx server was stopped and later restarted, mm2 reconnected but future timed out 60s later because the server was not yet fully ready... and when it does this for all 3 electrums (they are restarted on same day, but with couple hours distance), the result is All electrums are currently disconnected later

can mm2 simply wait a bit longer after first server.ping till it tries to actually reconnect to those electrums? maybe 60s?

[shamardy]

this is related to this https://github.com/KomodoPlatform/atomicDEX-API/blob/4fbe21e74d20ed197e51d8d080377b7623092162/mm2src/coins/utxo/rpc_clients.rs#L1824
so when mm2 doesn't receive data from the electrum for 60s it shuts down the connection. An easy solution is to change the value to be a little bit longer like you suggested or even make the value configurable depending on the electrum. I don't know why 60s was chosen so I think we need @artemii235 help on this.

[shamardy]

It has been changed from 10s to 60s before here #286 with consideration that it can be increased later.

[artemii235]

The most important log is 27 20:04:16, utxo:1263] Electrum electrum3.cipig.net:10060 server.version error "JsonRpcError { client_info: "coin: DOGE", request: JsonRpcRequest { jsonrpc: "2.0", id: "73452", method: "server.version", params: [String("mpm GUI/MM2 1e08d3d9b"), Array([String("1.2"), String("1.4")])] }, error: Transport("rpc_clients:1253] rpc_clients:2027] common:1411] future timed out") }". Remove the connection.

MM2 drops the connection completely if it can't negotiate the version. I'm a bit unsure if we should do something about it in MM2 - it's better to ensure that the Electrum server is fully responsive before it starts listening for connections.

[cipig]

MM2 drops the connection completely if it can't negotiate the version. I'm a bit unsure if we should do something about it in MM2 - it's better to ensure that the Electrum server is fully responsive before it starts listening for connections.

You are right, it is actually a bug in electrumx because it starts listening on the port too early after a start/restart. This problem will go away indirectly after spesmilo/electrumx#101 is merged and we update, because then i will not need to restart the electrums once a week any more

[artemii235]

Raising the priority as it seems to become a problem that requires MM2 restart or coin reactivation. We can at least stop dropping the connection entirely if the server.version request times out.

[cipig]

We can at least stop dropping the connection entirely if the server.version request times out.

that would be good... simply keep all configured electrums in the list and retry periodically to reach them
atm mm2 removes servers from the list on timeouts, but keeps eg those that drop my connection right away:
04 14:34:42, coins:rpc_clients:1965] ERROR "electrumx1.monacoin.ninja:50001" error Os { code: 101, kind: Other, message: "Network is unreachable" }
i see this message all the time, since electrumx1.monacoin.ninja blocked my home IP forever, other nodes can access it