From adeb9bc4e82550348e1867f7394327987db88574 Mon Sep 17 00:00:00 2001 From: Alastair Pitts Date: Mon, 2 Dec 2024 12:58:44 +1100 Subject: [PATCH] Add an encryption control character to the log lines --- .../bootstrapRunner/bootstrapRunner.go | 3 +- .../Kubernetes/PodLogLineParserFixture.cs | 18 +++++-- .../ScriptPodLogEncryptionKeyGenerator.cs | 2 +- .../ScriptPodLogEncryptionKeyProvider.cs | 4 +- .../Kubernetes/InMemoryTentacleScriptLog.cs | 10 ++++ ...gService.cs => KubernetesPodLogService.cs} | 2 +- .../Kubernetes/KubernetesScriptPodCreator.cs | 2 +- .../Kubernetes/PodLogLineParser.cs | 54 +++++++++++++------ 8 files changed, 70 insertions(+), 25 deletions(-) rename source/Octopus.Tentacle/Kubernetes/{IKubernetesPodLogService.cs => KubernetesPodLogService.cs} (99%) diff --git a/docker/kubernetes-agent-tentacle/bootstrapRunner/bootstrapRunner.go b/docker/kubernetes-agent-tentacle/bootstrapRunner/bootstrapRunner.go index e9586122a..0a3b30987 100644 --- a/docker/kubernetes-agent-tentacle/bootstrapRunner/bootstrapRunner.go +++ b/docker/kubernetes-agent-tentacle/bootstrapRunner/bootstrapRunner.go @@ -106,7 +106,8 @@ func Write(stream string, text string, counter *SafeCounter, gcm cipher.AEAD) { ciphertext := gcm.Seal(nonce, nonce, []byte(text), nil) - fmt.Printf("|%d|%s|%x\n", counter.Value, stream, ciphertext) + // the |e| indicates the line is encrypted (if we every supported plain, we'd put |p| here) + fmt.Printf("|e|%d|%s|%x\n", counter.Value, stream, ciphertext) counter.Value++ counter.Mutex.Unlock() diff --git a/source/Octopus.Tentacle.Tests/Kubernetes/PodLogLineParserFixture.cs b/source/Octopus.Tentacle.Tests/Kubernetes/PodLogLineParserFixture.cs index 237e9d784..2fda7bee7 100644 --- a/source/Octopus.Tentacle.Tests/Kubernetes/PodLogLineParserFixture.cs +++ b/source/Octopus.Tentacle.Tests/Kubernetes/PodLogLineParserFixture.cs @@ -52,16 +52,28 @@ public void ThirdPartIsNotAValidSource(string line) result.Error.Should().Contain("log level").And.Contain(line); } - [Test] - public void SimpleMessage() + [TestCase("2024-04-03T06:03:10.501025551Z |e|123|stdout|This is the message", true)] + [TestCase("2024-04-03T06:03:10.501025551Z |p|123|stdout|This is the message", false)] + //This is the previous log message format where we didn't have the encryption control section + [TestCase("2024-04-03T06:03:10.501025551Z |123|stdout|This is the message", false)] + public void SimpleMessage(string line, bool isLogMessageEncrypted) { - var logLine = PodLogLineParser.ParseLine($"2024-04-03T06:03:10.501025551Z |123|stdout|This is the message", encryptionProvider) + var logLine = PodLogLineParser.ParseLine(line, encryptionProvider) .Should().BeOfType().Subject.LogLine; logLine.LineNumber.Should().Be(123); logLine.Source.Should().Be(ProcessOutputSource.StdOut); logLine.Message.Should().Be("This is the message"); logLine.Occurred.Should().BeCloseTo(new DateTimeOffset(2024, 4, 3, 6, 3, 10, 501, TimeSpan.Zero), TimeSpan.FromMilliseconds(1)); + + if (isLogMessageEncrypted) + { + encryptionProvider.Received(1).Decrypt(Arg.Is("This is the message")); + } + else + { + encryptionProvider.DidNotReceive().Decrypt(Arg.Is("This is the message")); + } } [Test] diff --git a/source/Octopus.Tentacle/Kubernetes/Crypto/ScriptPodLogEncryptionKeyGenerator.cs b/source/Octopus.Tentacle/Kubernetes/Crypto/ScriptPodLogEncryptionKeyGenerator.cs index c448c75c7..fa65b64a8 100644 --- a/source/Octopus.Tentacle/Kubernetes/Crypto/ScriptPodLogEncryptionKeyGenerator.cs +++ b/source/Octopus.Tentacle/Kubernetes/Crypto/ScriptPodLogEncryptionKeyGenerator.cs @@ -31,7 +31,7 @@ public async Task GenerateKey(ScriptTicket scriptTicket, int keySizeInBy var pdb = new Pkcs5S2ParametersGenerator(new Sha256Digest()); //we use the machine encryption key as the password and the script ticket is the salt - pdb.Init(PbeParametersGenerator.Pkcs5PasswordToBytes(Encoding.ASCII.GetChars(machineEncryptionKey)), Encoding.UTF8.GetBytes(scriptTicket.TaskId), 1000); + pdb.Init(machineEncryptionKey, Encoding.UTF8.GetBytes(scriptTicket.TaskId), 1000); var key = (KeyParameter)pdb.GenerateDerivedMacParameters(keySizeInBytes * 8); return key.GetKey(); diff --git a/source/Octopus.Tentacle/Kubernetes/Crypto/ScriptPodLogEncryptionKeyProvider.cs b/source/Octopus.Tentacle/Kubernetes/Crypto/ScriptPodLogEncryptionKeyProvider.cs index 9bdab8c03..fa1bd42c0 100644 --- a/source/Octopus.Tentacle/Kubernetes/Crypto/ScriptPodLogEncryptionKeyProvider.cs +++ b/source/Octopus.Tentacle/Kubernetes/Crypto/ScriptPodLogEncryptionKeyProvider.cs @@ -10,7 +10,7 @@ namespace Octopus.Tentacle.Kubernetes.Crypto { public interface IScriptPodLogEncryptionKeyProvider { - Task WriteEncryptionKeyfileToWorkspace(ScriptTicket scriptTicket, CancellationToken cancellationToken); + Task GenerateAndWriteEncryptionKeyfileToWorkspace(ScriptTicket scriptTicket, CancellationToken cancellationToken); Task GetEncryptionKey(ScriptTicket scriptTicket, CancellationToken cancellationToken); void Delete(ScriptTicket scriptTicket); } @@ -32,7 +32,7 @@ public ScriptPodLogEncryptionKeyProvider(IScriptWorkspaceFactory scriptWorkspace this.log = log; } - public async Task WriteEncryptionKeyfileToWorkspace(ScriptTicket scriptTicket, CancellationToken cancellationToken) + public async Task GenerateAndWriteEncryptionKeyfileToWorkspace(ScriptTicket scriptTicket, CancellationToken cancellationToken) { if (encryptionKeyCache.ContainsKey(scriptTicket)) { diff --git a/source/Octopus.Tentacle/Kubernetes/InMemoryTentacleScriptLog.cs b/source/Octopus.Tentacle/Kubernetes/InMemoryTentacleScriptLog.cs index 66b0f2f43..3c83efc7e 100644 --- a/source/Octopus.Tentacle/Kubernetes/InMemoryTentacleScriptLog.cs +++ b/source/Octopus.Tentacle/Kubernetes/InMemoryTentacleScriptLog.cs @@ -27,6 +27,16 @@ public void Error(string message) logs.Add(new ProcessOutput(ProcessOutputSource.StdErr, message)); } + public void Warning(string message) + { + lock (logs) + { + logs.Add(new ProcessOutput(ProcessOutputSource.StdOut, "##octopus[stdout-warning]")); + logs.Add(new ProcessOutput(ProcessOutputSource.StdOut, message)); + logs.Add(new ProcessOutput(ProcessOutputSource.StdOut, "##octopus[stdout-default]")); + } + } + public IReadOnlyCollection PopLogs() { lock (logs) diff --git a/source/Octopus.Tentacle/Kubernetes/IKubernetesPodLogService.cs b/source/Octopus.Tentacle/Kubernetes/KubernetesPodLogService.cs similarity index 99% rename from source/Octopus.Tentacle/Kubernetes/IKubernetesPodLogService.cs rename to source/Octopus.Tentacle/Kubernetes/KubernetesPodLogService.cs index f2ef7fc93..e8d331344 100644 --- a/source/Octopus.Tentacle/Kubernetes/IKubernetesPodLogService.cs +++ b/source/Octopus.Tentacle/Kubernetes/KubernetesPodLogService.cs @@ -105,7 +105,7 @@ public KubernetesPodLogService( { //if we can't read the pod log encryption key for a while var message = $"Failed to read pod log encryption key. No new pod logs will be read."; - tentacleScriptLog.Verbose(message); + tentacleScriptLog.Warning(message); Log.Warn(ex, message); return (new List(), lastLogSequence, null); diff --git a/source/Octopus.Tentacle/Kubernetes/KubernetesScriptPodCreator.cs b/source/Octopus.Tentacle/Kubernetes/KubernetesScriptPodCreator.cs index 2c7021a0b..719791d1d 100644 --- a/source/Octopus.Tentacle/Kubernetes/KubernetesScriptPodCreator.cs +++ b/source/Octopus.Tentacle/Kubernetes/KubernetesScriptPodCreator.cs @@ -79,7 +79,7 @@ public async Task CreatePod(StartKubernetesScriptCommandV1 command, IScriptWorks log)) { //Write the log encryption key here - await scriptPodLogEncryptionKeyProvider.WriteEncryptionKeyfileToWorkspace(command.ScriptTicket, cancellationToken); + await scriptPodLogEncryptionKeyProvider.GenerateAndWriteEncryptionKeyfileToWorkspace(command.ScriptTicket, cancellationToken); //Possibly create the image pull secret name var imagePullSecretName = await CreateImagePullSecret(command, cancellationToken); diff --git a/source/Octopus.Tentacle/Kubernetes/PodLogLineParser.cs b/source/Octopus.Tentacle/Kubernetes/PodLogLineParser.cs index 75b02a68b..bad0cc51e 100644 --- a/source/Octopus.Tentacle/Kubernetes/PodLogLineParser.cs +++ b/source/Octopus.Tentacle/Kubernetes/PodLogLineParser.cs @@ -41,14 +41,14 @@ public InvalidPodLogLineParseResult(string error) Error = error; } } - + public class EndOfStreamPodLogLineParseResult : ValidPodLogLineParseResult { public override LogLineType Type => LogLineType.EndOfStream; public int ExitCode { get; } - public EndOfStreamPodLogLineParseResult( PodLogLine logLine, int exitCode) : base(logLine) + public EndOfStreamPodLogLineParseResult(PodLogLine logLine, int exitCode) : base(logLine) { ExitCode = exitCode; } @@ -62,23 +62,42 @@ static class PodLogLineParser public static PodLogLineParseResult ParseLine(string line, IPodLogEncryptionProvider encryptionProvider) { - var logParts = line.Split(new[] { '|' }, 4); - if (logParts.Length != 4) + var initialParts = line.Split(new[] { '|' }, 2); + + var datePart = initialParts[0]; + + var remainingMessage = initialParts[1]; + + //get the first 2 control chars and check + var encryptionControl = remainingMessage.Substring(0, 2); + + var isEncryptedMessage = false; + //there is an encryption control part at the start of the remaining message + if (encryptionControl.Equals("e|", StringComparison.Ordinal) || + encryptionControl.Equals("p|", StringComparison.Ordinal)) + { + isEncryptedMessage = encryptionControl[0] == 'e'; + + //we slice the encryption control from the start of the message, then parse as normal + remainingMessage = remainingMessage.Substring(2); + } + + var logParts = remainingMessage.Split(new[] { '|' }, 3); + if (logParts.Length != 3) { return new InvalidPodLogLineParseResult($"Pod log line is not correctly pipe-delimited: '{line}'"); } - var datePart = logParts[0]; - var lineNumberPart = logParts[1]; - var outputSourcePart = logParts[2]; - var encryptedMessagePart = logParts[3]; + var lineNumberPart = logParts[0]; + var outputSourcePart = logParts[1]; + var messagePart = logParts[2]; if (!DateTimeOffset.TryParse(datePart, out var occurred)) { return new InvalidPodLogLineParseResult($"Pod log timestamp '{datePart}' is invalid: '{line}'"); } - if (!int.TryParse(lineNumberPart, out int lineNumber)) + if (!int.TryParse(lineNumberPart, out var lineNumber)) { return new InvalidPodLogLineParseResult($"Pod log line number '{lineNumberPart}' is invalid: '{line}'"); } @@ -88,22 +107,25 @@ public static PodLogLineParseResult ParseLine(string line, IPodLogEncryptionProv return new InvalidPodLogLineParseResult($"Pod log level '{outputSourcePart}' is invalid: '{line}'"); } - //the log messages are being returned from the pods encrypted, decrypt them here - var decryptedMessagePath = encryptionProvider.Decrypt(encryptedMessagePart); - if (decryptedMessagePath.StartsWith(EndOfStreamMarkerPrefix)) + //if the log messages are being returned from the pods encrypted, decrypt them here + var logMessage = isEncryptedMessage + ? encryptionProvider.Decrypt(messagePart) + : messagePart; + + if (logMessage.StartsWith(EndOfStreamMarkerPrefix)) { try { - var exitCode = int.Parse(decryptedMessagePath.Split(new[] { EndOfStreamMarkerExitCodeDelimiter }, StringSplitOptions.None)[1]); - return new EndOfStreamPodLogLineParseResult(new PodLogLine(lineNumber, source, decryptedMessagePath, occurred), exitCode); + var exitCode = int.Parse(logMessage.Split(new[] { EndOfStreamMarkerExitCodeDelimiter }, StringSplitOptions.None)[1]); + return new EndOfStreamPodLogLineParseResult(new PodLogLine(lineNumber, source, logMessage, occurred), exitCode); } catch (Exception) { return new InvalidPodLogLineParseResult($"Pod log end of stream marker is invalid: '{line}'"); } } - - return new ValidPodLogLineParseResult(new PodLogLine(lineNumber, source, decryptedMessagePath, occurred)); + + return new ValidPodLogLineParseResult(new PodLogLine(lineNumber, source, logMessage, occurred)); } } } \ No newline at end of file