Add extract logs to buildpack

Author: macsux

README.MD

@@ -21,7 +21,7 @@ applications:
   memory: 512M
   health-check-type: none
   buildpacks: 
-    - https://github.com/macsux/kerberos-buildpack/releases/download/WIP/KerberosBuildpack-linux-x64-WIP.zip
+    - https://github.com/macsux/kerberos-buildpack/releases/download/v1.0.6/KerberosBuildpack-linux-x64-v1.0.6.zip
     - dotnet_core_buildpack
   env:
     KRB5_KDC: ad.almirex.com
@@ -30,6 +30,8 @@ applications:
 
 ```
 
+** Adjust URL of the Kerberos buildpack to latest version. You can get the full zip URL from [Releases](https://github.com/macsux/kerberos-buildpack/releases) page.
+
 ## How it works
 
 ![](./docs/img/architecture.jpg)
@@ -49,26 +51,22 @@ Recommendation is to start with sample app included, which exposes the folowing
 
 After the app starts up you should see logs emitted from sidecar process that look like this:
 ```csharp
-   2022-01-26T16:04:52.80-0500 [PROXY/0] OUT Exit status 137
-   2022-01-26T16:04:52.87-0500 [APP/PROC/WEB/0] OUT info: Microsoft.Hosting.Lifetime[14]
-   2022-01-26T16:04:52.87-0500 [APP/PROC/WEB/0] OUT       Now listening on: http://0.0.0.0:9090
-   2022-01-26T16:04:52.88-0500 [APP/PROC/WEB/0] OUT info: Microsoft.Hosting.Lifetime[0]
-   2022-01-26T16:04:52.88-0500 [APP/PROC/WEB/0] OUT       Application started. Press Ctrl+C to shut down.
-   2022-01-26T16:04:52.88-0500 [APP/PROC/WEB/0] OUT info: Microsoft.Hosting.Lifetime[0]
-   2022-01-26T16:04:52.88-0500 [APP/PROC/WEB/0] OUT       Hosting environment: Production
-   2022-01-26T16:04:52.88-0500 [APP/PROC/WEB/0] OUT info: Microsoft.Hosting.Lifetime[0]
-   2022-01-26T16:04:52.88-0500 [APP/PROC/WEB/0] OUT       Content root path: /home/vcap/app/
-   2022-01-26T16:04:53.23-0500 [APP/PROC/WEB/0] OUT info: KerberosSidecar.KerberosWorker[0]
-   2022-01-26T16:04:53.23-0500 [APP/PROC/WEB/0] OUT       Service authenticated successfully as 'iwaclient'
-   2022-01-26T16:04:53.24-0500 [APP/PROC/WEB/0] OUT info: KerberosSidecar.Spn.LoggingSpnClient[0]
-   2022-01-26T16:04:53.24-0500 [APP/PROC/WEB/0] OUT       Ensure that the following SPN for the service exists: http/kerberosdemo.apps.longbeach.cf-app.com
+   2022-01-26T19:04:14.26-0500 [APP/PROC/WEB/0] OUT info: KerberosSidecar[0]
+   2022-01-26T19:04:14.26-0500 [APP/PROC/WEB/0] OUT       Kerberos sidecar started....
+   2022-01-26T19:04:14.74-0500 [APP/PROC/WEB/0] OUT info: KerberosSidecar.KerberosWorker[0]
+   2022-01-26T19:04:14.74-0500 [APP/PROC/WEB/0] OUT       Service authenticated successfully as 'iwaclient'
+   2022-01-26T19:04:14.75-0500 [APP/PROC/WEB/0] OUT info: KerberosSidecar.Spn.LoggingSpnClient[0]
+   2022-01-26T19:04:14.75-0500 [APP/PROC/WEB/0] OUT       Ensure that the following SPN for the service exists: http/kerberosdemo.apps.longbeach.cf-app.com
 ```
 
+* sidecar logs may be intermixed with app logs
+
 If you have not received a message similar to `Service authenticated successfully as 'iwaclient'`, it means that the worker sidecar has been unable to obtain ticket from your KDC.
 
 #### Things to check 
 
 - Sidecar process started, as indicated by log entry containing `Now listening on: http://0.0.0.0:9090`. (note port 9090 - there maybe similar log entry but for port 8080 - that one is for the main app).
 - Credentials are correct and specified in the right format
 - KDC is accessible from the container. Use `/testkdc` endpoint of sample app to test.
-- Any other errors coming from the logs
+- Acquire additional logging from sidercar by turning up Kerberos related log verbosity by adding the following env var:
+  - `Logging__LogLevel__Kerberos: Debug`

build/Build.cs

@@ -4,6 +4,7 @@
 using System.IO.Compression;
 using System.Linq;
 using System.Runtime.CompilerServices;
+using System.Text.RegularExpressions;
 using System.Threading.Tasks;
 using ICSharpCode.SharpZipLib.Zip;
 using NuGet.Configuration;
@@ -141,10 +142,14 @@ public bool IsGitHubRepository
         .Executes(() =>
         {
             var demoProjectDirectory = RootDirectory / "sample" / "KerberosDemo";
-            DotNetPublish(c => c
-                .SetProject(demoProjectDirectory / "KerberosDemo.csproj")
-                .SetConfiguration("DEBUG"));
+            // DotNetPublish(c => c
+            //     .SetProject(demoProjectDirectory / "KerberosDemo.csproj")
+            //     .SetConfiguration("DEBUG"));
             var publishFolder = demoProjectDirectory / "bin" / "Debug" / "net5.0" / "publish";
+            var manifestFile = publishFolder / "manifest.yml";
+            var manifest = File.ReadAllText(manifestFile);
+            manifest = manifest.ReplaceRegex(@"\r?\n\s*path:.+", match => match.Result(""));
+            File.WriteAllText(manifestFile, manifest);
             var artifactZip = ArtifactsDirectory / $"sampleapp-{Runtime}-{ReleaseName}.zip";
             DeleteFile(artifactZip);
             ZipFile.CreateFromDirectory(publishFolder, artifactZip, CompressionLevel.NoCompression, false);
@@ -194,7 +199,7 @@ public bool IsGitHubRepository
             {
                 var zipPackageLocation = ArtifactsDirectory / artifact;
                 var stream = File.OpenRead(zipPackageLocation);
-                var releaseAssetUpload = new ReleaseAssetUpload(PackageZipName, "application/zip", stream, TimeSpan.FromHours(1));
+                var releaseAssetUpload = new ReleaseAssetUpload(artifact, "application/zip", stream, TimeSpan.FromHours(1));
                 var releaseAsset = await client.Repository.Release.UploadAsset(release, releaseAssetUpload);
 
                 Logger.Block(releaseAsset.BrowserDownloadUrl);

sample/KerberosDemo/KerberosDemo.csproj

@@ -11,4 +11,10 @@
     <PackageReference Include="Swashbuckle.AspNetCore" Version="5.6.3" />
   </ItemGroup>
 
+  <ItemGroup>
+    <None Update="manifest.yml">
+      <CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
+    </None>
+  </ItemGroup>
+
 </Project>

sample/KerberosDemo/appsettings.json

@@ -1,8 +1,8 @@
 {
   "Logging": {
     "LogLevel": {
-      "Default": "Debug",
-      "Microsoft": "Debug",
+      "Default": "Information",
+      "Microsoft": "Warning",
       "Microsoft.Hosting.Lifetime": "Information"
     }
   },

sample/KerberosDemo/manifest.yml

@@ -5,7 +5,7 @@ applications:
   memory: 512M
   health-check-type: none
   buildpacks: 
-    - https://github.com/macsux/kerberos-buildpack/releases/download/WIP/KerberosBuildpack-linux-x64-WIP.zip
+    - https://github.com/macsux/kerberos-buildpack/releases/download/v1.0.6/KerberosBuildpack-linux-x64-v1.0.6.zip
     - dotnet_core_buildpack
   env:
     KRB5_KDC: dc1.macsux.com

src/KerberosBuildpack/KerberosBuildpack.cs

@@ -23,6 +23,7 @@ public class KerberosBuildpack : SupplyBuildpack
 
         protected override void Apply(AbsolutePath buildPath, AbsolutePath cachePath, AbsolutePath depsPath, int index)
         {
+            Console.WriteLine("==== Installing Kerberos Buildpack ==== ");
             var myDependenciesDirectory = depsPath / index.ToString(); // store any runtime dependencies not belonging to the app in this directory
             var krb5Dir = buildPath / ".krb5";
 
@@ -38,13 +39,16 @@ protected override void Apply(AbsolutePath buildPath, AbsolutePath cachePath, Ab
             var sidecarTargetDir = myDependenciesDirectory / "sidecar";
 
             FileSystemTasks.CopyDirectoryRecursively(sidecarSrcDir, sidecarTargetDir, DirectoryExistsPolicy.Merge, FileExistsPolicy.Overwrite);
+            Console.WriteLine($"Sidecar process copied into $HOME/deps/{index}/sidecar");
 
             var profiled = buildPath / ".profile.d";
             FileSystemTasks.EnsureExistingDirectory(profiled);
             var startSidecarScript = File.ReadAllText(currentAssemblyDir / "startsidecar.sh");
             startSidecarScript = startSidecarScript.Replace("@index", index.ToString());
-            var startSidecarScriptPath = profiled / $"{index:00}_{nameof(KerberosBuildpack)}_startsidecar.sh";
+            var startupScriptName = $"{index:00}_{nameof(KerberosBuildpack)}_startsidecar.sh";
+            var startSidecarScriptPath = profiled / startupScriptName;
             File.WriteAllText(startSidecarScriptPath, startSidecarScript);
+            Console.WriteLine($"Sidecar process startup script installed into $HOME/app/profile.d/{startupScriptName}");
             // below code attempts to use official way to introduce sidecar via buildpack as described here https://docs.cloudfoundry.org/buildpacks/sidecar-buildpacks.html
             // except it doesn't work and staging never completes - just hands with no error. workaround for now is to have process started as a background executable
             // stuffed into .profile.d startup script, but this makes logs emitted by sidecar show up as if originating from app

src/KerberosBuildpack/startsidecar.sh

@@ -1,6 +1,7 @@
 #!/bin/bash
 #set -ux
 #set +e
+cd $DEPS_DIR/0/sidecar/
 $DEPS_DIR/0/sidecar/KerberosSidecar --urls=http://0.0.0.0:9090 &
 
 #

src/KerberosSidecar/KerberosSidecar.csproj

@@ -17,7 +17,10 @@
   </ItemGroup>
 
   <ItemGroup>
-    <None Include="appsettings.Development.yaml" CopyToPublishDirectory="Never"/>
+    <None Include="appsettings.Development.yaml" CopyToPublishDirectory="Never" />
+    <None Update="appsettings.yaml">
+      <CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
+    </None>
   </ItemGroup>
 
 </Project>

src/KerberosSidecar/Program.cs

@@ -110,4 +110,5 @@
 {
     endpoints.MapHealthChecks("/health/ready", new HealthCheckOptions().WithJsonDetails());
 });
+app.Logger.LogInformation("Kerberos sidecar started....");
 await app.RunAsync();