Add an encryption control character to the log lines

OctopusDeploy · Dec 2, 2024 · adeb9bc · adeb9bc
1 parent f4ed2ae
commit adeb9bc
Show file tree

Hide file tree

Showing 8 changed files with 70 additions and 25 deletions.
diff --git 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
@@ -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<ValidPodLogLineParseResult>().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
@@ -31,7 +31,7 @@ public async Task<byte[]> 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
@@ -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<byte[]> 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
@@ -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<ProcessOutput> PopLogs()
         {
             lock (logs)

diff --git a/...le/Kubernetes/IKubernetesPodLogService.cs → ...cle/Kubernetes/KubernetesPodLogService.cs b/...le/Kubernetes/IKubernetesPodLogService.cs → ...cle/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<ProcessOutput>(), lastLogSequence, null);

diff --git 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
@@ -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));
         }
     }
 }