Skip to content

Commit 1b9347b

Browse files
hawkowlhawkowl
authored
[ARO-22350] MISE Authorization Handler logging improvement & cleanup (#4439)
* add a helper to capture logs and output them on failure for debugging help * check for correctly parsed ipv6 * rewrite tests and do some refactoring for timeout verification * use the log context from the request if possible, and also fix up the fake args to make more sense * use a labelled type because I'm sick of trying to remember what it is when writing tests :) * add logging test coverage
1 parent c69a6b5 commit 1b9347b

File tree

23 files changed

+418
-207
lines changed

23 files changed

+418
-207
lines changed

‎pkg/backend/openshiftcluster_test.go‎

Lines changed: 9 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,6 @@ import (
1212
"testing"
1313

1414
"github.com/onsi/gomega"
15-
"github.com/onsi/gomega/types"
1615
"github.com/sirupsen/logrus"
1716
"go.uber.org/mock/gomock"
1817

@@ -483,7 +482,7 @@ func TestAsyncOperationResultLog(t *testing.T) {
483482
name string
484483
initialProvisioningState api.ProvisioningState
485484
backendErr error
486-
wantEntries []map[string]types.GomegaMatcher
485+
wantEntries []testlog.ExpectedLogEntry
487486
}{
488487
{
489488
name: "Success Status Code",
@@ -496,7 +495,7 @@ func TestAsyncOperationResultLog(t *testing.T) {
496495
Target: "target",
497496
},
498497
},
499-
wantEntries: []map[string]types.GomegaMatcher{
498+
wantEntries: []testlog.ExpectedLogEntry{
500499
{
501500
"LOGKIND": gomega.Equal("asyncqos"),
502501
"operationType": gomega.Equal("Succeeded"),
@@ -516,7 +515,7 @@ func TestAsyncOperationResultLog(t *testing.T) {
516515
Target: "target",
517516
},
518517
},
519-
wantEntries: []map[string]types.GomegaMatcher{
518+
wantEntries: []testlog.ExpectedLogEntry{
520519
{
521520
"LOGKIND": gomega.Equal("asyncqos"),
522521
"operationType": gomega.Equal("Failed"),
@@ -536,7 +535,7 @@ func TestAsyncOperationResultLog(t *testing.T) {
536535
Target: "target",
537536
},
538537
},
539-
wantEntries: []map[string]types.GomegaMatcher{
538+
wantEntries: []testlog.ExpectedLogEntry{
540539
{
541540
"LOGKIND": gomega.Equal("asyncqos"),
542541
"operationType": gomega.Equal("Failed"),
@@ -554,7 +553,7 @@ func TestAsyncOperationResultLog(t *testing.T) {
554553
&http.Response{StatusCode: http.StatusInternalServerError},
555554
"An error message",
556555
),
557-
wantEntries: []map[string]types.GomegaMatcher{
556+
wantEntries: []testlog.ExpectedLogEntry{
558557
{
559558
"LOGKIND": gomega.Equal("asyncqos"),
560559
"operationType": gomega.Equal("Failed"),
@@ -572,7 +571,7 @@ func TestAsyncOperationResultLog(t *testing.T) {
572571
&http.Response{StatusCode: http.StatusBadRequest},
573572
"An error message",
574573
),
575-
wantEntries: []map[string]types.GomegaMatcher{
574+
wantEntries: []testlog.ExpectedLogEntry{
576575
{
577576
"LOGKIND": gomega.Equal("asyncqos"),
578577
"operationType": gomega.Equal("Failed"),
@@ -589,7 +588,7 @@ func TestAsyncOperationResultLog(t *testing.T) {
589588
"methodName",
590589
"An error message",
591590
),
592-
wantEntries: []map[string]types.GomegaMatcher{
591+
wantEntries: []testlog.ExpectedLogEntry{
593592
{
594593
"LOGKIND": gomega.Equal("asyncqos"),
595594
"operationType": gomega.Equal("Failed"),
@@ -604,7 +603,7 @@ func TestAsyncOperationResultLog(t *testing.T) {
604603
backendErr: runtime.NewResponseError(
605604
&http.Response{StatusCode: http.StatusInternalServerError},
606605
),
607-
wantEntries: []map[string]types.GomegaMatcher{
606+
wantEntries: []testlog.ExpectedLogEntry{
608607
{
609608
"LOGKIND": gomega.Equal("asyncqos"),
610609
"operationType": gomega.Equal("Failed"),
@@ -619,7 +618,7 @@ func TestAsyncOperationResultLog(t *testing.T) {
619618
backendErr: runtime.NewResponseError(
620619
&http.Response{StatusCode: http.StatusUnauthorized},
621620
),
622-
wantEntries: []map[string]types.GomegaMatcher{
621+
wantEntries: []testlog.ExpectedLogEntry{
623622
{
624623
"LOGKIND": gomega.Equal("asyncqos"),
625624
"operationType": gomega.Equal("Failed"),

‎pkg/cluster/failurediagnostics/virtualmachines_test.go‎

Lines changed: 8 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,6 @@ import (
1414

1515
"github.com/go-test/deep"
1616
"github.com/onsi/gomega"
17-
"github.com/onsi/gomega/types"
1817
"github.com/sirupsen/logrus"
1918
"go.uber.org/mock/gomock"
2019

@@ -49,14 +48,14 @@ func TestVirtualMachinesSerialConsole(t *testing.T) {
4948
name string
5049
expectedOutput interface{}
5150
mock func(vmClient *mock_compute.MockVirtualMachinesClient)
52-
expectedLogs []map[string]types.GomegaMatcher
51+
expectedLogs []testlog.ExpectedLogEntry
5352
}{
5453
{
5554
name: "failure to fetch VMs",
5655
mock: func(vmClient *mock_compute.MockVirtualMachinesClient) {
5756
vmClient.EXPECT().List(gomock.Any(), "resourceGroupCluster").Return(nil, errors.New("vm explod"))
5857
},
59-
expectedLogs: []map[string]types.GomegaMatcher{},
58+
expectedLogs: []testlog.ExpectedLogEntry{},
6059
expectedOutput: []interface{}{
6160
"vm listing error: vm explod",
6261
},
@@ -66,7 +65,7 @@ func TestVirtualMachinesSerialConsole(t *testing.T) {
6665
mock: func(vmClient *mock_compute.MockVirtualMachinesClient) {
6766
vmClient.EXPECT().List(gomock.Any(), "resourceGroupCluster").Return([]mgmtcompute.VirtualMachine{}, nil)
6867
},
69-
expectedLogs: []map[string]types.GomegaMatcher{},
68+
expectedLogs: []testlog.ExpectedLogEntry{},
7069
expectedOutput: []interface{}{
7170
"no VMs found",
7271
},
@@ -92,7 +91,7 @@ func TestVirtualMachinesSerialConsole(t *testing.T) {
9291
gomock.Any(), "resourceGroupCluster", "somename", gomock.Any(),
9392
).Times(1).Return(errors.New("explod"))
9493
},
95-
expectedLogs: []map[string]types.GomegaMatcher{},
94+
expectedLogs: []testlog.ExpectedLogEntry{},
9695
expectedOutput: []interface{}{
9796
`vm somename: {"location":"eastus","properties":{}}`,
9897
"vm boot diagnostics retrieval error for somename: explod",
@@ -118,7 +117,7 @@ func TestVirtualMachinesSerialConsole(t *testing.T) {
118117
return err
119118
})
120119
},
121-
expectedLogs: []map[string]types.GomegaMatcher{
120+
expectedLogs: []testlog.ExpectedLogEntry{
122121
{
123122
"level": gomega.Equal(logrus.InfoLevel),
124123
"msg": gomega.Equal(`hello`),
@@ -154,7 +153,7 @@ func TestVirtualMachinesSerialConsole(t *testing.T) {
154153
return err
155154
})
156155
},
157-
expectedLogs: []map[string]types.GomegaMatcher{
156+
expectedLogs: []testlog.ExpectedLogEntry{
158157
{
159158
"level": gomega.Equal(logrus.InfoLevel),
160159
"msg": gomega.Equal(`hello`),
@@ -190,7 +189,7 @@ func TestVirtualMachinesSerialConsole(t *testing.T) {
190189
return err
191190
})
192191
},
193-
expectedLogs: []map[string]types.GomegaMatcher{},
192+
expectedLogs: []testlog.ExpectedLogEntry{},
194193
expectedOutput: []interface{}{
195194
`vm somename: {"location":"eastus","properties":{}}`,
196195
},
@@ -222,7 +221,7 @@ func TestVirtualMachinesSerialConsole(t *testing.T) {
222221
return err
223222
})
224223
},
225-
expectedLogs: []map[string]types.GomegaMatcher{
224+
expectedLogs: []testlog.ExpectedLogEntry{
226225
{
227226
"level": gomega.Equal(logrus.InfoLevel),
228227
"msg": gomega.Equal(`1aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa`),

‎pkg/cluster/gatherlogs_test.go‎

Lines changed: 8 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -10,7 +10,6 @@ import (
1010
"testing"
1111

1212
"github.com/onsi/gomega"
13-
"github.com/onsi/gomega/types"
1413
"github.com/sirupsen/logrus"
1514
"github.com/stretchr/testify/assert"
1615
"github.com/stretchr/testify/require"
@@ -174,7 +173,7 @@ func TestLogNodes(t *testing.T) {
174173
name string
175174
objects []kruntime.Object
176175
want interface{}
177-
wantLogs []map[string]types.GomegaMatcher
176+
wantLogs []testlog.ExpectedLogEntry
178177
wantErr string
179178
}{
180179
{
@@ -184,7 +183,7 @@ func TestLogNodes(t *testing.T) {
184183
master0Node.Name, corev1.ConditionTrue,
185184
master1Node.Name, corev1.ConditionFalse,
186185
master2Node.Name, corev1.ConditionUnknown),
187-
wantLogs: []map[string]types.GomegaMatcher{
186+
wantLogs: []testlog.ExpectedLogEntry{
188187
{
189188
"level": gomega.Equal(logrus.InfoLevel),
190189
"msg": gomega.Equal(asJson(master0Node)),
@@ -224,7 +223,7 @@ func TestLogClusterOperators(t *testing.T) {
224223
name string
225224
objects []kruntime.Object
226225
want interface{}
227-
wantLogs []map[string]types.GomegaMatcher
226+
wantLogs []testlog.ExpectedLogEntry
228227
wantErr string
229228
}{
230229
{
@@ -233,7 +232,7 @@ func TestLogClusterOperators(t *testing.T) {
233232
want: fmt.Sprintf("%s - Available: %s, Progressing: %s, Degraded: %s\n%s - Available: %s, Progressing: %s, Degraded: %s",
234233
aroOperator.Name, configv1.ConditionTrue, configv1.ConditionFalse, configv1.ConditionFalse,
235234
machineApiOperator.Name, configv1.ConditionFalse, configv1.ConditionUnknown, configv1.ConditionTrue),
236-
wantLogs: []map[string]types.GomegaMatcher{
235+
wantLogs: []testlog.ExpectedLogEntry{
237236
{
238237
"level": gomega.Equal(logrus.InfoLevel),
239238
"msg": gomega.Equal(asJson(aroOperator)),
@@ -269,15 +268,15 @@ func TestLogIngressControllers(t *testing.T) {
269268
name string
270269
objects []kruntime.Object
271270
want interface{}
272-
wantLogs []map[string]types.GomegaMatcher
271+
wantLogs []testlog.ExpectedLogEntry
273272
wantErr string
274273
}{
275274
{
276275
name: "returns simple IC output and logs full IC object",
277276
objects: []kruntime.Object{defaultIngressController},
278277
want: fmt.Sprintf("%s - Available: %s, Progressing: %s, Degraded: %s",
279278
defaultIngressController.Name, operatorv1.ConditionTrue, operatorv1.ConditionFalse, operatorv1.ConditionFalse),
280-
wantLogs: []map[string]types.GomegaMatcher{
279+
wantLogs: []testlog.ExpectedLogEntry{
281280
{
282281
"level": gomega.Equal(logrus.InfoLevel),
283282
"msg": gomega.Equal(asJson(defaultIngressController)),
@@ -309,7 +308,7 @@ func TestLogPodLogs(t *testing.T) {
309308
name string
310309
objects []kruntime.Object
311310
want interface{}
312-
wantLogs []map[string]types.GomegaMatcher
311+
wantLogs []testlog.ExpectedLogEntry
313312
wantErr string
314313
}{
315314
{
@@ -323,7 +322,7 @@ func TestLogPodLogs(t *testing.T) {
323322
fmt.Sprintf("pod status %s: %v", aroOperatorMasterPod.Name, aroOperatorMasterPod.Status),
324323
fmt.Sprintf("pod status %s: %v", aroOperatorWorkerPod.Name, aroOperatorWorkerPod.Status),
325324
},
326-
wantLogs: []map[string]types.GomegaMatcher{
325+
wantLogs: []testlog.ExpectedLogEntry{
327326
{
328327
"level": gomega.Equal(logrus.InfoLevel),
329328
"msg": gomega.Equal("fake logs"),

‎pkg/cluster/install_test.go‎

Lines changed: 4 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,6 @@ import (
1111
"time"
1212

1313
"github.com/onsi/gomega"
14-
"github.com/onsi/gomega/types"
1514
"github.com/sirupsen/logrus"
1615
"go.uber.org/mock/gomock"
1716

@@ -89,7 +88,7 @@ func TestStepRunnerWithInstaller(t *testing.T) {
8988
for _, tt := range []struct {
9089
name string
9190
steps []steps.Step
92-
wantEntries []map[string]types.GomegaMatcher
91+
wantEntries []testlog.ExpectedLogEntry
9392
wantErr string
9493
kubernetescli *fake.Clientset
9594
configcli *configfake.Clientset
@@ -102,7 +101,7 @@ func TestStepRunnerWithInstaller(t *testing.T) {
102101
steps.Action(failingFunc),
103102
},
104103
wantErr: "oh no!",
105-
wantEntries: []map[string]types.GomegaMatcher{
104+
wantEntries: []testlog.ExpectedLogEntry{
106105
{
107106
"level": gomega.Equal(logrus.InfoLevel),
108107
"msg": gomega.Equal(`running step [Action pkg/cluster.failingFunc]`),
@@ -159,7 +158,7 @@ func TestStepRunnerWithInstaller(t *testing.T) {
159158
steps.Action(failingFunc),
160159
},
161160
wantErr: "oh no!",
162-
wantEntries: []map[string]types.GomegaMatcher{
161+
wantEntries: []testlog.ExpectedLogEntry{
163162
{
164163
"level": gomega.Equal(logrus.InfoLevel),
165164
"msg": gomega.Equal(`running step [Action pkg/cluster.failingFunc]`),
@@ -208,7 +207,7 @@ func TestStepRunnerWithInstaller(t *testing.T) {
208207
steps.Action(failingFunc),
209208
},
210209
wantErr: "oh no!",
211-
wantEntries: []map[string]types.GomegaMatcher{
210+
wantEntries: []testlog.ExpectedLogEntry{
212211
{
213212
"level": gomega.Equal(logrus.InfoLevel),
214213
"msg": gomega.Equal(`running step [Action pkg/cluster.failingFunc]`),

‎pkg/cluster/loadbalancerinternal_test.go‎

Lines changed: 8 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,6 @@ import (
1111
"time"
1212

1313
"github.com/onsi/gomega"
14-
"github.com/onsi/gomega/types"
1514
"github.com/sirupsen/logrus"
1615
"go.uber.org/mock/gomock"
1716

@@ -43,7 +42,7 @@ func TestUpdateLoadBalancerZonalNoopAndErrorPaths(t *testing.T) {
4342
architectureVersion api.ArchitectureVersion
4443
mocks func(lbs *mock_armnetwork.MockLoadBalancersClient, sku *mock_compute.MockResourceSkusClient, plses *mock_armnetwork.MockPrivateLinkServicesClient)
4544
wantErrs []error
46-
expectedLogs []map[string]types.GomegaMatcher
45+
expectedLogs []testlog.ExpectedLogEntry
4746
}{
4847
{
4948
name: "noop -- already zone redundant",
@@ -66,7 +65,7 @@ func TestUpdateLoadBalancerZonalNoopAndErrorPaths(t *testing.T) {
6665
}, nil,
6766
)
6867
},
69-
expectedLogs: []map[string]types.GomegaMatcher{
68+
expectedLogs: []testlog.ExpectedLogEntry{
7069
{
7170
"level": gomega.Equal(logrus.InfoLevel),
7271
"msg": gomega.Equal("internal load balancer frontend IP already zone-redundant, no need to continue"),
@@ -108,7 +107,7 @@ func TestUpdateLoadBalancerZonalNoopAndErrorPaths(t *testing.T) {
108107
},
109108
}, nil)
110109
},
111-
expectedLogs: []map[string]types.GomegaMatcher{
110+
expectedLogs: []testlog.ExpectedLogEntry{
112111
{
113112
"level": gomega.Equal(logrus.InfoLevel),
114113
"msg": gomega.Equal("non-zonal control plane SKU, not adding zone-redundant frontend IP"),
@@ -146,7 +145,7 @@ func TestUpdateLoadBalancerZonalNoopAndErrorPaths(t *testing.T) {
146145
},
147146
}, nil)
148147
},
149-
expectedLogs: []map[string]types.GomegaMatcher{},
148+
expectedLogs: []testlog.ExpectedLogEntry{},
150149
wantErrs: []error{errVMAvailability},
151150
},
152151
{
@@ -172,7 +171,7 @@ func TestUpdateLoadBalancerZonalNoopAndErrorPaths(t *testing.T) {
172171

173172
sku.EXPECT().List(gomock.Any(), "location eq eastus").Return([]mgmtcompute.ResourceSku{}, errTestSKUFetchError)
174173
},
175-
expectedLogs: []map[string]types.GomegaMatcher{},
174+
expectedLogs: []testlog.ExpectedLogEntry{},
176175
wantErrs: []error{errListVMResourceSKUs, errTestSKUFetchError},
177176
},
178177
} {
@@ -259,14 +258,14 @@ func TestUpdateLoadBalancerZonalMigration(t *testing.T) {
259258
backendPoolName string
260259
mocks func(lbs *mock_armnetwork.MockLoadBalancersClient, sku *mock_compute.MockResourceSkusClient, plses *mock_armnetwork.MockPrivateLinkServicesClient)
261260
wantErr error
262-
expectedLogs []map[string]types.GomegaMatcher
261+
expectedLogs []testlog.ExpectedLogEntry
263262
}{
264263
{
265264
name: "performed, zonal, v2",
266265
architectureVersion: api.ArchitectureVersionV2,
267266
internalLBName: infraID + "-internal",
268267
backendPoolName: infraID,
269-
expectedLogs: []map[string]types.GomegaMatcher{
268+
expectedLogs: []testlog.ExpectedLogEntry{
270269
{
271270
"level": gomega.Equal(logrus.InfoLevel),
272271
"msg": gomega.Equal("load balancer zonal migration: starting critical section"),
@@ -302,7 +301,7 @@ func TestUpdateLoadBalancerZonalMigration(t *testing.T) {
302301
architectureVersion: api.ArchitectureVersionV1,
303302
internalLBName: infraID + "-internal-lb",
304303
backendPoolName: infraID + "-internal-controlplane-v4",
305-
expectedLogs: []map[string]types.GomegaMatcher{
304+
expectedLogs: []testlog.ExpectedLogEntry{
306305
{
307306
"level": gomega.Equal(logrus.InfoLevel),
308307
"msg": gomega.Equal("load balancer zonal migration: starting critical section"),

‎pkg/containerinstall/install_test.go‎

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,6 @@ import (
1818
"github.com/containers/podman/v5/pkg/bindings/secrets"
1919
"github.com/containers/podman/v5/pkg/domain/entities"
2020
"github.com/containers/podman/v5/pkg/specgen"
21-
"github.com/onsi/gomega/types"
2221
"github.com/opencontainers/runtime-spec/specs-go"
2322
"github.com/sirupsen/logrus"
2423
"github.com/sirupsen/logrus/hooks/test"
@@ -98,7 +97,7 @@ var _ = Describe("Podman", Ordered, func() {
9897
hook.Reset()
9998
err = getContainerLogs(conn, log, containerID)
10099
g.Expect(err).ToNot(HaveOccurred())
101-
entries := []map[string]types.GomegaMatcher{
100+
entries := []testlog.ExpectedLogEntry{
102101
{
103102
"msg": Equal("stdout: hello\n"),
104103
"level": Equal(logrus.InfoLevel),

0 commit comments

Comments
 (0)