Skip to content

Commit eb52e87

Browse files
SarahFrenchSarahFrench
authored
test: Add tests for parsing logs from init commands, tests for parsing of RFC3339 timestamps with different levels of precision (#180)
1 parent c3ffb45 commit eb52e87

File tree

1 file changed

+175
-0
lines changed

1 file changed

+175
-0
lines changed

‎logging_test.go‎

Lines changed: 175 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@ package tfjson
44

55
import (
66
"encoding/json"
7+
"fmt"
78
"testing"
89
"time"
910

@@ -99,6 +100,59 @@ func TestLogging_generic(t *testing.T) {
99100
}
100101
}
101102

103+
// Checking what happens when Terraform core swaps from using time.RFC3339 to using hclog.TimeFormat when formatting
104+
// timestamps for logs. We see that terraform-json is able to parse either log without issue, though precision is different
105+
// as a consequence.
106+
func TestLogging_timestampPrecision(t *testing.T) {
107+
108+
// The strings below are what you get when you take this time and use the Format method with different arguments.
109+
// t := time.Date(2025, 11, 17, 18, 55, 01, 123456789, time.UTC)// "2025-11-17 18:55:01.123456789 +0000 UTC"
110+
// t.Format(time.RFC3339) == "2025-11-17T18:55:01Z"
111+
// t.Format(hclog.TimeFormat) == "2025-11-17T18:55:01.123Z"
112+
timeRFC3339 := "2025-11-17T18:55:01Z"
113+
hclogTimeFormat := "2025-11-17T18:55:01.123Z"
114+
115+
testCases := []struct {
116+
rawMessage string
117+
expectedMessage LogMsg
118+
}{
119+
{
120+
fmt.Sprintf(`{"@level":"info","@message":"Testing out timestamps in time.RFC3339 format","@module":"terraform.ui","@timestamp":"%s","type":"log"}`,
121+
timeRFC3339,
122+
),
123+
LogMessage{
124+
baseLogMessage: baseLogMessage{
125+
Lvl: Info,
126+
Msg: "Testing out timestamps in time.RFC3339 format",
127+
Time: time.Date(2025, 11, 17, 18, 55, 1, 0, time.UTC),
128+
},
129+
},
130+
},
131+
{
132+
fmt.Sprintf(`{"@level":"info","@message":"Testing out timestamps in hclog.TimeFormat format","@module":"terraform.ui","@timestamp":"%s","type":"log"}`,
133+
hclogTimeFormat,
134+
),
135+
LogMessage{
136+
baseLogMessage: baseLogMessage{
137+
Lvl: Info,
138+
Msg: "Testing out timestamps in hclog.TimeFormat format",
139+
Time: time.Date(2025, 11, 17, 18, 55, 1, 123000000, time.UTC),
140+
},
141+
},
142+
},
143+
}
144+
145+
for _, tc := range testCases {
146+
msg, err := UnmarshalLogMessage([]byte(tc.rawMessage))
147+
if err != nil {
148+
t.Fatal(err)
149+
}
150+
if diff := cmp.Diff(tc.expectedMessage, msg, cmpOpts); diff != "" {
151+
t.Fatalf("unexpected message: %s", diff)
152+
}
153+
}
154+
}
155+
102156
func TestLogging_query(t *testing.T) {
103157
testCases := []struct {
104158
rawMessage string
@@ -166,3 +220,124 @@ func TestLogging_query(t *testing.T) {
166220
}
167221
}
168222
}
223+
224+
// Includes a typical sequence of logs that happen when initializing a working directory
225+
//
226+
// Currently `init` creates some logs with "type":"log" and others with "type":"init_output"
227+
// Type "init_output" logs include a specific field called "message_code" that takes a string value.
228+
func TestLogging_init(t *testing.T) {
229+
testCases := []struct {
230+
rawMessage string
231+
expectedMessage LogMsg
232+
}{
233+
{
234+
`{"@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"}`,
235+
VersionLogMessage{
236+
baseLogMessage: baseLogMessage{
237+
Lvl: Info,
238+
Msg: "Terraform 1.15.0-dev",
239+
Time: time.Date(2025, 11, 17, 17, 17, 58, 540604000, time.UTC),
240+
},
241+
Terraform: version.Must(version.NewSemver("1.15.0-dev")),
242+
UI: version.Must(version.NewSemver("1.2.0")),
243+
},
244+
},
245+
{
246+
`{"@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"}`,
247+
UnknownLogMessage{
248+
baseLogMessage: baseLogMessage{
249+
Lvl: Info,
250+
Msg: "Initializing provider plugins found in the configuration...",
251+
Time: time.Date(2025, 11, 17, 17, 18, 04, 314000000, time.UTC),
252+
},
253+
},
254+
},
255+
{
256+
`{"@level":"info","@message":"hashicorp/aws: Finding latest version...","@module":"terraform.ui","@timestamp":"2025-11-17T17:18:04.314594Z","type":"log"}`,
257+
LogMessage{
258+
baseLogMessage: baseLogMessage{
259+
Lvl: Info,
260+
Msg: "hashicorp/aws: Finding latest version...",
261+
Time: time.Date(2025, 11, 17, 17, 18, 04, 314594000, time.UTC),
262+
},
263+
},
264+
},
265+
{
266+
`{"@level":"info","@message":"Installing provider version: hashicorp/aws v6.21.0...","@module":"terraform.ui","@timestamp":"2025-11-17T17:18:04.784659Z","type":"log"}`,
267+
LogMessage{
268+
baseLogMessage: baseLogMessage{
269+
Lvl: Info,
270+
Msg: "Installing provider version: hashicorp/aws v6.21.0...",
271+
Time: time.Date(2025, 11, 17, 17, 18, 04, 784659000, time.UTC),
272+
},
273+
},
274+
},
275+
{
276+
`{"@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"}`,
277+
LogMessage{
278+
baseLogMessage: baseLogMessage{
279+
Lvl: Info,
280+
Msg: "Installed provider version: hashicorp/aws v6.21.0 (signed by HashiCorp)",
281+
Time: time.Date(2025, 11, 17, 17, 18, 26, 345919000, time.UTC),
282+
},
283+
},
284+
},
285+
{
286+
`{"@level":"info","@message":"Initializing the backend...","@module":"terraform.ui","@timestamp":"2025-11-17T17:18:52.256Z","message_code":"initializing_backend_message","type":"init_output"}`,
287+
UnknownLogMessage{
288+
baseLogMessage: baseLogMessage{
289+
Lvl: Info,
290+
Msg: "Initializing the backend...",
291+
Time: time.Date(2025, 11, 17, 17, 18, 52, 256000000, time.UTC),
292+
},
293+
},
294+
},
295+
// At this point in an init command's output there is a log message that isn't presented in JSON format:
296+
// /*
297+
// Successfully configured the backend "local"! Terraform will automatically
298+
// use this backend unless the backend configuration changes.
299+
// */
300+
//
301+
// See this GitHub issue: https://github.com/hashicorp/terraform/issues/37911
302+
{
303+
`{"@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"}`,
304+
UnknownLogMessage{
305+
baseLogMessage: baseLogMessage{
306+
Lvl: Info,
307+
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.",
308+
Time: time.Date(2025, 11, 17, 17, 19, 06, 698000000, time.UTC),
309+
},
310+
},
311+
},
312+
{
313+
`{"@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"}`,
314+
UnknownLogMessage{
315+
baseLogMessage: baseLogMessage{
316+
Lvl: Info,
317+
Msg: "Terraform has been successfully initialized!",
318+
Time: time.Date(2025, 11, 17, 17, 19, 9, 915000000, time.UTC),
319+
},
320+
},
321+
},
322+
{
323+
`{"@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"}`,
324+
UnknownLogMessage{
325+
baseLogMessage: baseLogMessage{
326+
Lvl: Info,
327+
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.",
328+
Time: time.Date(2025, 11, 17, 17, 19, 10, 553000000, time.UTC),
329+
},
330+
},
331+
},
332+
}
333+
334+
for _, tc := range testCases {
335+
msg, err := UnmarshalLogMessage([]byte(tc.rawMessage))
336+
if err != nil {
337+
t.Fatal(err)
338+
}
339+
if diff := cmp.Diff(tc.expectedMessage, msg, cmpOpts); diff != "" {
340+
t.Fatalf("unexpected message: %s", diff)
341+
}
342+
}
343+
}

0 commit comments

Comments
 (0)