Audit score dropping? What is going on?

Node Operators troubleshooting
1

I just noted this:

Screenshot_2021-11-12_160322
Screenshot_2021-11-12_1603221186Ă—445 76.2 KB

A couple of seconds ago it was even lower at 96,32%.

Succesrate for this node shows as:

========== AUDIT ==============
Critically failed:     0
Critical Fail Rate:    0,000%
Recoverable failed:    0
Recoverable Fail Rate: 0,000%
Successful:            118
Success Rate:          100,000%

docker logs storagenode 2>&1 | grep GET_AUDIT | grep failed | wc -l
0

For that satellite I have found also this value: "auditHistory":{"score":0.9970331698747582,"windows":[{"windowStart":"2021-10-13T12:00:00Z"

What else could I check to find out what made the audit score drop as low as 96,32% but partly recovering as it seems?

2

Perhaps related to GET_REPAIR failed because of invalid signature
and take a look on this script: Got Disqualified from saltlake - #97 by Alexey for timeouts

3

No, I have some download failed but all of them are use of closed network connection.

docker logs storagenode 2>&1 | grep 12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs | grep -E "GET_AUDIT" | jq -R '. | split("\t") | (.[4] | fromjson) as $body | {SatelliteID: $body."Satellite ID", ($body."Piece ID"): {(.[0]): .[3]}}' | jq -s 'reduce .[] as $item ({}; . * $item)'                   {
  "SatelliteID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs",
  "CV3GYRROBL42YSHIVHXGO2BKJDQ5OUSAIGNLBBUXSK36X5PQZHAQ": {
    "2021-11-11T19:53:27.310Z": "download started",
    "2021-11-11T19:53:27.706Z": "downloaded"
  },
  "M7A7WLOXHGBDGFPRGZ5EE27KRKKIQKOW5VLLKPC7BQN7DDR2SLNQ": {
    "2021-11-11T20:30:56.066Z": "download started",
    "2021-11-11T20:30:57.115Z": "downloaded"
  },
  "RZ4HGGQAY4SRSSIH6LLZAHVEWTYAER4BNIBJDXPLAJROBTAVUTMQ": {
    "2021-11-11T20:33:42.464Z": "download started",
    "2021-11-11T20:33:50.900Z": "downloaded"
  },
  "PSC7WKCBVNUFLMVISX43JK5VCON4SCRYWCVC33H5LY2RMCUONAHA": {
    "2021-11-11T20:43:08.917Z": "download started",
    "2021-11-11T20:43:09.279Z": "downloaded"
  },
  "BNYYPBW6JA2CHZAZTQCBQU2CESDW34LB3A2L5O6YHBHJEK7VNFSA": {
    "2021-11-11T22:15:30.588Z": "download started",
    "2021-11-11T22:15:31.823Z": "downloaded"
  },
  "K4JGMUPBRFQATOKOYA6W5OV3PVOG3SLIDGPAKUOQ3DJLUYCSYABA": {
    "2021-11-11T23:49:30.617Z": "download started",
    "2021-11-11T23:49:31.048Z": "downloaded"
  },
  "GD5ZZTTIHQI7UP3CS6Z4O4EM6EH2YT54GCI5DB4HVUTZBUIIPZYQ": {
    "2021-11-11T23:56:45.189Z": "download started",
    "2021-11-11T23:56:45.547Z": "downloaded"
  },
  "QHFHHXW73O7WUIXSUSXCJ3YFMGHP7WEWN5LNVOOHDCMDJQXEBJKQ": {
    "2021-11-12T03:08:43.738Z": "download started",
    "2021-11-12T03:08:44.950Z": "downloaded"
  },
  "YH2ZG7CKDJ3OROHVY3AY7GN2VJJFAFTM3CCPOLSDMNXEVWUY7BWQ": {
    "2021-11-12T03:24:02.603Z": "download started",
    "2021-11-12T03:24:03.043Z": "downloaded"
  },
  "DQ6FLKTNPJC2SAHJ4W4JPLYWEQGDOODOW5TFN36L7IWTJAUMWCFA": {
    "2021-11-12T04:20:44.140Z": "download started",
    "2021-11-12T04:20:44.829Z": "downloaded"
  },
  "YYP5EP7FPT6IL3EY54KXUW4IMIXLLKCXKVMNBS5JGYHRSW3ULJBQ": {
    "2021-11-12T05:39:53.286Z": "download started",
    "2021-11-12T05:39:54.135Z": "downloaded"
  },
  "NE3ZTDS3VAJFWOEUG6KCR7K7NBKKGNZ4DARJAMONVG2G7M7ATEBA": {
    "2021-11-12T05:54:29.614Z": "download started",
    "2021-11-12T05:54:31.873Z": "downloaded"
  },
  "SPURYHBXA4Y6IGLU6SJOVR5MPTC4ERLGMAEESIJSSTEWZOVK4T2Q": {
    "2021-11-12T05:56:46.608Z": "download started",
    "2021-11-12T05:56:47.805Z": "downloaded"
  },
  "YTBJP67TRAFUINF7HPQLLJVGWF65ZVBA4UJTUBLEOWHAPVBA3ELQ": {
    "2021-11-12T06:34:01.873Z": "download started",
    "2021-11-12T06:34:05.441Z": "downloaded"
  },
  "3VY6PYIG6N4L7P4CN7LN665AUCS7LJ2CA7W57AX4KA3MBH7LL37A": {
    "2021-11-12T07:01:13.030Z": "download started",
    "2021-11-12T07:01:13.662Z": "downloaded"
  },
  "JG7IV4UFNNGDYY3NPLFN2TW36MEK45LXVUUHS6MZ6ZRA2V6AC4OQ": {
    "2021-11-12T07:02:17.877Z": "download started",
    "2021-11-12T07:02:19.505Z": "downloaded"
  },
  "2X6VYTITQDKE5J4ICQTZQEMXMXL6PKXKWFKCU3BXV4VGTJED5GQA": {
    "2021-11-12T07:16:49.620Z": "download started",
    "2021-11-12T07:16:50.689Z": "downloaded"
  },
  "GG3C7I3QRJFNZYBNBNHZMC34M3VMY7LBCWAB2WCFSZVD4TIDS6NQ": {
    "2021-11-12T08:02:48.640Z": "download started",
    "2021-11-12T08:02:53.793Z": "downloaded"
  },
  "XYO754GP7P6IQI3YCQLH6RK7ILXROWUKCQX43AOCOXAFYQWUPKSQ": {
    "2021-11-12T08:05:22.974Z": "download started",
    "2021-11-12T08:05:23.526Z": "downloaded"
  },
  "OSPKVNU7SDTSYYPZ24QX6SBFBAKRLAWGJXJHMA452LQZQSFQNFHA": {
    "2021-11-12T09:54:12.285Z": "download started",
    "2021-11-12T09:54:12.675Z": "downloaded"
  },
  "SDSJQJN6TDVGCMCKIWQCQBECSYRGQNWREHGAASXMYDGXKZLBCHVQ": {
    "2021-11-12T10:11:19.800Z": "download started",
    "2021-11-12T10:11:20.212Z": "downloaded"
  },
  "ISM2XNK4JUKG2FRRX62JGLUTLXIIFAM52QW5SQUZUGXUCWJ2PJ7A": {
    "2021-11-12T11:05:30.134Z": "download started",
    "2021-11-12T11:05:30.649Z": "downloaded"
  },
  "MZIQVXPJX7IEOGSFWLDEJEHO73KYMLRLRRH5FVFR7AFVFUDPX6PA": {
    "2021-11-12T11:35:29.028Z": "download started",
    "2021-11-12T11:35:30.337Z": "downloaded"
  },
  "HMUT6LPW54VKMCP6UH52RUT4U4E45VFEHF2WJ6PEODR7BBYZAOPQ": {
    "2021-11-12T11:42:48.208Z": "download started",
    "2021-11-12T11:42:50.627Z": "downloaded"
  },
  "DIPZVI23ZU6NQZE2OP56E2FHLQ64NSHYR5BLHFH7YH3IXITR4IHQ": {
    "2021-11-12T12:02:50.070Z": "download started",
    "2021-11-12T12:02:51.717Z": "downloaded"
  },
  "GU42NV4UHCGDEL3IHHZH3T65SOOENXSGYFKROAETT2ZBTK554O3Q": {
    "2021-11-12T12:21:42.799Z": "download started",
    "2021-11-12T12:21:43.561Z": "downloaded"
  },
  "IPLYTNO6KGWKK3QY2CP5FUHUMHPIEY6LPXLHIXL6NIL65USSUZBQ": {
    "2021-11-12T12:55:49.163Z": "download started",
    "2021-11-12T12:55:50.511Z": "downloaded"
  },
  "JBSC5QKS4YSMV7PY7VODEXYQB3TOEBDT4MW4HHSKHOPGBHXQRAAQ": {
    "2021-11-12T13:10:53.524Z": "download started",
    "2021-11-12T13:10:53.863Z": "downloaded"
  },
  "MWNQV4UT242ESBSIRWNVQTH37J5YB3Q2DUATLJMFULCGBFLT4KMA": {
    "2021-11-12T13:49:30.519Z": "download started",
    "2021-11-12T13:49:31.202Z": "downloaded"
  },
  "CTP7VY4B7C67VCSUGZAAQJPTO5OA6GPTALEZ47CBEVXZZAW6WK5Q": {
    "2021-11-12T13:57:28.924Z": "download started",
    "2021-11-12T13:57:29.449Z": "downloaded"
  },
  "X6TADHNGLYE2FFCPYXUL4PL4E6HXADVC2HDYQPZ7FGNW4GAYVGOQ": {
    "2021-11-12T14:11:12.286Z": "download started",
    "2021-11-12T14:11:15.063Z": "downloaded"
  },
  "L7ZVZU3A7AARX4SY4BJRHEJCV3ENRTZ2QV7SRAHQTPVRNCVN6RUA": {
    "2021-11-12T15:26:20.851Z": "download started",
    "2021-11-12T15:26:22.141Z": "downloaded"
  }
}

I don’t see any abnormal behavior.

4 
docker logs storagenode 2>&1 | grep GET_REPAIR | grep failed -c
5

Result is: 0 so this seems normal too.

6

Perhaps audit or repair failure now in the deleted logs…

7

Got same thing today, logs show no new errors except usual “race lost” errors.

Docker cleanup from here Prune unused Docker objects | Docker Documentation helped me, maybe this page will help you.

8

When I check in the Grafana dashboard for duration 1st of October until yesterday, then it shows me an audit score of 100%.
When I put the date until today, then it shows me an audit score of 99,65%. So it seems that if there was an issue with audits it must have been yesterday.

It is a weird coincidence that the docker restarted yesterday by itself. I wonder if there was an update. This made the logs before that disappear. I did not restart the node manually, so I don’t exactly know why it has restarted. Version is now at 1.42.4.

9

It’s not a solution, unfortunately

1 Like
10

The only restart will not wipe the logs. Even reboot do not do that. Only deleting of the container.

11

That makes it even weirder. I have not deleted the container nor rebooted. I have done nothing with it yesterday.

12

Can you check your system logs? Maybe there were a docker update?
And also, there is some small delay between failed audit in logs and affecting an audit score.

13

This node is on Armbian and I don’t think Docker is supposed to update itself. But something must have happend, the nodes uptime shows 22 hours only. But I am very sure I haven’t removed the container yesterday manually. Also my bash history does not show anything related to that.

14

Maybe watchtower did update?
Since you exporting metrics, maybe you exporting logs too? There is Loki could be used.

15

Maybe. That’s the only reasonable thing I can think of.

Not yet unfortunately.

16

Please, check it

docker logs --tail 10 watchtower
17

Yes, thanks:

time="2021-11-11T18:55:38Z" level=info msg="Found new storjlabs/storagenode:latest image ....
time="2021-11-11T18:56:10Z" level=info msg="Creating /storagenode"

So it got updated yesterday.

1 Like
18

In my Grafana I see the first drop in audits when I set the time from today 12am to 12pm. Before that the audit score displays as 100%.

19

Still there is no indication what happened between update and yesterday that made the audit score drop.

At least it seems to recover: Screenshot_2021-11-13_045503

20

Of course not, since your logs got deleted.
You can redirect them the into the file: How do I redirect my logs to a file? - Node Operator