Mask log trace
What does this MR do?
This adds support for masking variables. Rails API needs to annotate each variable to be masked with masked: true
flag.
From now one, the trace will be delayed until we are certain that it does not contain masked output.
It uses a Trie
type of search for efficient masked output search.
Why was this MR needed?
Are there points in the code the reviewer needs to double check?
Does this MR meet the acceptance criteria?
-
Documentation created/updated -
Added tests for this feature/bug -
In case of conflicts with master
- branch was rebased
What are the relevant issue numbers?
Merge request reports
Activity
- Resolved by Kamil Trzciński
- Resolved by Kamil Trzciński
@tmaczukin @matteeyah I have this working. Tested locally, it seems to mask correctly.
It adds a new feature send by Runner
features: { masked: true }
.It requires each masked variable to be annotated with
masked: true
, similar how they are annotated today withpublic: true
orfile: true
.Edited by Kamil Trzcińskichanged milestone to %11.9
added Deliverable devopsverify + 1 deleted label
@tmaczukin @steveazz I need your help on early review of this MR. I plan to slightly improve the implementation, and add a bunch of tests. Do you have any structural comments of what I should change?
- Resolved by Steve Xuereb
I need your help on early review of this MR. I plan to slightly improve the implementation, and add a bunch of tests. Do you have any structural comments of what I should change?
@ayufan The direction that it's going for is good, and I really like it. I don't have any feedback on the code as of yet.
- Resolved by Kamil Trzciński
There are few missing changes in the test files (related to changing
tracePatch.trace
frombytes.Buffer
to[]byte
):# gitlab.com/gitlab-org/gitlab-runner/network ./gitlab_test.go:706: cannot use trace (type bytes.Buffer) as type []byte in argument to newTracePatch ./trace_patch_test.go:14: cannot use *trace (type bytes.Buffer) as type []byte in argument to newTracePatch ./trace_patch_test.go:24: cannot use *trace (type bytes.Buffer) as type []byte in argument to newTracePatch ./trace_patch_test.go:30: cannot use *trace (type bytes.Buffer) as type []byte in argument to newTracePatch ./trace_patch_test.go:39: cannot use *trace (type bytes.Buffer) as type []byte in argument to newTracePatch
diff
diff --git a/network/gitlab_test.go b/network/gitlab_test.go index ae6089c0..6d09c54c 100644 --- a/network/gitlab_test.go +++ b/network/gitlab_test.go @@ -701,9 +701,7 @@ func getPatchServer(t *testing.T, handler func(w http.ResponseWriter, r *http.Re } func getTracePatch(traceString string, offset int) *tracePatch { - trace := bytes.Buffer{} - trace.WriteString(traceString) - tracePatch, _ := newTracePatch(trace, offset) + tracePatch, _ := newTracePatch([]byte(traceString), offset) return tracePatch } diff --git a/network/trace_patch_test.go b/network/trace_patch_test.go index ce936643..54061f8a 100644 --- a/network/trace_patch_test.go +++ b/network/trace_patch_test.go @@ -10,8 +10,7 @@ import ( var traceContent = "test content" func TestNewTracePatch(t *testing.T) { - trace := bytes.NewBufferString(traceContent) - tp, err := newTracePatch(*trace, 0) + tp, err := newTracePatch([]byte(traceContent), 0) assert.NoError(t, err) assert.Equal(t, 0, tp.Offset()) @@ -21,13 +20,12 @@ func TestNewTracePatch(t *testing.T) { func TestInvalidTracePatchInitialOffsetValue(t *testing.T) { trace := bytes.NewBufferString("test") - _, err := newTracePatch(*trace, trace.Len()+10) + _, err := newTracePatch([]byte("test"), trace.Len()+10) assert.EqualError(t, err, "Range is invalid, limit can't be less than offset") } func TestTracePatch_PatchAfterSetNewOffset(t *testing.T) { - trace := bytes.NewBufferString(traceContent) - tp, err := newTracePatch(*trace, 0) + tp, err := newTracePatch([]byte(traceContent), 0) assert.NoError(t, err) tp.SetNewOffset(5) @@ -35,8 +33,7 @@ func TestTracePatch_PatchAfterSetNewOffset(t *testing.T) { } func TestTracePatchEmptyPatch(t *testing.T) { - trace := bytes.NewBufferString(traceContent) - tp, err := newTracePatch(*trace, len(traceContent)) + tp, err := newTracePatch([]byte(traceContent), len(traceContent)) assert.NoError(t, err) assert.Empty(t, tp.Patch()) diff --git a/network/trace_test.go b/network/trace_test.go index 86a25a6c..852c3093 100644 --- a/network/trace_test.go +++ b/network/trace_test.go @@ -344,3 +344,17 @@ func TestFinalUpdateWithTrace(t *testing.T) { wg.Wait() } + +func TestVariablesMasking(t *testing.T) { + traceMessage := "This is the secret message containing secret values" + net := new(common.MockNetwork) + + trace := newJobTrace(net, jobConfig, jobCredentials) + trace.SetMasked([]string{"secret"}) + + trace.updateInterval = 500 * time.Microsecond + trace.start() + fmt.Fprint(trace, traceMessage) + + trace.finish() +} \ No newline at end of file
Edited by Tomasz Maczukin
- Resolved by Tomasz Maczukin
The thing that is obviously missing are the test. While testing the change manually I've found a strange failure, so maybe it would be good to add them now, even if the code is not finished yet?
For a reference:
The test
# ./network/trace_test.go func TestVariablesMasking(t *testing.T) { traceMessage := "This is the secret message containing secret values" maskedValues := []string{ "is", "secret", "containing", } wg := new(sync.WaitGroup) wg.Add(1) net := new(common.MockNetwork) defer net.AssertExpectations(t) net.On("PatchTrace", jobConfig, jobCredentials, mock.Anything). Return(common.UpdateSucceeded). Once(). Run(func(args mock.Arguments) { tracePatch, ok := args[2].(common.JobTracePatch) require.True(t, ok) t.Log(traceMessage) t.Log(string(tracePatch.Patch())) assert.Equal(t, "Th[MASKED] [MASKED] the [MASKED] message [MASKED] [MASKED] values", string(tracePatch.Patch())) }) net.On("UpdateJob", jobConfig, jobCredentials, mock.Anything). Return(common.UpdateSucceeded). Once(). Run(func(_ mock.Arguments) { wg.Done() }) trace := newJobTrace(net, jobConfig, jobCredentials) trace.SetMasked(maskedValues) trace.updateInterval = 25 * time.Second trace.start() fmt.Fprint(trace, traceMessage) trace.finish() wg.Wait() }
The test output (failing)
=== RUN TestVariablesMasking --- FAIL: TestVariablesMasking (0.00s) trace_test.go:368: This is the secret message containing secret values trace_test.go:369: Th[MASKED] [MASKED] the [MASKED] message [MASKED] [MASKED] value assertions.go:260: Error Trace: trace_test.go:370 mock_Network.go:31 trace.go:252 trace.go:319 trace.go:119 trace_test.go:387 Error: Not equal: expected: "Th[MASKED] [MASKED] the [MASKED] message [MASKED] [MASKED] values" actual : "Th[MASKED] [MASKED] the [MASKED] message [MASKED] [MASKED] value" Diff: --- Expected +++ Actual @@ -1 +1 @@ -Th[MASKED] [MASKED] the [MASKED] message [MASKED] [MASKED] values +Th[MASKED] [MASKED] the [MASKED] message [MASKED] [MASKED] value Test: TestVariablesMasking mock.go:456: PASS: PatchTrace(common.RunnerConfig,*common.JobCredentials,string) mock.go:456: PASS: UpdateJob(common.RunnerConfig,*common.JobCredentials,string) FAIL exit status 1 FAIL gitlab.com/gitlab-org/gitlab-runner/network 0.009s
The trace that is being sent is missing the last character. Just like
c.log.Bytes()[0:c.logMaskedSize]
fromsafeLog()
would lost one byte. It seems that increment ofc.logMaskedSize
is done wrong somewhere. But the code looks properly. So maybe there is something wrong in my test?
- Resolved by Kamil Trzciński
I have a feeling that
clientJobTrace
starts to be bloated with the number of methods and it's responsibilities. It rewrites the job output, it schedules patches/updates sending, it orchestrates the status changes... and now it's starting adjusting the content of the trace. Maybe we could move the trace masking code to an external object that would be just called by theclientJobTrace
internals? This could also make tests implementation easier and more unit-like
- Resolved by Tomasz Maczukin
Just thinking loud: should we disallow to set single characters as the masked variabes? Just imagine that someone adds variables containing
a
,b
or3
and make themmasked
. This would bloat the size of the trace significantly, waste a lot of CPU power since most of the output would probably contain such simple values.Maybe this is something that should be handled on Rails side, but I think it's something that we should think about.
- Resolved by Kamil Trzciński
- Resolved by Kamil Trzciński
- Resolved by Kamil Trzciński
One more thing - the MR doesn't contain changes in
vendor
.dep ensure
is required. We can wait with this for the final state of the MR, but I'll leave a note here so we will not forget about this
added 117 commits
-
41ffcb2f...9368cf24 - 115 commits from branch
master
- ab76182a - Add ability to mask variables.
- 8e6936c4 - Include trie library
-
41ffcb2f...9368cf24 - 115 commits from branch
@tmaczukin @steveazz
This is almost done. I likely miss one or two extra tests.
Also my
dep ensure
seems to be quite mangled. Can you check that?Can you comment WDYT?
Also my
dep ensure
seems to be quite mangled@ayufan I think this is because an old version of
dep
was used, when you randep ensure
. When updating tov0.5.0
should generate the correct input.Edited by Steve XuerebChecking. Yep. You are right! Thanks :)
Edited by Kamil Trzcińskiadded 2 commits
added 2 commits
added 2 commits
- Resolved by Tomasz Maczukin
- Resolved by Kamil Trzciński
- Resolved by Tomasz Maczukin
- Resolved by Kamil Trzciński
@ayufan Can we add a test similar as the one proposed by me at !1204 (comment 146801174)? While testing the
./helpers/trace/buffer.go
is good, I think we should have an integration-like test to see how it behaves when the buffer is used throughclientJobTrace
.
- Resolved by Kamil Trzciński
- Resolved by Kamil Trzciński
- Resolved by Kamil Trzciński
- Resolved by Kamil Trzciński
- Resolved by Kamil Trzciński
- Resolved by Kamil Trzciński
- Resolved by Kamil Trzciński
@ayufan this is awesome I learned about tire whilst reviewing this so thank you
I left a few questions.assigned to @ayufan
added 13 commits
-
a475bcf9...56efef02 - 11 commits from branch
master
- bb1e6c28 - Add ability to mask variables.
- 21d292f3 - Add `github.com/markelog/trie`
-
a475bcf9...56efef02 - 11 commits from branch
added 2 commits
assigned to @tmaczukin
@tmaczukin Can you review? I added last test.
- Resolved by Kamil Trzciński
Two last questions @ayufan looking good!
added 2 commits
LGTM, I'll leave it up to @tmaczukin to give the final
and merge.mentioned in commit 9ef63b5f
mentioned in merge request !1241 (merged)
mentioned in issue #3989 (closed)