mysteriumnetwork / node

Mysterium Network Node - official implementation of distributed VPN network (dVPN) protocol
https://mysterium.network
GNU General Public License v3.0
1.11k stars 311 forks source link

Fatal error for provider identity registrar. Identity will not be registered. #4470

Closed roiliani closed 2 years ago

roiliani commented 2 years ago

Node fails to register, UI shows the following message: image

In log file I see that the node registration has failed: 2021-12-10T13:04:36.239 INF core/discovery/discovery.go:242 > Identity 0x1fa6f349afa0125faea1074f3e6d7f74386744ec not registered, delaying proposal registration until identity is registered 2021-12-10T13:04:36.239 INF core/discovery/discovery.go:181 > Waiting for registration success event 2021-12-10T13:04:36.441 INF identity/registry/provider_registrar.go:203 > Provider "0x1fa6f349afa0125faea1074f3e6d7f74386744ec" not registered on BC, will check if elgible for auto-registration 2021-12-10T13:04:36.562 INF session/pingpong/hermes_promise_settler.go:185 > Provider {0x1fa6f349afa0125faea1074f3e6d7f74386744ec} not registered, skipping 2021-12-10T13:04:37.395 DBG core/location/oracle_resolver.go:64 > Detecting with oracle resolver 2021-12-10T13:04:38.262 DBG eventbus/event_bus.go:81 > Published topic="location-update-event" event={IP:158.101.43.168 ASN:31898 ISP:Oracle Cloud Continent:NA Country:US City:Arizona IPType:hosting} 2021-12-10T13:04:38.269 WRN session/pingpong/consumer_balance_tracker.go:475 > Could not get consumer channel error="no contract code at given address" 2021-12-10T13:04:38.404 DBG eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0x1fa6f349afa0125faea1074f3e6d7f74386744ec} Previous:+0 Current:+253762701464500000} 2021-12-10T13:04:39.212 ERR identity/registry/provider_registrar.go:264 > Registration failed for provider "0x1fa6f349afa0125faea1074f3e6d7f74386744ec" error="server response invalid: 400 Bad Request (https://transactor.mysterium.network/api/v1/identity/register/provider){\"error\":\"registration in progress\"}" 2021-12-10T13:04:39.212 ERR identity/registry/provider_registrar.go:124 > Fatal error for provider identity registrar. Identity will not be registered. Please restart your node. error="max attempts reached for provider registration: could not register identity on BC: server response invalid: 400 Bad Request (https://transactor.mysterium.network/api/v1/identity/register/provider){\"error\":\"registration in progress\"}" 2021-12-10T13:04:39.523 DBG eventbus/event_bus.go:81 > Published topic="NAT-type-detected" event=fullcone 2021-12-10T14:04:37.284 WRN session/pingpong/consumer_balance_tracker.go:475 > Could not get consumer channel error="no contract code at given address" 2021-12-10T14:04:37.432 DBG eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0x1fa6f349afa0125faea1074f3e6d7f74386744ec} Previous:+0 Current:+253762701464500000} 2021-12-10T14:59:35.391 ERR pilvytis/order_status_tracker.go:142 > Could not update orders error="Get \"https://pilvytis.mysterium.network/api/v1/payment/orders\": net/http: request canceled (Client.Timeout exceeded while awaiting headers)" identity=0x1fa6f349afa0125faea1074f3e6d7f74386744ec 2021-12-10T15:02:08.167 ERR pilvytis/order_status_tracker.go:142 > Could not update orders error="Get \"https://pilvytis.mysterium.network/api/v1/payment/orders\": net/http: request canceled (Client.Timeout exceeded while awaiting headers)" identity=0x1fa6f349afa0125faea1074f3e6d7f74386744ec 2021-12-10T15:04:38.639 WRN session/pingpong/consumer_balance_tracker.go:475 > Could not get consumer channel error="no contract code at given address" 2021-12-10T15:04:38.787 DBG eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0x1fa6f349afa0125faea1074f3e6d7f74386744ec} Previous:+0 Current:+253762701464500000} mysterium-node.log

etherunit commented 2 years ago

@roiliani I see that both attempts to be registered has failed https://transactor.mysterium.network/api/v1/identity/0x1fa6f349afa0125faea1074f3e6d7f74386744ec/status We had restarted our transactor instances. Can you please try it now?

roiliani commented 2 years ago

I've restarted the node, and it still stuck on "Your identity is being registered, please be patient..."

This is what I see in the log file: 2021-12-14T07:48:07.622 DBG mmn/client.go:56 > Registering node to MMN: {LocalIP:10.0.0.95 Identity:0x1fa6f349afa0125faea1074f3e6d7f74386744ec APIKey:Pv5rmxq3ixQv41UbSHTs9vVo4pG7nAeomi4vzKNz VendorID: OS:Ubuntu 20.04.3 LTS Arch:linux/arm64 NodeVersion:1.0.12} 2021-12-14T07:48:07.624 DBG eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0x1fa6f349afa0125faea1074f3e6d7f74386744ec} Previous:+0 Current:+253762701464500000} 2021-12-14T07:48:08.361 INF core/discovery/discovery.go:242 > Identity 0x1fa6f349afa0125faea1074f3e6d7f74386744ec not registered, delaying proposal registration until identity is registered 2021-12-14T07:48:08.362 INF core/discovery/discovery.go:181 > Waiting for registration success event 2021-12-14T07:48:08.449 INF session/pingpong/hermes_promise_settler.go:185 > Provider {0x1fa6f349afa0125faea1074f3e6d7f74386744ec} not registered, skipping 2021-12-14T07:48:08.607 INF identity/registry/provider_registrar.go:203 > Provider "0x1fa6f349afa0125faea1074f3e6d7f74386744ec" not registered on BC, will check if elgible for auto-registration 2021-12-14T07:48:10.316 INF identity/registry/provider_registrar.go:246 > provider "0x1fa6f349afa0125faea1074f3e6d7f74386744ec" not elgible for auto-registration 2021-12-14T07:50:25.817 DBG config/config.go:220 > Returning user config value terms.provider-agreed:true 2021-12-14T07:50:25.818 DBG config/config.go:220 > Returning user config value terms.consumer-agreed:true 2021-12-14T07:50:25.818 DBG config/config.go:220 > Returning user config value terms.version:0.0.34 2021-12-14T07:50:25.857 DBG identity/selector/handler.go:98 > Attempting to use last identity 2021-12-14T07:50:25.858 DBG identity/selector/handler.go:103 > Found identity in cache: 0x1fa6f349afa0125faea1074f3e6d7f74386744ec 2021-12-14T07:50:25.858 DBG identity/manager.go:153 > Unlocked identity found in cache, skipping keystore: 0x1fa6f349afa0125faea1074f3e6d7f74386744ec 2021-12-14T07:50:25.859 DBG identity/selector/handler.go:108 > Unlocked identity: 0x1fa6f349afa0125faea1074f3e6d7f74386744ec 2021-12-14T07:50:28.611 DBG core/location/oracle_resolver.go:64 > Detecting with oracle resolver 2021-12-14T07:50:29.427 WRN session/pingpong/consumer_balance_tracker.go:475 > Could not get consumer channel error="no contract code at given address" 2021-12-14T07:50:29.541 DBG eventbus/event_bus.go:81 > Published topic="location-update-event" event={IP:158.101.43.168 ASN:31898 ISP:Oracle Cloud Continent:NA Country:US City:Arizona IPType:hosting} 2021-12-14T07:50:29.582 DBG eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0x1fa6f349afa0125faea1074f3e6d7f74386744ec} Previous:+0 Current:+253762701464500000} 2021-12-14T07:50:29.981 INF session/pingpong/pricing.go:177 > pricing info loaded. expires @ 2021-12-14 07:54:15.726179248 +0000 UTC 2021-12-14T07:50:30.847 DBG eventbus/event_bus.go:81 > Published topic="NAT-type-detected" event=fullcone

roiliani commented 2 years ago

Just an update on the issue.

I've updated to the latest version and that has solved the issue and now the node registers correctly.