Skip to content

test: Add tests for parsing logs from init commands, tests for parsing of RFC3339 timestamps with different levels of precision #180

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
wants to merge 3 commits into
base: main
Choose a base branch
from
+175 −0
Open

test: Add tests for parsing logs from init commands, tests for parsing of RFC3339 timestamps with different levels of precision #180

Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
7eb671f
test: Add tests for parsing logs from init commands
SarahFrench Nov 17, 2025
da1cd7e
test: Compare parsing of `time.RFC3339` and `hclog.TimeFormat` format…
SarahFrench Nov 17, 2025
bac6efc
refactor: Remove use of `hashicorp/go-hclog` dependency
SarahFrench Nov 19, 2025
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
175 changes: 175 additions & 0 deletions logging_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ package tfjson

import (
"encoding/json"
"fmt"
"testing"
"time"

Expand Down Expand Up @@ -99,6 +100,59 @@ func TestLogging_generic(t *testing.T) {
}
}

// Checking what happens when Terraform core swaps from using time.RFC3339 to using hclog.TimeFormat when formatting
// timestamps for logs. We see that terraform-json is able to parse either log without issue, though precision is different
// as a consequence.
func TestLogging_timestampPrecision(t *testing.T) {

// The strings below are what you get when you take this time and use the Format method with different arguments.
// t := time.Date(2025, 11, 17, 18, 55, 01, 123456789, time.UTC)// "2025-11-17 18:55:01.123456789 +0000 UTC"
// t.Format(time.RFC3339) == "2025-11-17T18:55:01Z"
// t.Format(hclog.TimeFormat) == "2025-11-17T18:55:01.123Z"
timeRFC3339 := "2025-11-17T18:55:01Z"
hclogTimeFormat := "2025-11-17T18:55:01.123Z"

testCases := []struct {
rawMessage string
expectedMessage LogMsg
}{
{
fmt.Sprintf(`{"@level":"info","@message":"Testing out timestamps in time.RFC3339 format","@module":"terraform.ui","@timestamp":"%s","type":"log"}`,
timeRFC3339,
),
LogMessage{
baseLogMessage: baseLogMessage{
Lvl: Info,
Msg: "Testing out timestamps in time.RFC3339 format",
Time: time.Date(2025, 11, 17, 18, 55, 1, 0, time.UTC),
},
},
},
{
fmt.Sprintf(`{"@level":"info","@message":"Testing out timestamps in hclog.TimeFormat format","@module":"terraform.ui","@timestamp":"%s","type":"log"}`,
hclogTimeFormat,
),
LogMessage{
baseLogMessage: baseLogMessage{
Lvl: Info,
Msg: "Testing out timestamps in hclog.TimeFormat format",
Time: time.Date(2025, 11, 17, 18, 55, 1, 123000000, time.UTC),
},
},
},
}

for _, tc := range testCases {
msg, err := UnmarshalLogMessage([]byte(tc.rawMessage))
if err != nil {
t.Fatal(err)
}
if diff := cmp.Diff(tc.expectedMessage, msg, cmpOpts); diff != "" {
t.Fatalf("unexpected message: %s", diff)
}
}
}

func TestLogging_query(t *testing.T) {
testCases := []struct {
rawMessage string
Expand Down Expand Up @@ -165,3 +219,124 @@ func TestLogging_query(t *testing.T) {
}
}
}

// Includes a typical sequence of logs that happen when initializing a working directory
//
// Currently `init` creates some logs with "type":"log" and others with "type":"init_output"
// Type "init_output" logs include a specific field called "message_code" that takes a string value.
func TestLogging_init(t *testing.T) {
testCases := []struct {
rawMessage string
expectedMessage LogMsg
}{
{
`{"@level":"info","@message":"Terraform 1.15.0-dev","@module":"terraform.ui","@timestamp":"2025-11-17T17:17:58.540604Z","terraform":"1.15.0-dev","type":"version","ui":"1.2"}`,
VersionLogMessage{
baseLogMessage: baseLogMessage{
Lvl: Info,
Msg: "Terraform 1.15.0-dev",
Time: time.Date(2025, 11, 17, 17, 17, 58, 540604000, time.UTC),
},
Terraform: version.Must(version.NewSemver("1.15.0-dev")),
UI: version.Must(version.NewSemver("1.2.0")),
},
},
{
`{"@level":"info","@message":"Initializing provider plugins found in the configuration...","@module":"terraform.ui","@timestamp":"2025-11-17T17:18:04.314Z","message_code":"initializing_provider_plugin_from_config_message","type":"init_output"}`,
UnknownLogMessage{
baseLogMessage: baseLogMessage{
Lvl: Info,
Msg: "Initializing provider plugins found in the configuration...",
Time: time.Date(2025, 11, 17, 17, 18, 04, 314000000, time.UTC),
},
},
},
{
`{"@level":"info","@message":"hashicorp/aws: Finding latest version...","@module":"terraform.ui","@timestamp":"2025-11-17T17:18:04.314594Z","type":"log"}`,
LogMessage{
baseLogMessage: baseLogMessage{
Lvl: Info,
Msg: "hashicorp/aws: Finding latest version...",
Time: time.Date(2025, 11, 17, 17, 18, 04, 314594000, time.UTC),
},
},
},
{
`{"@level":"info","@message":"Installing provider version: hashicorp/aws v6.21.0...","@module":"terraform.ui","@timestamp":"2025-11-17T17:18:04.784659Z","type":"log"}`,
LogMessage{
baseLogMessage: baseLogMessage{
Lvl: Info,
Msg: "Installing provider version: hashicorp/aws v6.21.0...",
Time: time.Date(2025, 11, 17, 17, 18, 04, 784659000, time.UTC),
},
},
},
{
`{"@level":"info","@message":"Installed provider version: hashicorp/aws v6.21.0 (signed by HashiCorp)","@module":"terraform.ui","@timestamp":"2025-11-17T17:18:26.345919Z","type":"log"}`,
LogMessage{
baseLogMessage: baseLogMessage{
Lvl: Info,
Msg: "Installed provider version: hashicorp/aws v6.21.0 (signed by HashiCorp)",
Time: time.Date(2025, 11, 17, 17, 18, 26, 345919000, time.UTC),
},
},
},
{
`{"@level":"info","@message":"Initializing the backend...","@module":"terraform.ui","@timestamp":"2025-11-17T17:18:52.256Z","message_code":"initializing_backend_message","type":"init_output"}`,
UnknownLogMessage{
baseLogMessage: baseLogMessage{
Lvl: Info,
Msg: "Initializing the backend...",
Time: time.Date(2025, 11, 17, 17, 18, 52, 256000000, time.UTC),
},
},
},
// At this point in an init command's output there is a log message that isn't presented in JSON format:
// /*
// Successfully configured the backend "local"! Terraform will automatically
// use this backend unless the backend configuration changes.
// */
//
// See this GitHub issue: https://github.com/hashicorp/terraform/issues/37911
{
`{"@level":"info","@message":"Terraform has created a lock file .terraform.lock.hcl to record the provider\nselections it made above. Include this file in your version control repository\nso that Terraform can guarantee to make the same selections by default when\nyou run \"terraform init\" in the future.","@module":"terraform.ui","@timestamp":"2025-11-17T17:19:06.698Z","message_code":"lock_info","type":"init_output"}`,
UnknownLogMessage{
baseLogMessage: baseLogMessage{
Lvl: Info,
Msg: "Terraform has created a lock file .terraform.lock.hcl to record the provider\nselections it made above. Include this file in your version control repository\nso that Terraform can guarantee to make the same selections by default when\nyou run \"terraform init\" in the future.",
Time: time.Date(2025, 11, 17, 17, 19, 06, 698000000, time.UTC),
},
},
},
{
`{"@level":"info","@message":"Terraform has been successfully initialized!","@module":"terraform.ui","@timestamp":"2025-11-17T17:19:09.915Z","message_code":"output_init_success_message","type":"init_output"}`,
UnknownLogMessage{
baseLogMessage: baseLogMessage{
Lvl: Info,
Msg: "Terraform has been successfully initialized!",
Time: time.Date(2025, 11, 17, 17, 19, 9, 915000000, time.UTC),
},
},
},
{
`{"@level":"info","@message":"You may now begin working with Terraform. Try running \"terraform plan\" to see\nany changes that are required for your infrastructure. All Terraform commands\nshould now work.\n\nIf you ever set or change modules or backend configuration for Terraform,\nrerun this command to reinitialize your working directory. If you forget, other\ncommands will detect it and remind you to do so if necessary.","@module":"terraform.ui","@timestamp":"2025-11-17T17:19:10.553Z","message_code":"output_init_success_cli_message","type":"init_output"}`,
UnknownLogMessage{
baseLogMessage: baseLogMessage{
Lvl: Info,
Msg: "You may now begin working with Terraform. Try running \"terraform plan\" to see\nany changes that are required for your infrastructure. All Terraform commands\nshould now work.\n\nIf you ever set or change modules or backend configuration for Terraform,\nrerun this command to reinitialize your working directory. If you forget, other\ncommands will detect it and remind you to do so if necessary.",
Time: time.Date(2025, 11, 17, 17, 19, 10, 553000000, time.UTC),
},
},
},
}

for _, tc := range testCases {
msg, err := UnmarshalLogMessage([]byte(tc.rawMessage))
if err != nil {
t.Fatal(err)
}
if diff := cmp.Diff(tc.expectedMessage, msg, cmpOpts); diff != "" {
t.Fatalf("unexpected message: %s", diff)
}
}
}