Make verbosity configurable and not leak sensitive values

[gtrog]

What this PR does / why we need it:
Reduce verbose logging, which leaks sensitive values like secrets/keys, but, make it configurable via RCLONE_VERBOSE.

Which issue(s) this PR fixes:
Fixes #4247

Special notes for your reviewer:

[seldondev]

Hi @gtrog. Thanks for your PR.

I'm waiting for a SeldonIO or todo member to verify that this patch is reasonable to test. If it is, they should reply with /ok-to-test on its own line. Until that is done, I will not automatically test new commits in this PR, but the usual testing commands by org members will still work. Regular contributors should join the org to skip this step.

Once the patch is verified, the new status will be reflected by the ok-to-test label.

I understand the commands that are listed here.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the jenkins-x/lighthouse repository.

[gtrog]

Tested locally:

# docker build . -t rclone

Default verbosity, no DEBUG messages:

# docker run -it --rm rclone
Usage:
  rclone copy source:path dest:path [flags]

Flags:
      --create-empty-src-dirs   Create empty source dirs on destination after copy
  -h, --help                    help for copy

Use "rclone [command] --help" for more information about a command.
Use "rclone help flags" for to see the global flags.
Use "rclone help backends" for a list of supported services.
Command copy needs 2 arguments minimum: you provided 0 non flag arguments: []

Then, with overridden verbosity contains DEBUG messages:

# docker run -it --rm -e RCLONE_VERBOSE=2 rclone
2022/08/01 18:40:27 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "copy"]
Usage:
  rclone copy source:path dest:path [flags]

Flags:
      --create-empty-src-dirs   Create empty source dirs on destination after copy
  -h, --help                    help for copy

Use "rclone [command] --help" for more information about a command.
Use "rclone help flags" for to see the global flags.
Use "rclone help backends" for a list of supported services.
Command copy needs 2 arguments minimum: you provided 0 non flag arguments: []

[RafalSkolasinski]

Thank you @gtrog, the change looks good. Could you post difference in output between verbose level 1 and 2 for completness?

[gtrog]

Thank you @gtrog, the change looks good. Could you post difference in output between verbose level 1 and 2 for completness?

Sure thing, if I build the docker image locally:

docker build . -t rclone-copy

And then run it the same way the tfserving-model-initializer init-container does (with the default verbosity=1):

# docker run -it --rm \
  -e RCLONE_CONFIG_S3_ACCESS_KEY_REGION="us-east-2" \
  -e RLCONE_CONFIG_S3_ACCESS_KEY_ID="<REDACTED>" \
  -e RCLONE_CONFIG_S3_SECRET_ACCESS_KEY="<REDACTED>" \
  -e RCLONE_CONFIG_S3_TYPE="s3" \
  -e RCLONE_CONFIG_S3_PROVIDER="aws" \
  -e RCLONE_CONFIG_S3_ENV_AUTH="false" \
  rclone-copy s3://rtr-data-models/stage/models/happy/v1.0/1652196245 /tmp/models
2022/08/04 13:34:51 NOTICE: Config file "/config/rclone/rclone.conf" not found - using defaults
2022/08/04 13:34:51 INFO  : 1/variables/variables.index: Copied (new)
2022/08/04 13:34:51 INFO  : 1/saved_model.pb: Copied (new)
2022/08/04 13:34:53 INFO  : 1/variables/variables.data-00000-of-00001: Copied (new)
2022/08/04 13:34:53 INFO  :
Transferred:       83.144 MiB / 83.144 MiB, 100%, 31.145 MiB/s, ETA 0s
Transferred:            3 / 3, 100%
Elapsed time:         2.2s

Next, if I run it the same way, but explicitly setting verbosity=2:

# docker run -it --rm \
  -e RCLONE_CONFIG_S3_REGION="us-east-2" \
  -e RCLONE_CONFIG_S3_ACCESS_KEY_ID="<REDACTED>" \
  -e RCLONE_CONFIG_S3_SECRET_ACCESS_KEY="<REDACTED>" \
  -e RCLONE_CONFIG_S3_TYPE="s3" \
  -e RCLONE_CONFIG_S3_PROVIDER="aws" \
  -e RCLONE_CONFIG_S3_ENV_AUTH="false" \
  -e RCLONE_VERBOSE=2 \
  rclone-copy s3://rtr-data-models/stage/models/happy/v1.0/1652196245 /mnt/models
2022/08/04 13:38:28 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "copy" "s3://rtr-data-models/stage/models/happy/v1.0/1652196245" "/mnt/models"]
2022/08/04 13:38:28 DEBUG : Creating backend with remote "s3://rtr-data-models/stage/models/happy/v1.0/1652196245"
2022/08/04 13:38:28 DEBUG : Setting type="s3" for "s3" from environment variable RCLONE_CONFIG_S3_TYPE
2022/08/04 13:38:28 DEBUG : Setting provider="aws" for "s3" from environment variable RCLONE_CONFIG_S3_PROVIDER
2022/08/04 13:38:28 DEBUG : Setting env_auth="false" for "s3" from environment variable RCLONE_CONFIG_S3_ENV_AUTH
2022/08/04 13:38:28 DEBUG : Setting access_key_id="<REDACTED>" for "s3" from environment variable RCLONE_CONFIG_S3_ACCESS_KEY_ID
2022/08/04 13:38:28 DEBUG : Setting secret_access_key="<REDACTED>" for "s3" from environment variable RCLONE_CONFIG_S3_SECRET_ACCESS_KEY
2022/08/04 13:38:28 DEBUG : Setting region="us-east-2" for "s3" from environment variable RCLONE_CONFIG_S3_REGION
2022/08/04 13:38:28 DEBUG : Setting region="us-east-2" for "s3" from environment variable RCLONE_CONFIG_S3_REGION
2022/08/04 13:38:28 DEBUG : Setting region="us-east-2" for "s3" from environment variable RCLONE_CONFIG_S3_REGION
2022/08/04 13:38:28 DEBUG : s3: detected overridden config - adding "{TrI48}" suffix to name
2022/08/04 13:38:28 DEBUG : Setting provider="aws" for "s3" from environment variable RCLONE_CONFIG_S3_PROVIDER
2022/08/04 13:38:28 DEBUG : Setting env_auth="false" for "s3" from environment variable RCLONE_CONFIG_S3_ENV_AUTH
2022/08/04 13:38:28 DEBUG : Setting access_key_id="<REDACTED>" for "s3" from environment variable RCLONE_CONFIG_S3_ACCESS_KEY_ID
2022/08/04 13:38:28 DEBUG : Setting secret_access_key="<REDACTED>" for "s3" from environment variable RCLONE_CONFIG_S3_SECRET_ACCESS_KEY
2022/08/04 13:38:28 DEBUG : Setting region="us-east-2" for "s3" from environment variable RCLONE_CONFIG_S3_REGION
2022/08/04 13:38:28 NOTICE: Config file "/config/rclone/rclone.conf" not found - using defaults
2022/08/04 13:38:29 DEBUG : fs cache: renaming cache item "s3://rtr-data-models/stage/models/happy/v1.0/1652196245" to be canonical "s3{TrI48}:rtr-data-models/stage/models/happy/v1.0/165219624
5"
2022/08/04 13:38:29 DEBUG : Creating backend with remote "/mnt/models"
2022/08/04 13:38:29 DEBUG : Local file system at /mnt/models: Waiting for checks to finish
2022/08/04 13:38:29 DEBUG : Local file system at /mnt/models: Waiting for transfers to finish
2022/08/04 13:38:29 DEBUG : 1/variables/variables.index: md5 = 7a60f2aa9a3abc2ef37a923f01e77a4c OK
2022/08/04 13:38:29 INFO  : 1/variables/variables.index: Copied (new)
2022/08/04 13:38:29 DEBUG : 1/saved_model.pb: md5 = a96abbefdc7d40a65ec48aed89723476 OK
2022/08/04 13:38:29 INFO  : 1/saved_model.pb: Copied (new)
2022/08/04 13:38:31 INFO  : 1/variables/variables.data-00000-of-00001: Copied (new)
2022/08/04 13:38:31 INFO  :
Transferred:       83.144 MiB / 83.144 MiB, 100%, 41.075 MiB/s, ETA 0s
Transferred:            3 / 3, 100%
Elapsed time:         2.3s

2022/08/04 13:38:31 DEBUG : 13 go routines active

So, this would allow you to still set verbosity=2 by adding RCLONE_VERBOSE=2 in your secret that's referenced, not the easiest way to turn on verbose=2 logging if you're pulling a public model and not using secret ref yet.

An argument could be made that rclone should definitely fix this on their side as well, to not log sensitive values, but until they do, we shouldn't default to verbose=2.

[RafalSkolasinski]

Thanks @gtrog, I'd probably prefer to have some verbosity 2.5 (knowing what vars are set but with values redacted automatically). But as it seems there's no option for this setting for verbosity 1 seems appropriate.

[RafalSkolasinski]

LGTM

[seldondev]

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: RafalSkolasinski

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

• OWNERS [RafalSkolasinski]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

[gtrog]

Thanks @gtrog, I'd probably prefer to have some verbosity 2.5 (knowing what vars are set but with values redacted automatically). But as it seems there's no option for this setting for verbosity 1 seems appropriate.

Yeah, I'll see if I can make a contribution to RClone as well and maybe eventually circle back here and do that