[urgent] multiple users can't register identity, or connection problems

[cvl]

Describe the bug 3+ users reported same or similar errors. Registration is taking place forever or says "can't get app to work".

Logs: mysterium-node.log mysterium-node.log

Note: Those identities were added to pilvytis right after registration. They're in the list of registered identities, yet when I try to fetch the balance, it says: Exception: Request failed for https://testnet2-hermes.mysterium.network returned code 500. Truncated server response: {"cause":"internal error","message":"consumer unregistered: internal error","data":""} (use muteHttpExceptions option to examine full response)

There's clearly a bug in pilvytis api. I've turned off adding to pilvytis for now. Is this related?

Environment (please complete the following information):

• Node version: 0.46.1
• OS: Windows 10

[cvl]

One more, android this time: mysterium-node.log

CC: @vkuznecovas

[tomasmik]

There's clearly a bug in pilvytis api. I've turned off adding to pilvytis for now. Is this related?

I see no offchain balances added from your side in pilvytis, so I assume you've added them to the old V1 endpoints. In that case pilvytis has absolutely nothing to do with this.

The past few days we've had numerous issues with registrations because of a few transaction bugs + insane jump in gas price in Goerli. Those issues are mostly fixed and we should be going back to normal. Some registrations that have failed during this time were dropped forever and clients should re-register. @vkuznecovas could give more in depth information if needed.

[cvl]

Anything I can do on my side? I'm losing customers by hour.

[cvl]

I've just tried to register failed to register identity:

• On first app launch I got "2021-05-21T13:26:58.089 ERR source/identity/registry/registry_contract.go:113 > failed to contact hermes to get new registration status error="could not request consumer data from hermes: internal error" status=Unregistered"

Then on second launch, it worked (although still throws 2021-05-21T13:28:04.506 ERR source/session/pingpong/consumer_balance_tracker.go:144 > Could not recover Grand Total Promised error="could not request consumer data from hermes: internal error") but it works after second launch.

[cvl]

Something strange is happening. App doesn't get into connecting state, says 2021-05-21T13:30:36.459 DBG source/eventbus/event_bus.go:81 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x2bd49cae49ffe35a0acd8dbbe47d1d18c42ab4ba ConsumerID:0x9ceac2f7218da1e9af92ef835ca781f25a592fba HermesID:0xD5d2f5729D4581dfacEBedF46C7014DeFda43585 Error: Stage:registration_in_progress}

when connecting. Connects then (no indication of connecting state).

[cvl]

Connection lost after 30 seconds

2021-05-21T13:31:49.366 DBG source/config/config.go:196 > Returning default value default-currency:MYSTT 2021-05-21T13:31:49.366 INF source/cmd/di.go:932 > Reconnecting HTTP clients due to VPN connection state change 2021-05-21T13:31:49.366 INF source/core/state/state.go:404 > Session ID: , state: NotConnected, duration: 59.522114249s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYSTT 2021-05-21T13:31:49.403 DBG source/eventbus/event_bus.go:81 > Published topic="Trace" event={ID: Key:Consumer whole Connect Duration:1m12.872553001s} 2021-05-21T13:31:49.403 DBG source/eventbus/event_bus.go:81 > Published topic="Trace" event={ID: Key:Consumer P2P channel creation Duration:939.903394ms} 2021-05-21T13:31:49.403 WRN source/core/quality/sender.go:344 > Can't recover session context error="unknown session: " 2021-05-21T13:31:49.403 DBG source/eventbus/event_bus.go:81 > Published topic="Trace" event={ID: Key:Consumer P2P connect Duration:287.305951ms} 2021-05-21T13:31:49.403 WRN source/core/quality/sender.go:344 > Can't recover session context error="unknown session: " 2021-05-21T13:31:49.403 DBG source/eventbus/event_bus.go:81 > Published topic="Trace" event={ID: Key:Consumer P2P exchange Duration:471.679701ms} 2021-05-21T13:31:49.403 WRN source/core/quality/sender.go:344 > Can't recover session context error="unknown session: " 2021-05-21T13:31:49.403 DBG source/eventbus/event_bus.go:81 > Published topic="Trace" event={ID: Key:Consumer P2P exchange (ports) Duration:335.161µs} 2021-05-21T13:31:49.403 WRN source/core/quality/sender.go:344 > Can't recover session context error="unknown session: " 2021-05-21T13:31:49.404 DBG source/eventbus/event_bus.go:81 > Published topic="Trace" event={ID: Key:Consumer P2P exchange ack Duration:178.639757ms} 2021-05-21T13:31:49.404 WRN source/core/quality/sender.go:344 > Can't recover session context error="unknown session: " 2021-05-21T13:31:49.404 DBG source/eventbus/event_bus.go:81 > Published topic="Trace" event={ID: Key:Consumer P2P dial (upnp) Duration:416.138µs} 2021-05-21T13:31:49.404 WRN source/core/quality/sender.go:344 > Can't recover session context error="unknown session: " 2021-05-21T13:31:49.404 DBG source/eventbus/event_bus.go:81 > Published topic="Trace" event={ID: Key:Consumer P2P dial ack Duration:617.015µs} 2021-05-21T13:31:49.404 WRN source/core/quality/sender.go:344 > Can't recover session context error="unknown session: " 2021-05-21T13:31:49.404 DBG source/eventbus/event_bus.go:81 > Published topic="Trace" event={ID: Key:Consumer session creation Duration:20.000666593s} 2021-05-21T13:31:49.404 WRN source/core/quality/sender.go:344 > Can't recover session context error="unknown session: " 2021-05-21T13:31:49.404 DBG source/core/connection/manager.go:192 > Consumer connection trace: "Consumer whole Connect" took 1m12.872553001s, "Consumer P2P channel creation" took 939.903394ms, "Consumer P2P connect" took 287.305951ms, "Consumer P2P exchange" took 471.679701ms, "Consumer P2P exchange (ports)" took 335.161µs, "Consumer P2P exchange ack" took 178.639757ms, "Consumer P2P dial (upnp)" took 416.138µs, "Consumer P2P dial ack" took 617.015µs, "Consumer session creation" took 20.000666593s 2021-05-21T13:31:49.404 WRN source/core/quality/sender.go:344 > Can't recover session context error="unknown session: " 2021-05-21T13:31:49.404 DBG source/eventbus/event_bus.go:81 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x2bd49cae49ffe35a0acd8dbbe47d1d18c42ab4ba ConsumerID:0x9ceac2f7218da1e9af92ef835ca781f25a592fba HermesID:0xD5d2f5729D4581dfacEBedF46C7014DeFda43585 Error:could not send p2p session create request: timeout waiting for reply to "p2p-session-create": p2p send timeout Stage:connection_unknown_error} 2021-05-21T13:31:49.404 ERR source/tequilapi/endpoints/connection.go:221 > Failed to connect error="could not send p2p session create request: timeout waiting for reply to \"p2p-session-create\": p2p send timeout" 2021-05-21T13:31:50.003 DBG source/eventbus/event_bus.go:81 > Published topic="ether-client-reconnect" event={} 2021-05-21T13:31:50.003 DBG source/identity/registry/registry_contract.go:331 > Loading initial state 2021-05-21T13:31:50.182 INF source/session/pingpong/consumer_balance_tracker.go:219 > Subscribed to channel 0x0c652E4055F56220aCb1A4069fE36C9b3B0011cB balance events 2021-05-21T13:31:50.215 INF source/identity/registry/registry_contract.go:232 > Waiting on identities 0x61149596d0CcE1DE5F4Ee6Ac2fBE2B465Bc2eCe4 hermes 0xD5d2f5729D4581dfacEBedF46C7014DeFda43585 2021-05-21T13:31:50.406 INF source/identity/registry/registry_contract.go:232 > Waiting on identities 0x9cEaC2f7218dA1e9AF92Ef835CA781f25A592fBA hermes 0xD5d2f5729D4581dfacEBedF46C7014DeFda43585 2021-05-21T13:31:51.693 DBG source/core/discovery/repository.go:61 > Retrieving proposals from 3 repositories 2021-05-21T13:31:52.222 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 1404 supported: 1404 2021-05-21T13:31:52.224 INF source/core/discovery/repository.go:91 > Returning 1620 unique proposals 2021-05-21T13:32:01.694 DBG source/core/discovery/repository.go:61 > Retrieving proposals from 3 repositories 2021-05-21T13:32:02.011 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 1404 supported: 1404 2021-05-21T13:32:02.013 INF source/core/discovery/repository.go:91 > Returning 1605 unique proposals 2021-05-21T13:32:09.367 ERR source/core/location/cache.go:102 > Location update failed error="failed to execute request: Get https://testnet2-location.mysterium.network/api/v1/location: net/http: request canceled (Client.Timeout exceeded while awaiting headers)" 2021-05-21T13:32:10.275 WRN source/communication/nats/connection_wrap.go:95 > NATS: disconnected 2021-05-21T13:32:10.627 WRN source/communication/nats/connection_wrap.go:96 > NATS: reconnected

[cvl]

2021-05-21T14:10:12.557 ERR source/identity/registry/registry_contract.go:113 > failed to contact hermes to get new registration status error="could not request consumer data from hermes: could not unmarshal error body: invalid character 'B' after top-level value" status=Unregistered

[tomasmik]

As this was mostly probably due to the transactor/hermes outages and you're now moving to offchain I will close this.