Project

General

Profile

Actions

Bug #19127

closed

spurious config warnings when using local keepstore on compute

Added by Ward Vandewege almost 2 years ago. Updated almost 2 years ago.

Status:
Resolved
Priority:
Normal
Assigned To:
Category:
-
Target version:
Story points:
-
Release relationship:
Auto

Description

Observed on Arvados 2.4.0 on pirca, e.g. pirca-xvhdp-m1mdkxyqugein4m

These warnings get logged in the container logs under these circumstances:

Config:

    Containers:
      PreemptiblePriceFactor: 1
      LocalKeepLogsToContainerLog: errors
Two questions/bugs:
  • these are warnings, why are they showing up when LocalKeepLogsToContainerLog is set to errors ? Does errors also somehow include warnings? That's confusing.
  • the warnings seem wrong. They don't show up when checking the config with arvados-server config-check.

Warnings:

2022-05-11T19:12:59.961853108Z starting keepstore on http://localhost:42569
2022-05-11T19:12:59.961889139Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c52xlarge.Scratch","time":"2022-05-11T19:12:59.374860700Z"}
2022-05-11T19:12:59.961898898Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c52xlarge.Name","time":"2022-05-11T19:12:59.374935708Z"}
2022-05-11T19:12:59.961908852Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c54xlarge.Name","time":"2022-05-11T19:12:59.374964424Z"}
2022-05-11T19:12:59.961918521Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c54xlarge.Scratch","time":"2022-05-11T19:12:59.374988872Z"}
2022-05-11T19:12:59.961927672Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g52xlarge.preemptible.Name","time":"2022-05-11T19:12:59.375745729Z"}
2022-05-11T19:12:59.961935857Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g52xlarge.preemptible.Scratch","time":"2022-05-11T19:12:59.375953678Z"}
2022-05-11T19:12:59.961957863Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g54xlarge.Name","time":"2022-05-11T19:12:59.376123687Z"}
2022-05-11T19:12:59.961964834Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g54xlarge.Scratch","time":"2022-05-11T19:12:59.376285332Z"}
2022-05-11T19:12:59.961973470Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.inf16xlarge.preemptible.Name","time":"2022-05-11T19:12:59.376450316Z"}
2022-05-11T19:12:59.961980428Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.inf16xlarge.preemptible.Scratch","time":"2022-05-11T19:12:59.376619218Z"}
2022-05-11T19:12:59.961989254Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c5large.Scratch","time":"2022-05-11T19:12:59.376796323Z"}
2022-05-11T19:12:59.961998393Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c5large.Name","time":"2022-05-11T19:12:59.376989255Z"}
2022-05-11T19:12:59.962004546Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g58xlarge.preemptible.Name","time":"2022-05-11T19:12:59.377145316Z"}
2022-05-11T19:12:59.962012511Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g58xlarge.preemptible.Scratch","time":"2022-05-11T19:12:59.377301156Z"}
2022-05-11T19:12:59.962034722Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5xlarge_extradisk.Name","time":"2022-05-11T19:12:59.377478606Z"}
2022-05-11T19:12:59.962043258Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5xlarge_extradisk.Scratch","time":"2022-05-11T19:12:59.377632135Z"}
2022-05-11T19:12:59.962078491Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c54xlarge.preemptible.Name","time":"2022-05-11T19:12:59.377820339Z"}
2022-05-11T19:12:59.962102477Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c54xlarge.preemptible.Scratch","time":"2022-05-11T19:12:59.377991277Z"}
2022-05-11T19:12:59.962109769Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m52xlarge.preemptible.Scratch","time":"2022-05-11T19:12:59.378155300Z"}
2022-05-11T19:12:59.962117943Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m52xlarge.preemptible.Name","time":"2022-05-11T19:12:59.378307037Z"}
2022-05-11T19:12:59.962124702Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5large.preemptible.Scratch","time":"2022-05-11T19:12:59.378462819Z"}
2022-05-11T19:12:59.962134576Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5large.preemptible.Name","time":"2022-05-11T19:12:59.378615162Z"}
2022-05-11T19:12:59.962146387Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5xlarge_extradisk.preemptible.Name","time":"2022-05-11T19:12:59.378769767Z"}
2022-05-11T19:12:59.962155085Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5xlarge_extradisk.preemptible.Scratch","time":"2022-05-11T19:12:59.378926964Z"}
2022-05-11T19:12:59.962161833Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.t3small.Name","time":"2022-05-11T19:12:59.379080403Z"}
2022-05-11T19:12:59.962183550Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.t3small.Scratch","time":"2022-05-11T19:12:59.379286475Z"}
2022-05-11T19:12:59.962190470Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c52xlarge.preemptible.Scratch","time":"2022-05-11T19:12:59.379332414Z"}
2022-05-11T19:12:59.962204018Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c52xlarge.preemptible.Name","time":"2022-05-11T19:12:59.379378580Z"}
2022-05-11T19:12:59.962211510Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g52xlarge.Name","time":"2022-05-11T19:12:59.379405404Z"}
2022-05-11T19:12:59.962219782Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g52xlarge.Scratch","time":"2022-05-11T19:12:59.379426468Z"}
2022-05-11T19:12:59.962227280Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m54xlarge.Scratch","time":"2022-05-11T19:12:59.379448616Z"}
2022-05-11T19:12:59.962237904Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m54xlarge.Name","time":"2022-05-11T19:12:59.379467450Z"}
2022-05-11T19:12:59.962260826Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c5large.preemptible.Scratch","time":"2022-05-11T19:12:59.379512398Z"}
2022-05-11T19:12:59.962269791Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c5large.preemptible.Name","time":"2022-05-11T19:12:59.379537204Z"}
2022-05-11T19:12:59.962276352Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g54xlarge.preemptible.Name","time":"2022-05-11T19:12:59.379558744Z"}
2022-05-11T19:12:59.962285306Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g54xlarge.preemptible.Scratch","time":"2022-05-11T19:12:59.379578922Z"}
2022-05-11T19:12:59.962293162Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m54xlarge.preemptible.Name","time":"2022-05-11T19:12:59.379622906Z"}
2022-05-11T19:12:59.962308322Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m54xlarge.preemptible.Scratch","time":"2022-05-11T19:12:59.379646674Z"}
2022-05-11T19:12:59.962315887Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g5xlarge.Name","time":"2022-05-11T19:12:59.379668849Z"}
2022-05-11T19:12:59.962339655Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g5xlarge.Scratch","time":"2022-05-11T19:12:59.379712975Z"}
2022-05-11T19:12:59.962346432Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g5xlarge.preemptible.Name","time":"2022-05-11T19:12:59.379738887Z"}
2022-05-11T19:12:59.962359248Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g5xlarge.preemptible.Scratch","time":"2022-05-11T19:12:59.379758653Z"}
2022-05-11T19:12:59.962364123Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5large.Name","time":"2022-05-11T19:12:59.379780002Z"}
2022-05-11T19:12:59.962381293Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5large.Scratch","time":"2022-05-11T19:12:59.379833750Z"}
2022-05-11T19:12:59.962388598Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.t3small.preemptible.Name","time":"2022-05-11T19:12:59.379855657Z"}
2022-05-11T19:12:59.962396513Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.t3small.preemptible.Scratch","time":"2022-05-11T19:12:59.379905486Z"}
2022-05-11T19:12:59.962417432Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.inf16xlarge.Name","time":"2022-05-11T19:12:59.379930223Z"}
2022-05-11T19:12:59.962427236Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.inf16xlarge.Scratch","time":"2022-05-11T19:12:59.379955265Z"}
2022-05-11T19:12:59.962434348Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5xlarge.preemptible.Scratch","time":"2022-05-11T19:12:59.379976380Z"}
2022-05-11T19:12:59.962444912Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5xlarge.preemptible.Name","time":"2022-05-11T19:12:59.379997807Z"}
2022-05-11T19:12:59.962452483Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c5xlarge.Scratch","time":"2022-05-11T19:12:59.380044466Z"}
2022-05-11T19:12:59.962460825Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c5xlarge.Name","time":"2022-05-11T19:12:59.380099065Z"}
2022-05-11T19:12:59.962468509Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c5xlarge.preemptible.Name","time":"2022-05-11T19:12:59.380150390Z"}
2022-05-11T19:12:59.962494344Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.c5xlarge.preemptible.Scratch","time":"2022-05-11T19:12:59.380172697Z"}
2022-05-11T19:12:59.962502201Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g58xlarge.Name","time":"2022-05-11T19:12:59.380194002Z"}
2022-05-11T19:12:59.962511181Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.g58xlarge.Scratch","time":"2022-05-11T19:12:59.380238818Z"}
2022-05-11T19:12:59.962518448Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m52xlarge.Name","time":"2022-05-11T19:12:59.380263034Z"}
2022-05-11T19:12:59.962526997Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m52xlarge.Scratch","time":"2022-05-11T19:12:59.380282939Z"}
2022-05-11T19:12:59.962534002Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5xlarge.Scratch","time":"2022-05-11T19:12:59.380326160Z"}
2022-05-11T19:12:59.962543591Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.InstanceTypes.m5xlarge.Name","time":"2022-05-11T19:12:59.380349136Z"}
2022-05-11T19:12:59.962550634Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.Users.UserNotifierEmailBcc.info@curii.com","time":"2022-05-11T19:12:59.380390762Z"}
2022-05-11T19:12:59.962573121Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.Users.NewUserNotificationRecipients.playground@curii.com","time":"2022-05-11T19:12:59.380438381Z"}
2022-05-11T19:12:59.962592406Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.Users.NewUserNotificationRecipients.sysadmin+PIRCA@curii.com","time":"2022-05-11T19:12:59.380458961Z"}
2022-05-11T19:12:59.962601848Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.Users.NewInactiveUserNotificationRecipients.playground@curii.com","time":"2022-05-11T19:12:59.380487479Z"}
2022-05-11T19:12:59.962610289Z {"level":"warning","msg":"deprecated or unknown config entry: Clusters.pirca.Users.NewInactiveUserNotificationRecipients.sysadmin+PIRCA@curii.com","time":"2022-05-11T19:12:59.380541614Z"}
2022-05-11T19:12:59.962622666Z {"ClusterID":"pirca","PID":1682,"level":"info","msg":"keepstore 2.4.0 (go1.17.1) starting, pid 1682","time":"2022-05-11T19:12:59.391936777Z"}
2022-05-11T19:12:59.962646332Z {"ClusterID":"pirca","PID":1682,"level":"info","msg":"started volume pirca-nyw5e-000000000000000 (s3-bucket:\"pirca-nyw5e-000000000000000-volume\"), ReadOnly=false","time":"2022-05-11T19:12:59.392114368Z"}
2022-05-11T19:12:59.962663470Z {"ClusterID":"pirca","Listen":"127.0.0.1:42569","PID":1682,"Service":"keepstore","URL":"http://localhost:42569/","level":"info","msg":"listening","time":"2022-05-11T19:12:59.538837708Z"}
2022-05-11T19:12:59.961214904Z using local keepstore process (pid 1682) at http://localhost:42569, writing logs to keepstore.txt in log collection
2022-05-11T19:13:02.946896108Z crunch-run 2.4.0 (go1.17.1) started
2022-05-11T19:13:02.947553420Z crunch-run process has uid=0(root) gid=0(root) groups=0(root)
2022-05-11T19:13:02.947571669Z Executing container 'pirca-dz642-mufa2uvwonyri0s' using docker runtime
2022-05-11T19:13:02.947581564Z Executing on host 'ip-10-254-254-115'
2022-05-11T19:13:03.054213584Z container token "v2/pirca-gj3su-07dfbqhvkvb9ksh/2nms9f8otf3x4jcfqd6h79eycble41tf6ynfeactoyb8r032st/pirca-dz642-mufa2uvwonyri0s" 
...

Subtasks 1 (0 open1 closed)

Task #19128: review 19127-remove-warningsResolvedWard Vandewege05/13/2022Actions
Actions #1

Updated by Ward Vandewege almost 2 years ago

  • Description updated (diff)
Actions #2

Updated by Ward Vandewege almost 2 years ago

  • Description updated (diff)
Actions #3

Updated by Ward Vandewege almost 2 years ago

  • Release set to 51
Actions #4

Updated by Tom Clegg almost 2 years ago

  • these are warnings, why are they showing up when LocalKeepLogsToContainerLog is set to errors ? Does errors also somehow include warnings? That's confusing.

Maybe "errors" is not the best term -- it means

      # * "errors" -- all logs except "response" logs with 2xx                                                                                         
      #   response codes and "request" logs                                                                                                            
  • the warnings seem wrong. They don't show up when checking the config with arvados-server config-check.

This happens because the "Name" and "Scratch" fields are dumped by "config-dump" even though they are computed fields, not expected to be in a literal config file, therefore they don't appear in the sample/default config.default.yml.

Unless I'm forgetting some awkward side effect, I think the fix is just to add the `json:"-"` struct tag to these fields so they don't get dumped -- they get populated/overwritten by the loader anyway when loading the dumped config.

Actions #5

Updated by Ward Vandewege almost 2 years ago

  • Target version changed from 2022-06-08 sprint to 2022-05-25 sprint
  • Assigned To set to Ward Vandewege
  • Status changed from New to In Progress

Tom Clegg wrote:

  • these are warnings, why are they showing up when LocalKeepLogsToContainerLog is set to errors ? Does errors also somehow include warnings? That's confusing.

Maybe "errors" is not the best term -- it means

[...]

  • the warnings seem wrong. They don't show up when checking the config with arvados-server config-check.

This happens because the "Name" and "Scratch" fields are dumped by "config-dump" even though they are computed fields, not expected to be in a literal config file, therefore they don't appear in the sample/default config.default.yml.

Unless I'm forgetting some awkward side effect, I think the fix is just to add the `json:"-"` struct tag to these fields so they don't get dumped -- they get populated/overwritten by the loader anyway when loading the dumped config.

fb553cae8d2132a17bc31d06d7b5f95aeebff78a on branch 19127-remove-warnings

developer-run-tests: #3114

Actions #7

Updated by Tom Clegg almost 2 years ago

I pushed a test update that fails without the fix.

19127-remove-warnings @ 2a1924361a836d95fd3a055fd501c96599489547 -- developer-run-tests: #3115

Looks like TestInstanceTypeFixup is failing because I did forget a side effect though -- json:"-" means it doesn't load the Name/Scratch field either, which breaks things (both are "legacy" things, but I'm not sure we can safely stop supporting them)
  • Ignoring the "Name" field means we can't load old config files that had a list of instance types with Name fields, instead of a dictionary with name as key
  • Ignoring the "Scratch" field means we can't load config files that just say "Scratch" instead of specifying separate "IncludedScratch" and "AddedScratch"
Other ideas
  • do something custom with a MarshalJSON/UnmarshalJSON method
  • add Scratch to config.default.yml with a comment saying normally it's 0/omitted, meaning included+added
  • make an exception for those fields in the "warn about unrecognized fields" code

We already throw an error if Scratch!=0 and Scratch!=IncludedScratch+AddedScratch. We should probably add a similar check for the Name field anyway -- and in that case I think the 3rd option (skip the generic deprecated/unknown warning for these fields) would mean you only get warnings if the values are inconsistent, which won't happen in a dumped config.

Actions #8

Updated by Ward Vandewege almost 2 years ago

Tom Clegg wrote:

I pushed a test update that fails without the fix.

19127-remove-warnings @ 2a1924361a836d95fd3a055fd501c96599489547 -- developer-run-tests: #3115

Looks like TestInstanceTypeFixup is failing because I did forget a side effect though -- json:"-" means it doesn't load the Name/Scratch field either, which breaks things (both are "legacy" things, but I'm not sure we can safely stop supporting them)
  • Ignoring the "Name" field means we can't load old config files that had a list of instance types with Name fields, instead of a dictionary with name as key
  • Ignoring the "Scratch" field means we can't load config files that just say "Scratch" instead of specifying separate "IncludedScratch" and "AddedScratch"

The "Name" change is from a long time ago (#13674, bd059862d1dd7e68642dd365f0a536621ff6735f, June 2018, part of Arvados 1.2.0), not worth worrying about I think. The "Scratch" field was deprecated in Arvados 1.4.0 (in June 2019) so I think we can ignore that too, or rather:

  • remove special backwards compatibility support for "Name" (aka InstanceTypes specified as Array instead of Hash) and "Scratch" in the config file loader
  • do the `json:"-"` thing

d8045cd78fc849525e7b2564325ae9cb3a91497d on branch 19127-remove-warnings

developer-run-tests: #3121
developer-run-tests-apps-workbench-integration: #3338

Actions #9

Updated by Tom Clegg almost 2 years ago

LGTM, thanks!

Actions #10

Updated by Ward Vandewege almost 2 years ago

  • % Done changed from 0 to 100
  • Status changed from In Progress to Resolved

Applied in changeset arvados-private:commit:arvados|44a296b1c976ebf546cbd4b2444ec2b41c571f88.

Actions

Also available in: Atom PDF