System clock is out of sync: system clock is out of sync with all trusted satellites

|2020-04-07 06:12:29|stderr|2020-04-07T06:12:29.442Z e[31mFATALe[0m failed preflight check {"error": "system clock is out of sync: system clock is out of sync with all trusted satellites", "errorVerbose": "system clock is out of sync: system clock is out of sync with all trusted satellites\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).Check:96\n\tstorj.io/storj/storagenode.(*Peer).Run:648\n\tmain.cmdRun:208\n\tstorj.io/storj/pkg/process.cleanup.func1.2:312\n\tstorj.io/storj/pkg/process.cleanup.func1:330\n\tgithub.com/spf13/cobra.(*Command).execute:826\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:914\n\tgithub.com/spf13/cobra.(*Command).Execute:864\n\tstorj.io/storj/pkg/process.ExecWithCustomConfig:84\n\tstorj.io/storj/pkg/process.ExecCustomDebug:66\n\tmain.main:328\n\truntime.main:203"}|
| --- | --- | --- |
|2020-04-07 06:12:29|stderr|2020-04-07T06:12:29.442Z e[31mERRORe[0m preflight:localtime unable to get satellite system time {"Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "error": "rpccompat: context deadline exceeded", "errorVerbose": "rpccompat: context deadline exceeded\n\tstorj.io/common/rpc.Dialer.dialTransport:256\n\tstorj.io/common/rpc.Dialer.dial:233\n\tstorj.io/common/rpc.Dialer.DialAddressID:152\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).getSatelliteTime:110\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).Check.func1:67\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}|
|2020-04-07 06:12:29|stderr|2020-04-07T06:12:29.418Z e[31mERRORe[0m preflight:localtime unable to get satellite system time {"Satellite ID": "118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW", "error": "rpccompat: context deadline exceeded", "errorVerbose": "rpccompat: context deadline exceeded\n\tstorj.io/common/rpc.Dialer.dialTransport:256\n\tstorj.io/common/rpc.Dialer.dial:233\n\tstorj.io/common/rpc.Dialer.DialAddressID:152\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).getSatelliteTime:110\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).Check.func1:67\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}|
|2020-04-07 06:12:29|stderr|2020-04-07T06:12:29.418Z e[31mERRORe[0m preflight:localtime unable to get satellite system time {"Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "error": "rpccompat: context deadline exceeded", "errorVerbose": "rpccompat: context deadline exceeded\n\tstorj.io/common/rpc.Dialer.dialTransport:256\n\tstorj.io/common/rpc.Dialer.dial:233\n\tstorj.io/common/rpc.Dialer.DialAddressID:152\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).getSatelliteTime:110\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).Check.func1:67\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}|
|2020-04-07 06:12:29|stderr|2020-04-07T06:12:29.419Z e[31mERRORe[0m preflight:localtime unable to get satellite system time {"Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "error": "rpccompat: context deadline exceeded", "errorVerbose": "rpccompat: context deadline exceeded\n\tstorj.io/common/rpc.Dialer.dialTransport:256\n\tstorj.io/common/rpc.Dialer.dial:233\n\tstorj.io/common/rpc.Dialer.DialAddressID:152\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).getSatelliteTime:110\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).Check.func1:67\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}|
|2020-04-07 06:12:29|stderr|2020-04-07T06:12:29.419Z e[31mERRORe[0m preflight:localtime unable to get satellite system time {"Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "error": "rpccompat: dial tcp 34.80.94.151:7777: i/o timeout", "errorVerbose": "rpccompat: dial tcp 34.80.94.151:7777: i/o timeout\n\tstorj.io/common/rpc.Dialer.dialTransport:256\n\tstorj.io/common/rpc.Dialer.dial:233\n\tstorj.io/common/rpc.Dialer.DialAddressID:152\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).getSatelliteTime:110\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).Check.func1:67\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}|
|2020-04-07 06:12:09|stderr|2020-04-07T06:12:09.395Z e[34mINFOe[0m preflight:localtime start checking local system clock with trusted satellites' system clock.|
|2020-04-07 06:12:06|stderr|2020-04-07T06:12:06.271Z e[34mINFOe[0m db.migration Database Version {"version": 33}|
|2020-04-07 06:12:02|stderr|2020-04-07T06:12:02.955Z e[34mINFOe[0m version running on version v1.0.1|
|2020-04-07 06:12:02|stderr|2020-04-07T06:12:02.265Z e[34mINFOe[0m operator wallet: |
|2020-04-07 06:12:02|stderr|2020-04-07T06:12:02.265Z e[34mINFOe[0m Operator email: mail@domain.com|
|2020-04-07 06:12:02|stderr|2020-04-07T06:12:02.255Z e[34mINFOe[0m Configuration loaded from: /app/config/config.yaml|

Can you confirm if your port is open ?

Is that how it works?!

Here is an idea: does the time that storagenode is logging match the time when it is happening? i.e. in docker logs -f storagenode is the time correct in those logs?
It looks like it logs in UTC or Zulu so mine is logging 2020-04-07T10:35:48.148Z at 11:35 (UTC+1)

That indicates you have a problem with your network and not with your system clock. If your system clock would be wrong you would see the offset here. Instead you get an error message that you couldn’t reach the satellite.

1 Like

then problem can be with dns resolver?

.INIT. does not mean you have a working NTP, in fact it means your NTP is broken

Had the same problem with Synology on time set up to auto (in sync with NTP servers), I tried to re-align but time on machine and satellites was skewed by timezone. I end up setting a time manually (which was the same value as auto…LOL) and it fixed the problem, there is some underlying cause for sure but as time set to manual was the same as auto and it let Storj to work I just let it go.

1 Like

Getting the same problem here.

  • I am running with docker on Linux
  • I was running with label “beta” that is not up to date, so I got a warning that my node was going to be blacklisted…
  • When I restarted the node: It was not accepting to start again, because beta label (the one suggested in the official documentation!) is now out of date!
  • watchtower was not acting (sounds logical, since beta label is stuck in version 1.0.1)
  • So I decided to go manual and took the latest version on Docker hub: storjlabs/storagenode:d73630fd-go1.13.8
  • Now I can’t start my node again: “system clock is out of sync: system clock is out of sync with all trusted satellites” (my server is on sync: ntpdate ntp.ubuntu.com gives “25 Apr 14:06:55 ntpdate[30816]: adjust time server 91.189.89.199 offset 0.000921 sec”)
  • I tried to roll back to the last tag in 1.3.3: I can’t, my db is in version 37, not in version 36 anymore.
  • So now, my node is going to be revoked because it’s off for a few hours.

Sorry, but I’m out. Setting up a node (and keeping it running) should be an easy task, not a task requiring hours. Having a node up&running is not profitable enough to require a few hours of engineering to put it up + human monitoring to keep it running. My suggestions for the future of your solution:

  • Keep a “latest” (not beta or whatever) label up to date.
  • The installation should be easy, with no maintenance required at all, and with critical alerts by email if a manual task is required (should never happen). For example:
    ** don’t have an external agent (watchtower) bound to docker socket (sic) checking for new versions: the node should update gracefully by itself if a new version is available.
    ** Provide whatever is required to restart the node if the server restarts.
  • Don’t push broken versions to the official repo: split your repository in two, with a promotion mechanism. I should not have been able to pull a broken image.

I wish you the best for the future, but it will be without me until you are able to provide an easy to install & maintain solution.
Best,
Simon

1 Like

The beta label is up to date with version v1.1.1.

Never ever do that unless you are prepared for a manual rollback your database.

Sounds like a network problem. You can see the difference in the logs. Is it failing because the node was unable to contact the satellite or is it failing because the clock offset is too high. The later would result in an offset printout.

You can downgrade your database manually. I would recommend reading this: https://github.com/storj/storj/blob/533a65a2996bed3b47870294825ba04af51be12b/storagenode/storagenodedb/database.go#L1197

For safety reasons I would always recommend not messing around with database migrations but since you started that already I can as well tell you where you can find additional information on how to finish it. For the next time don’t do it. Watchtower will update for you.

This is incorrect. We currently do not disqualify for low uptime, while we are in the process of implementing a new method for that.

1 Like

Thanks @littleskunk!
Though my remarks about the importance to have easy to install&maintain nodes still prevails, thanks to your link, I was able to manually rollback the DB change and to start the node again!

3 Likes

Same here! I’m in 37, how to revert to db 36?

Finally I have reverted

sqlite3 heldamount.db

CREATE TABLE payments (
id bigserial NOT NULL,
created_at timestamp NOT NULL,
satellite_id bytea NOT NULL,
period text,
amount bigint NOT NULL,
receipt text,
notes text,
PRIMARY KEY ( id )
);

.exit

thanks god!

1 Like

help

2020-12-26T05:39:19.817-0300 ERROR Failed preflight check. {“error”: “system clock is out of sync: system clock is out of sync with all trusted satellites”, “errorVerbose”: “system clock is out of sync: system clock is out of sync with all trusted satellites\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).Check:96\n\tstorj.io/storj/storagenode.(*Peer).Run:785\n\tmain.cmdRun:218\n\tstorj.io/private/process.cleanup.func1.4:363\n\tstorj.io/private/process.cleanup.func1:381\n\tgithub.com/spf13/cobra.(*Command).execute:842\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:950\n\tgithub.com/spf13/cobra.(*Command).Execute:887\n\tstorj.io/private/process.ExecWithCustomConfig:88\n\tstorj.io/private/process.Exec:65\n\tmain.(*service).Execute.func1:66\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57”}
2020-12-26T05:39:20.598-0300 FATAL Unrecoverable error {“error”: “system clock is out of sync: system clock is out of sync with all trusted satellites”, “errorVerbose”: “system clock is out of sync: system clock is out of sync with all trusted satellites\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).Check:96\n\tstorj.io/storj/storagenode.(*Peer).Run:785\n\tmain.cmdRun:218\n\tstorj.io/private/process.cleanup.func1.4:363\n\tstorj.io/private/process.cleanup.func1:381\n\tgithub.com/spf13/cobra.(*Command).execute:842\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:950\n\tgithub.com/spf13/cobra.(*Command).Execute:887\n\tstorj.io/private/process.ExecWithCustomConfig:88\n\tstorj.io/private/process.Exec:65\n\tmain.(*service).Execute.func1:66\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57”}

Please, go through this checklist and fix offline issue:

I had a similiar problem last few days. My problem was that my current nameserver from my ISP did not resolve the satelites name correctly. I don’t know why, but after I changed the nameserver in /etc/resolv.conf from my standard gateway IP do google 8.8.8.8 everything worked fine again. But the first error which apeared in the logs was, that the clock is out of sync.

Yes, this is a first check after contacting a satellite.

Is it available for debian linux too?

You do not need it for Debian. Install ntp and it will be synced automatically

But I think your problem is not clock out of sync, this is a last error after all checks. You need a first one, where your node is likely is unable to contact satellites, either because your IP is not reachable or network is not configured properly (some firewalls or network interface issue).
Please, post last 20 lines from your logs: How do I check my logs? - Storj

1 Like

No, I am just collecting information on what I should do next!