Skip to content

PCSM 335 use rfc 3339 format for log timestamps #69

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
rasika-chivate wants to merge 10 commits into
base: main
Choose a base branch
from
+27 −12
Open

PCSM 335 use rfc 3339 format for log timestamps #69

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
6b358ee
PCSM-335-Use-RFC-3339-format-for-log-timestamps
rasika-chivate Sep 7, 2026
99e6414
Update logging.md
rasika-chivate Sep 7, 2026
882fba8
Update logging.md
rasika-chivate Sep 7, 2026
0eadf1b
Update logging.md
rasika-chivate Sep 7, 2026
6e8e1ec
Fix Vale action release lookup
Copilot Sep 7, 2026
8242dda
Potential fix for pull request finding
rasika-chivate Sep 7, 2026
a47a655
Update logging.md
rasika-chivate Sep 7, 2026
20e5330
Merge branch 'PCSM-335-Use-RFC-3339-format-for-log-timestamps' of htt…
rasika-chivate Sep 7, 2026
71a8c15
Update troubleshooting log timestamps
Copilot Sep 7, 2026
0df4975
Update troubleshooting.md
rasika-chivate Sep 7, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion .github/workflows/main.yml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,7 @@ jobs:

#Run check
- name: reviewdog
uses: vale-cli/vale-action@v2.1.1
uses: vale-cli/vale-action@v3.0.0
with:
vale_flags: "--glob=*.md"
# fail_on_error: true
Expand Down
25 changes: 20 additions & 5 deletions docs/logging.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -45,15 +45,30 @@

PCSM can output logs in two formats: human-readable text (default) and structured JSON.

#### Timestamp format

!!! admonition "Version added: 0.10.0"

PCSM writes every log timestamp in [RFC 3339 :octicons-link-external-16:](https://www.rfc-editor.org/rfc/rfc3339){:target="_blank"} format and always in UTC, also known as Zulu time. This applies to both text and JSON output.

Check notice on line 52 in docs/logging.md

View workflow job for this annotation

GitHub Actions / vale

[vale] docs/logging.md#L52 <Google.Acronyms>(https://developers.google.com/style/abbreviations) 

Spell out 'PCSM', if it's unfamiliar to the audience.
Raw output 
{"message":"Spell out 'PCSM', if it's unfamiliar to the audience.","location":{"path":"docs/logging.md","range":{"start":{"line":52,"column":1},"end":{"line":52,"column":5}}},"severity":"INFO","code":{"value":"Google.Acronyms","url":"https://developers.google.com/style/abbreviations"}}

Check notice on line 52 in docs/logging.md

View workflow job for this annotation

GitHub Actions / vale

[vale] docs/logging.md#L52 <Google.Acronyms>(https://developers.google.com/style/abbreviations) 

Spell out 'RFC', if it's unfamiliar to the audience.
Raw output 
{"message":"Spell out 'RFC', if it's unfamiliar to the audience.","location":{"path":"docs/logging.md","range":{"start":{"line":52,"column":37},"end":{"line":52,"column":40}}},"severity":"INFO","code":{"value":"Google.Acronyms","url":"https://developers.google.com/style/abbreviations"}}

Copilot AI Sep 7, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Updated the six timestamped text-log examples in docs/troubleshooting.md to RFC 3339 UTC format in commit 71a8c15.


```{.text .no-copy}
2026-06-02T10:43:46.854Z INF POST /start s=http
```

The format is `YYYY-MM-DDTHH:MM:SS.mmmZ`. The `T` separates the date from the time, and the trailing `Z` marks the timestamp as UTC, also known as Zulu time.

Using UTC provides a consistent timestamp regardless of the host's local timezone. This makes it easier to correlate PCSM logs with MongoDB logs, FTDC diagnostics, application logs, and monitoring systems without converting between local timezones.

Check notice on line 60 in docs/logging.md

View workflow job for this annotation

GitHub Actions / vale

[vale] docs/logging.md#L60 <Google.Acronyms>(https://developers.google.com/style/abbreviations) 

Spell out 'PCSM', if it's unfamiliar to the audience.
Raw output 
{"message":"Spell out 'PCSM', if it's unfamiliar to the audience.","location":{"path":"docs/logging.md","range":{"start":{"line":60,"column":118},"end":{"line":60,"column":122}}},"severity":"INFO","code":{"value":"Google.Acronyms","url":"https://developers.google.com/style/abbreviations"}}

Check notice on line 60 in docs/logging.md

View workflow job for this annotation

GitHub Actions / vale

[vale] docs/logging.md#L60 <Google.Acronyms>(https://developers.google.com/style/abbreviations) 

Spell out 'FTDC', if it's unfamiliar to the audience.
Raw output 
{"message":"Spell out 'FTDC', if it's unfamiliar to the audience.","location":{"path":"docs/logging.md","range":{"start":{"line":60,"column":147},"end":{"line":60,"column":151}}},"severity":"INFO","code":{"value":"Google.Acronyms","url":"https://developers.google.com/style/abbreviations"}}

Check warning on line 60 in docs/logging.md

View workflow job for this annotation

GitHub Actions / vale

[vale] docs/logging.md#L60 <Google.WordListCase>(https://developers.google.com/style/word-list) 

Use 'app' instead of 'application'.
Raw output 
{"message":"Use 'app' instead of 'application'.","location":{"path":"docs/logging.md","range":{"start":{"line":60,"column":165},"end":{"line":60,"column":176}}},"severity":"WARNING","code":{"value":"Google.WordListCase","url":"https://developers.google.com/style/word-list"}}


#### Text format (default)

By default, logs are printed to the console in a color-coded, human-readable format. This is ideal for interactive use and manual inspection.

??? example "Sample output"

```text
2024-10-26 14:30:01.000 INF s=http Starting HTTP server at http://localhost:2242
2024-10-26 14:30:05.123 DBG s=repl:watch op=insert ns=test.coll1 op_ts=1729953005,1
2026-06-02T10:43:46.854Z INF s=http Starting HTTP server at http://localhost:2242
2026-06-02T10:43:46.955Z DBG s=repl:watch op=insert ns=test.coll1 op_ts=1780397026,1

@chupe chupe Sep 15, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
2026-06-02T10:43:46.955Z DBG s=repl:watch op=insert ns=test.coll1 op_ts=1780397026,1
2026-06-02T10:43:46.955Z DBG s=repl:watch op=insert ns=test.coll1 op_ts=[1780397026,1]

```

You can disable the colorization with the `--log-no-color` flag. This is useful when redirecting log output to a file.
Expand Down Expand Up @@ -81,8 +96,8 @@
??? example "Sample output"

```json
{"level":"info","s":"http","time":"2024-10-01 14:30:01.000","message":"Starting HTTP server at http://localhost:2242"}
{"level":"debug","s":"repl:watch","op":"insert","ns":"test.coll1","op_ts":[1729953005,1],"time":"2024-10-26 14:30:05.123"}
{"level":"info","s":"http","time":"2026-06-02T10:43:46.854Z","message":"Starting HTTP server at http://localhost:2242"}
{"level":"debug","s":"repl:watch","op":"insert","ns":"test.coll1","op_ts":[1780397026,1],"time":"2026-06-02T10:43:46.955Z"}
```

### JSON field reference
Expand All @@ -95,7 +110,7 @@
| `s` | string | The scope or component where the log originated (e.g., http, clone, repl). |
| `ns` | string | The MongoDB namespace (database.collection) related to the event. |
| `elapsed_secs` | float | The time taken for an operation to complete, in seconds. |
| `time` | string | The timestamp of the log event in YYYY-MM-DD HH:MM:SS.ms format. |
| `time` | string | The timestamp of the log event in RFC 3339 format, always in UTC (`YYYY-MM-DDTHH:MM:SS.mmmZ`). |

Check notice on line 113 in docs/logging.md

View workflow job for this annotation

GitHub Actions / vale

[vale] docs/logging.md#L113 <Google.Acronyms>(https://developers.google.com/style/abbreviations) 

Spell out 'RFC', if it's unfamiliar to the audience.
Raw output 
{"message":"Spell out 'RFC', if it's unfamiliar to the audience.","location":{"path":"docs/logging.md","range":{"start":{"line":113,"column":63},"end":{"line":113,"column":66}}},"severity":"INFO","code":{"value":"Google.Acronyms","url":"https://developers.google.com/style/abbreviations"}}

Check notice on line 113 in docs/logging.md

View workflow job for this annotation

GitHub Actions / vale

[vale] docs/logging.md#L113 <Google.Parens>(https://developers.google.com/style/parentheses) 

Use parentheses judiciously.
Raw output 
{"message":"Use parentheses judiciously.","location":{"path":"docs/logging.md","range":{"start":{"line":113,"column":94},"end":{"line":113,"column":122}}},"severity":"INFO","code":{"value":"Google.Parens","url":"https://developers.google.com/style/parentheses"}}
| `message` | string | The main log message. |
| `error` | string | The error message, if an error occurred. |
| `op` | string | The type of operation (e.g., insert, createIndexes). |
Expand Down
12 changes: 6 additions & 6 deletions docs/troubleshooting.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,9 +13,9 @@ After subsequently starting the service, you may see such messages:
??? example "Sample error messages"

```{.text .no-copy}
2025-06-02 21:25:38.927 INF Found Recovery Data. Recovering... s=recovery
2026-06-02T10:43:46.854Z INF Found Recovery Data. Recovering... s=recovery
Error: new server: recover Percona ClusterSync for MongoDB: recover: cannot resume: replication is not started or not resuming from failure
2025-06-02 21:25:38.929 FTL error="new server: recover Percona ClusterSync for MongoDB: recover: cannot resume: replication is not started or not resuming from failure"
2026-06-02T10:43:46.856Z FTL error="new server: recover Percona ClusterSync for MongoDB: recover: cannot resume: replication is not started or not resuming from failure"
```

### Recovery steps
Expand Down Expand Up @@ -64,10 +64,10 @@ If PCSM exits abnormally or is stopped unexpectedly, restart the `pcsm` service.
??? example "Example logs"

```{.text .no-copy}
2025-06-02 21:32:04.592 INF Starting Cluster Replication s=pcsm
2025-06-02 21:32:04.592 DBG Change Replication is resuming s=repl
2025-06-02 21:32:04.592 INF Change Replication resumed op_ts=[1748887947,1] s=repl
2025-06-02 21:32:04.594 DBG Checkpoint saved s=checkpointing
2026-06-02T10:43:46.854Z INF Starting Cluster Replication s=pcsm
2026-06-02T10:43:46.854Z DBG Change Replication is resuming s=repl
2026-06-02T10:43:46.854Z INF Change Replication resumed op_ts=[1748887947,1] s=repl
2026-06-02T10:43:46.856Z DBG Checkpoint saved s=checkpointing
```

### Replication fails while PCSM is running
Expand Down
Loading