Respect log format flag/config for stdout logs #1770

ashmeenkaur · 2024-03-06T17:33:24Z

Description

Background: A default logger with log format json is created using golang init() function. This logger logs the output to stdout/stderr until explict logger is created based on user specified configuration/flags.

This PR includes changes to ensure that init logger respects the user specified log format.

Link to the issue in case of a bug fix.

NA

Testing details

Manual - Manually verifies the console output:

Default format

ashmeen@ashmeen:~/gcsfuse$ go run ./ ashmeenbkt /tmp/mnt
{"timestamp":{"seconds":1709746144,"nanos":259745636},"severity":"INFO","message":"Start gcsfuse/unknown (Go version go1.22-20240109-RC01 cl/597041403 +dcbe772469 X:fieldtrack,boringcrypto) for app \"\" using mount point: /tmp/mnt\n"}
{"timestamp":{"seconds":1709746144,"nanos":259907976},"severity":"INFO","message":"GCSFuse mount command flags: {\"AppName\":\"\",\"Foreground\":false,\"ConfigFile\":\"\",\"MountOptions\":{},\"DirMode\":493,\"FileMode\":420,\"Uid\":-1,\"Gid\":-1,\"ImplicitDirs\":false,\"OnlyDir\":\"\",\"RenameDirLimit\":0,\"CustomEndpoint\":null,\"BillingProject\":\"\",\"KeyFile\":\"\",\"TokenUrl\":\"\",\"ReuseTokenFromUrl\":true,\"EgressBandwidthLimitBytesPerSecond\":-1,\"OpRateLimitHz\":-1,\"SequentialReadSizeMb\":200,\"MaxRetrySleep\":30000000000,\"StatCacheCapacity\":20460,\"StatCacheTTL\":60000000000,\"TypeCacheTTL\":60000000000,\"HttpClientTimeout\":0,\"MaxRetryDuration\":-1000000000,\"RetryMultiplier\":2,\"LocalFileCache\":false,\"TempDir\":\"\",\"ClientProtocol\":\"http1\",\"MaxConnsPerHost\":100,\"MaxIdleConnsPerHost\":100,\"EnableNonexistentTypeCache\":false,\"StackdriverExportInterval\":0,\"OtelCollectorAddress\":\"\",\"LogFile\":\"\",\"LogFormat\":\"json\",\"ExperimentalEnableJsonRead\":false,\"DebugFuseErrors\":true,\"DebugFuse\":false,\"DebugFS\":false,\"DebugGCS\":false,\"DebugHTTP\":false,\"DebugInvariants\":false,\"DebugMutex\":false}"}
{"timestamp":{"seconds":1709746144,"nanos":259959126},"severity":"INFO","message":"GCSFuse mount config flags: {\"CreateEmptyFile\":false,\"Severity\":\"INFO\",\"Format\":\"json\",\"FilePath\":\"\",\"LogRotateConfig\":{\"MaxFileSizeMB\":512,\"BackupFileCount\":10,\"Compress\":true},\"MaxSizeMB\":-1,\"CacheFileForRangeRead\":false,\"CacheDir\":\"\",\"TtlInSeconds\":-9223372036854775808,\"TypeCacheMaxSizeMB\":4,\"StatCacheMaxSizeMB\":-9223372036854775808,\"EnableEmptyManagedFolders\":false}"}
{"timestamp":{"seconds":1709746144,"nanos":573254485},"severity":"INFO","message":"File system has been successfully mounted."}

Text Format via flag

ashmeen@ashmeen:~/gcsfuse$ go run ./ --log-format=text ashmeenbkt /tmp/mnt
time="06/03/2024 05:27:56.373766" severity=INFO message="Start gcsfuse/unknown (Go version go1.22-20240109-RC01 cl/597041403 +dcbe772469 X:fieldtrack,boringcrypto) for app \"\" using mount point: /tmp/mnt\n"
time="06/03/2024 05:27:56.373967" severity=INFO message="GCSFuse mount command flags: {\"AppName\":\"\",\"Foreground\":false,\"ConfigFile\":\"\",\"MountOptions\":{},\"DirMode\":493,\"FileMode\":420,\"Uid\":-1,\"Gid\":-1,\"ImplicitDirs\":false,\"OnlyDir\":\"\",\"RenameDirLimit\":0,\"CustomEndpoint\":null,\"BillingProject\":\"\",\"KeyFile\":\"\",\"TokenUrl\":\"\",\"ReuseTokenFromUrl\":true,\"EgressBandwidthLimitBytesPerSecond\":-1,\"OpRateLimitHz\":-1,\"SequentialReadSizeMb\":200,\"MaxRetrySleep\":30000000000,\"StatCacheCapacity\":20460,\"StatCacheTTL\":60000000000,\"TypeCacheTTL\":60000000000,\"HttpClientTimeout\":0,\"MaxRetryDuration\":-1000000000,\"RetryMultiplier\":2,\"LocalFileCache\":false,\"TempDir\":\"\",\"ClientProtocol\":\"http1\",\"MaxConnsPerHost\":100,\"MaxIdleConnsPerHost\":100,\"EnableNonexistentTypeCache\":false,\"StackdriverExportInterval\":0,\"OtelCollectorAddress\":\"\",\"LogFile\":\"\",\"LogFormat\":\"text\",\"ExperimentalEnableJsonRead\":false,\"DebugFuseErrors\":true,\"DebugFuse\":false,\"DebugFS\":false,\"DebugGCS\":false,\"DebugHTTP\":false,\"DebugInvariants\":false,\"DebugMutex\":false}"
time="06/03/2024 05:27:56.374023" severity=INFO message="GCSFuse mount config flags: {\"CreateEmptyFile\":false,\"Severity\":\"INFO\",\"Format\":\"text\",\"FilePath\":\"\",\"LogRotateConfig\":{\"MaxFileSizeMB\":512,\"BackupFileCount\":10,\"Compress\":true},\"MaxSizeMB\":-1,\"CacheFileForRangeRead\":false,\"CacheDir\":\"\",\"TtlInSeconds\":-9223372036854775808,\"TypeCacheMaxSizeMB\":4,\"StatCacheMaxSizeMB\":-9223372036854775808,\"EnableEmptyManagedFolders\":false}"
time="06/03/2024 05:27:56.677186" severity=INFO message="File system has been successfully mounted."

JSON Format via flag

ashmeen@ashmeen:~/gcsfuse$ go run ./ --log-format=json ashmeenbkt /tmp/mnt
{"timestamp":{"seconds":1709746106,"nanos":301735419},"severity":"INFO","message":"Start gcsfuse/unknown (Go version go1.22-20240109-RC01 cl/597041403 +dcbe772469 X:fieldtrack,boringcrypto) for app \"\" using mount point: /tmp/mnt\n"}
{"timestamp":{"seconds":1709746106,"nanos":301988849},"severity":"INFO","message":"GCSFuse mount command flags: {\"AppName\":\"\",\"Foreground\":false,\"ConfigFile\":\"\",\"MountOptions\":{},\"DirMode\":493,\"FileMode\":420,\"Uid\":-1,\"Gid\":-1,\"ImplicitDirs\":false,\"OnlyDir\":\"\",\"RenameDirLimit\":0,\"CustomEndpoint\":null,\"BillingProject\":\"\",\"KeyFile\":\"\",\"TokenUrl\":\"\",\"ReuseTokenFromUrl\":true,\"EgressBandwidthLimitBytesPerSecond\":-1,\"OpRateLimitHz\":-1,\"SequentialReadSizeMb\":200,\"MaxRetrySleep\":30000000000,\"StatCacheCapacity\":20460,\"StatCacheTTL\":60000000000,\"TypeCacheTTL\":60000000000,\"HttpClientTimeout\":0,\"MaxRetryDuration\":-1000000000,\"RetryMultiplier\":2,\"LocalFileCache\":false,\"TempDir\":\"\",\"ClientProtocol\":\"http1\",\"MaxConnsPerHost\":100,\"MaxIdleConnsPerHost\":100,\"EnableNonexistentTypeCache\":false,\"StackdriverExportInterval\":0,\"OtelCollectorAddress\":\"\",\"LogFile\":\"\",\"LogFormat\":\"json\",\"ExperimentalEnableJsonRead\":false,\"DebugFuseErrors\":true,\"DebugFuse\":false,\"DebugFS\":false,\"DebugGCS\":false,\"DebugHTTP\":false,\"DebugInvariants\":false,\"DebugMutex\":false}"}
{"timestamp":{"seconds":1709746106,"nanos":302051319},"severity":"INFO","message":"GCSFuse mount config flags: {\"CreateEmptyFile\":false,\"Severity\":\"INFO\",\"Format\":\"json\",\"FilePath\":\"\",\"LogRotateConfig\":{\"MaxFileSizeMB\":512,\"BackupFileCount\":10,\"Compress\":true},\"MaxSizeMB\":-1,\"CacheFileForRangeRead\":false,\"CacheDir\":\"\",\"TtlInSeconds\":-9223372036854775808,\"TypeCacheMaxSizeMB\":4,\"StatCacheMaxSizeMB\":-9223372036854775808,\"EnableEmptyManagedFolders\":false}"}
{"timestamp":{"seconds":1709746106,"nanos":721464755},"severity":"INFO","message":"File system has been successfully mounted."}

JSON Format via config file

ashmeen@ashmeen:~/gcsfuse$ go run ./ --config-file=~/Documents/config.yaml ashmeenbkt /tmp/mnt
{"time":"06/03/2024 05:30:46.926068","severity":"INFO","message":"Value of [config-file] resolved from [~/Documents/config.yaml] to [/usr/local/google/home/ashmeen/Documents/config.yaml]\n"}
{"timestamp":{"seconds":1709746246,"nanos":926277650},"severity":"INFO","message":"Start gcsfuse/unknown (Go version go1.22-20240109-RC01 cl/597041403 +dcbe772469 X:fieldtrack,boringcrypto) for app \"\" using mount point: /tmp/mnt\n"}
{"timestamp":{"seconds":1709746246,"nanos":926462020},"severity":"INFO","message":"GCSFuse mount command flags: {\"AppName\":\"\",\"Foreground\":false,\"ConfigFile\":\"/usr/local/google/home/ashmeen/Documents/config.yaml\",\"MountOptions\":{},\"DirMode\":493,\"FileMode\":420,\"Uid\":-1,\"Gid\":-1,\"ImplicitDirs\":false,\"OnlyDir\":\"\",\"RenameDirLimit\":0,\"CustomEndpoint\":null,\"BillingProject\":\"\",\"KeyFile\":\"\",\"TokenUrl\":\"\",\"ReuseTokenFromUrl\":true,\"EgressBandwidthLimitBytesPerSecond\":-1,\"OpRateLimitHz\":-1,\"SequentialReadSizeMb\":200,\"MaxRetrySleep\":30000000000,\"StatCacheCapacity\":20460,\"StatCacheTTL\":60000000000,\"TypeCacheTTL\":60000000000,\"HttpClientTimeout\":0,\"MaxRetryDuration\":-1000000000,\"RetryMultiplier\":2,\"LocalFileCache\":false,\"TempDir\":\"\",\"ClientProtocol\":\"http1\",\"MaxConnsPerHost\":100,\"MaxIdleConnsPerHost\":100,\"EnableNonexistentTypeCache\":false,\"StackdriverExportInterval\":0,\"OtelCollectorAddress\":\"\",\"LogFile\":\"\",\"LogFormat\":\"json\",\"ExperimentalEnableJsonRead\":false,\"DebugFuseErrors\":true,\"DebugFuse\":false,\"DebugFS\":false,\"DebugGCS\":false,\"DebugHTTP\":false,\"DebugInvariants\":false,\"DebugMutex\":false}"}
{"timestamp":{"seconds":1709746246,"nanos":926519580},"severity":"INFO","message":"GCSFuse mount config flags: {\"CreateEmptyFile\":false,\"Severity\":\"INFO\",\"Format\":\"json\",\"FilePath\":\"\",\"LogRotateConfig\":{\"MaxFileSizeMB\":512,\"BackupFileCount\":10,\"Compress\":true},\"MaxSizeMB\":-1,\"CacheFileForRangeRead\":false,\"CacheDir\":\"\",\"TtlInSeconds\":3600,\"TypeCacheMaxSizeMB\":0,\"StatCacheMaxSizeMB\":10000,\"EnableEmptyManagedFolders\":false}"}
{"timestamp":{"seconds":1709746247,"nanos":248655939},"severity":"INFO","message":"File system has been successfully mounted."}

Text Format via config file

ashmeen@ashmeen:~/gcsfuse$ go run ./ --config-file=~/Documents/config.yaml ashmeenbkt /tmp/mnt
{"time":"06/03/2024 05:31:35.071958","severity":"INFO","message":"Value of [config-file] resolved from [~/Documents/config.yaml] to [/usr/local/google/home/ashmeen/Documents/config.yaml]\n"}
time="06/03/2024 05:31:35.072193" severity=INFO message="Start gcsfuse/unknown (Go version go1.22-20240109-RC01 cl/597041403 +dcbe772469 X:fieldtrack,boringcrypto) for app \"\" using mount point: /tmp/mnt\n"
time="06/03/2024 05:31:35.072323" severity=INFO message="GCSFuse mount command flags: {\"AppName\":\"\",\"Foreground\":false,\"ConfigFile\":\"/usr/local/google/home/ashmeen/Documents/config.yaml\",\"MountOptions\":{},\"DirMode\":493,\"FileMode\":420,\"Uid\":-1,\"Gid\":-1,\"ImplicitDirs\":false,\"OnlyDir\":\"\",\"RenameDirLimit\":0,\"CustomEndpoint\":null,\"BillingProject\":\"\",\"KeyFile\":\"\",\"TokenUrl\":\"\",\"ReuseTokenFromUrl\":true,\"EgressBandwidthLimitBytesPerSecond\":-1,\"OpRateLimitHz\":-1,\"SequentialReadSizeMb\":200,\"MaxRetrySleep\":30000000000,\"StatCacheCapacity\":20460,\"StatCacheTTL\":60000000000,\"TypeCacheTTL\":60000000000,\"HttpClientTimeout\":0,\"MaxRetryDuration\":-1000000000,\"RetryMultiplier\":2,\"LocalFileCache\":false,\"TempDir\":\"\",\"ClientProtocol\":\"http1\",\"MaxConnsPerHost\":100,\"MaxIdleConnsPerHost\":100,\"EnableNonexistentTypeCache\":false,\"StackdriverExportInterval\":0,\"OtelCollectorAddress\":\"\",\"LogFile\":\"\",\"LogFormat\":\"json\",\"ExperimentalEnableJsonRead\":false,\"DebugFuseErrors\":true,\"DebugFuse\":false,\"DebugFS\":false,\"DebugGCS\":false,\"DebugHTTP\":false,\"DebugInvariants\":false,\"DebugMutex\":false}"
time="06/03/2024 05:31:35.072380" severity=INFO message="GCSFuse mount config flags: {\"CreateEmptyFile\":false,\"Severity\":\"INFO\",\"Format\":\"text\",\"FilePath\":\"\",\"LogRotateConfig\":{\"MaxFileSizeMB\":512,\"BackupFileCount\":10,\"Compress\":true},\"MaxSizeMB\":-1,\"CacheFileForRangeRead\":false,\"CacheDir\":\"\",\"TtlInSeconds\":3600,\"TypeCacheMaxSizeMB\":0,\"StatCacheMaxSizeMB\":10000,\"EnableEmptyManagedFolders\":false}"
time="06/03/2024 05:31:35.366242" severity=INFO message="File system has been successfully mounted."

Unit tests - NA
Integration tests - Via KOKORO

mustvicky

Does it make sense to have UTs for this change? What if we break the new behavior later accidentally

gargnitingoogle

@ashmeenkaur I left some comment. Please address.

internal/logger/logger.go

main.go

ashmeenkaur · 2024-03-07T10:00:10Z

Does it make sense to have UTs for this change? What if we break the new behavior later accidentally

Added unit tests for SetLogFormat method, however adding tests for main is difficult and it will essentially be an integration test.

gargnitingoogle

@ashmeenkaur I added some more comments. Please address.

main.go

internal/logger/logger.go

internal/logger/logger_test.go

gargnitingoogle · 2024-03-08T08:30:05Z

@ashmeenkaur Could you please share the link to the passed integration test run?

main.go

gargnitingoogle

LGTM with a nitpick and a fix expected in a future PR.

ashmeenkaur · 2024-03-08T08:47:35Z

@ashmeenkaur Could you please share the link to the passed integration test run?

Added to the PR description

Co-authored-by: Nitin Garg <113666283+gargnitingoogle@users.noreply.github.com>

gargnitingoogle

LGTM, with a future non-blocking fix pending.

internal/logger/logger.go

raj-prince

LGTM. one minor comment.

* respect log format flag/config for stdout logs. * add unit test * review comments * review comments * Update main.go Co-authored-by: Nitin Garg <113666283+gargnitingoogle@users.noreply.github.com> * review comments --------- Co-authored-by: Nitin Garg <113666283+gargnitingoogle@users.noreply.github.com>

respect log format flag/config for stdout logs.

f7c65b4

ashmeenkaur added the execute-integration-tests Run only integration tests label Mar 6, 2024

ashmeenkaur marked this pull request as ready for review March 6, 2024 18:53

ashmeenkaur requested review from sethiay, vadlakondaswetha and raj-prince as code owners March 6, 2024 18:53

mustvicky reviewed Mar 7, 2024

View reviewed changes

gargnitingoogle requested changes Mar 7, 2024

View reviewed changes

internal/logger/logger.go Outdated Show resolved Hide resolved

internal/logger/logger.go Show resolved Hide resolved

main.go Show resolved Hide resolved

ashmeenkaur added 2 commits March 7, 2024 09:21

add unit test

079883e

review comments

f7f6043

ashmeenkaur requested review from gargnitingoogle and mustvicky March 7, 2024 10:00

ashmeenkaur removed the execute-integration-tests Run only integration tests label Mar 7, 2024

gargnitingoogle requested changes Mar 8, 2024

View reviewed changes

main.go Show resolved Hide resolved

internal/logger/logger.go Outdated Show resolved Hide resolved

internal/logger/logger.go Show resolved Hide resolved

internal/logger/logger.go Outdated Show resolved Hide resolved

internal/logger/logger_test.go Outdated Show resolved Hide resolved

review comments

55fd4a0

ashmeenkaur requested a review from gargnitingoogle March 8, 2024 05:50

gargnitingoogle reviewed Mar 8, 2024

View reviewed changes

main.go Outdated Show resolved Hide resolved

gargnitingoogle self-requested a review March 8, 2024 08:34

gargnitingoogle previously approved these changes Mar 8, 2024

View reviewed changes

ashmeenkaur dismissed gargnitingoogle’s stale review via 1af1671 March 8, 2024 08:47

Update main.go

1af1671

Co-authored-by: Nitin Garg <113666283+gargnitingoogle@users.noreply.github.com>

gargnitingoogle previously approved these changes Mar 8, 2024

View reviewed changes

raj-prince reviewed Mar 8, 2024

View reviewed changes

internal/logger/logger.go Outdated Show resolved Hide resolved

raj-prince reviewed Mar 8, 2024

View reviewed changes

review comments

0a47d31

ashmeenkaur dismissed gargnitingoogle’s stale review via 0a47d31 March 8, 2024 09:58

raj-prince approved these changes Mar 8, 2024

View reviewed changes

ashmeenkaur merged commit 5e6aa1e into master Mar 11, 2024
8 checks passed

ashmeenkaur deleted the fix_log_format_at_init branch March 11, 2024 01:22

BrewTestBot mentioned this pull request Apr 23, 2024

gcsfuse 2.0.1 Homebrew/homebrew-core#169823

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Respect log format flag/config for stdout logs #1770

Respect log format flag/config for stdout logs #1770

ashmeenkaur commented Mar 6, 2024 •

edited

Loading

mustvicky left a comment

gargnitingoogle left a comment

ashmeenkaur commented Mar 7, 2024

gargnitingoogle left a comment

gargnitingoogle commented Mar 8, 2024

gargnitingoogle left a comment

ashmeenkaur commented Mar 8, 2024

gargnitingoogle left a comment

raj-prince left a comment

Respect log format flag/config for stdout logs #1770

Respect log format flag/config for stdout logs #1770

Conversation

ashmeenkaur commented Mar 6, 2024 • edited Loading

Description

Link to the issue in case of a bug fix.

Testing details

mustvicky left a comment

Choose a reason for hiding this comment

gargnitingoogle left a comment

Choose a reason for hiding this comment

ashmeenkaur commented Mar 7, 2024

gargnitingoogle left a comment

Choose a reason for hiding this comment

gargnitingoogle commented Mar 8, 2024

gargnitingoogle left a comment

Choose a reason for hiding this comment

ashmeenkaur commented Mar 8, 2024

gargnitingoogle left a comment

Choose a reason for hiding this comment

raj-prince left a comment

Choose a reason for hiding this comment

ashmeenkaur commented Mar 6, 2024 •

edited

Loading