Unable to retrieve Container logs with invalid utf-8 sequences (panic)

[aureq]

Describe what happened

(Related to this Slack thread)

While investigating the thread mentioned above, I create a basic container printing garbage utf-8 sequences.
While I couldn't get the same error message as our customer, I found 4 occurrences of a crash when calling the datasource Docker.GetLogs().

The app consists of:

• A C# Pulumi app
• A basic `Dockerfile
• A Bash shell script echoing the sequences

Sample program

Program.cs

using System;
using System.Collections.Generic;
using Pulumi;
using Pulumi.Docker;

return await Deployment.RunAsync(() =>
{
    var imageName = "my-sample-app";

    var MyDockerProvider = new Pulumi.Docker.Provider("docker-provider", new ProviderArgs
    {
        CertPath = "/home/aureq/.docker",
    });

    var MyDockerImage = new Image("docker-image", new ImageArgs
    {
        Build = new Pulumi.Docker.Inputs.DockerBuildArgs
        {
            Context = ".",
            Dockerfile = "Dockerfile",
            Platform = "linux/amd64",
        },
        ImageName = $"{imageName}:v1.0.0",
        SkipPush = true,

    }, new CustomResourceOptions
    {
        Provider = MyDockerProvider,
    });

    var MyDockerContainer = new Pulumi.Docker.Container("docker-container", new ContainerArgs
    {
        Name = imageName,
        Image = MyDockerImage.Id,
        Attach = true,
        Logs = true,
        MustRun = false,

    }, new CustomResourceOptions
    {
        Provider = MyDockerProvider,
    });

    var MyDockerContainerLogs = Pulumi.Output.All(MyDockerContainer.Name, MyDockerContainer.Id).Apply(values =>
    {
        var containerName = values[0];
        var containerId = values[1];

        var containerLogs = Pulumi.Docker.GetLogs.InvokeAsync(new GetLogsArgs
        {
            Name = containerName,
            Follow = true,
            ShowStdout = true,
            ShowStderr = true,
        }, new InvokeOptions
        {
            Provider = MyDockerProvider,
            Parent = MyDockerContainer,
        });
        System.Console.WriteLine($"Name: {containerName}, Id: {containerId}");
        return containerLogs;
    });

    // Export outputs here
    return new Dictionary<string, object?>
    {
        // ["MyDockerContainerLogs"] = MyDockerContainerLogs.Apply(logList => logList.LogsListStrings),
        ["MyDockerContainer"] = MyDockerContainer.ContainerLogs
    };
});

Dockerfile

FROM debian:latest

COPY app/entrypoint.sh /
RUN chmod 0755 /entrypoint.sh

CMD ["/entrypoint.sh"]

app/entrypoint.sh

#!/bin/bash

generate_invalid_utf8() {
    # Array of invalid UTF-8 byte sequences
    invalid_sequences=(
        "a"                         # valid ASCII
        "\xc3\xb1"                  # Valid 2 Octet Sequence
        "\xc3\x28"                  # Invalid 2 Octet Sequence
        "\xa0\xa1"                  # Invalid Sequence Identifier
        "\xe2\x28\xa1"              # Valid 3 Octet Sequence
        "\xe2\x28\xa1"              # Invalid 3 Octet Sequence (in 2nd Octet)
        "\xe2\x82\x28"              # Invalid 3 Octet Sequence (in 3rd Octet)
        "\xf0\x90\x8c\xbc"          # Valid 4 Octet Sequence
        "\xf0\x28\x8c\xbc"          # Invalid 4 Octet Sequence (in 2nd Octet)
        "\xf0\x90\x28\xbc"          # Invalid 4 Octet Sequence (in 3rd Octet)
        "\xf0\x28\x8c\x28"          # Invalid 4 Octet Sequence (in 4th Octet)
        "\xf8\xa1\xa1\xa1\xa1"      # Valid 5 Octet Sequence (but not Unicode!)
        "\xfc\xa1\xa1\xa1\xa1\xa1"  # Valid 6 Octet Sequence (but not Unicode!)
        "\xF0\xA4\xAD\xA2"          # Invalid Sequence
        "\xC0\xAF"                  # Overlong encoding of '/'
        # "\xE0\x80\xAF"              # Overlong encoding of '/'                      # crash 1: crash docker:index/getLogs:getLogs
        "\xF0\x80\x80\xAF"          # Overlong encoding of '/'
        "\xF8\x80\x80\x80\xAF"      # Invalid 5-byte sequence
        "\xFC\x80\x80\x80\x80\xAF"  # Invalid 6-byte sequence
        "\xC1\xBF"                  # Overlong encoding of '?'
        # "\xE0\x9F\xBF"              # Overlong encoding of '?'                      # crash 2: crash docker:index/getLogs:getLogs
        "\xF0\x8F\xBF\xBF"          # Overlong encoding of '?'
        # "\xED\xA0\x80"              # Surrogate half (high)                         # crash 3: crash docker:index/getLogs:getLogs
        # "\xED\xBF\xBF"              # Surrogate half (low)                          # crash 4: crash docker:index/getLogs:getLogs
        "\xF5\x90\x80\x80"          # Invalid code point (greater than U+10FFFF)
        "\x80"                      # Lone continuation byte
        "\xC2"                      # Start byte without continuation
        "\xE1\x80"                  # Two-byte start without continuation
        # "\xF1\x80\x80"              # Three-byte start without continuation         # crash 5: crash docker:index/getLogs:getLogs
    )

    echo "Generating invalid UTF-8 sequences:"

    # Iterate over the array and display each invalid sequence
    for seq in "${invalid_sequences[@]}"; do
        echo -e "$seq"
    done
}

generate_invalid_utf8

Log output

After a close look, the 5 different test cases all generate the same crash.

    Name: my-sample-app, Id: 2dbe29309f6e9934c873a28076f7fdd26aa2692a3e963cbde2c38633af67f403

    panic: runtime error: slice bounds out of range [8:7]
    goroutine 142 [running]:
    github.com/terraform-providers/terraform-provider-docker/internal/provider.dataSourceDockerLogsRead({0x194d2d0, 0xc0002b2d20}, 0x0?, {0x13a6560?, 0xc0006da310?})
        /home/runner/work/pulumi-docker/pulumi-docker/upstream/internal/provider/data_source_docker_logs.go:118 +0x838
    github.com/hashicorp/terraform-plugin-sdk/v2/helper/schema.(*Resource).read(0xc0007bf5e0, {0x194d228, 0xc0009e1470}, 0xd?, {0x13a6560, 0xc0006da310})
        /home/runner/go/pkg/mod/github.com/pulumi/terraform-plugin-sdk/[email protected]/helper/schema/resource.go:795 +0x11b
    github.com/hashicorp/terraform-plugin-sdk/v2/helper/schema.(*Resource).ReadDataApply(0xc0007bf5e0, {0x194d228, 0xc0009e1470}, 0xc000711600, {0x13a6560, 0xc0006da310})
        /home/runner/go/pkg/mod/github.com/pulumi/terraform-plugin-sdk/[email protected]/helper/schema/resource.go:1015 +0x149
    github.com/pulumi/pulumi-terraform-bridge/v3/pkg/tfshim/sdk-v2.v2Provider.ReadDataApply({0xc00068c720?, {0x0?, 0xc000d07330?, 0x12c3afa?}}, {0x194d228, 0xc0009e1470}, {0x16cdefa, 0xb}, {0x1951100, 0xc000711600})
        /home/runner/go/pkg/mod/github.com/pulumi/pulumi-terraform-bridge/[email protected]/pkg/tfshim/sdk-v2/provider.go:197 +0xcb
    github.com/pulumi/pulumi-terraform-bridge/v3/pkg/tfbridge.(*Provider).Invoke(0xc0003f7300, {0x194d228?, 0xc0009e1110?}, 0xc000154040)
        /home/runner/go/pkg/mod/github.com/pulumi/pulumi-terraform-bridge/[email protected]/pkg/tfbridge/provider.go:1564 +0xb4f
    github.com/pulumi/pulumi-docker/provider/v4.dockerHybridProvider.Invoke({{}, {0x24b7f00, 0x29922, 0x29922}, {0x19327f8, 0x6}, {0x195fc00, 0xc0003f7300}, {0x195fa90, 0xc000728d20}}, ...)
        /home/runner/work/pulumi-docker/pulumi-docker/provider/hybrid.go:99 +0xdc
    github.com/pulumi/pulumi/sdk/v3/proto/go._ResourceProvider_Invoke_Handler.func1({0x194d228, 0xc0009e1110}, {0x158f420?, 0xc000154040})
        /home/runner/go/pkg/mod/github.com/pulumi/pulumi/sdk/[email protected]/proto/go/provider_grpc.pb.go:500 +0x75
    github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1({0x194d228, 0xc0009e0ea0}, {0x158f420, 0xc000154040}, 0xc0009deb00, 0xc0009d07c8)
        /home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/go/otgrpc/server.go:57 +0x3d0
    github.com/pulumi/pulumi/sdk/v3/proto/go._ResourceProvider_Invoke_Handler({0x1651340?, 0xc0006f9bd0}, {0x194d228, 0xc0009e0ea0}, 0xc000257000, 0xc000646240)
        /home/runner/go/pkg/mod/github.com/pulumi/pulumi/sdk/[email protected]/proto/go/provider_grpc.pb.go:502 +0x135
    google.golang.org/grpc.(*Server).processUnaryRPC(0xc00055d000, {0x194d228, 0xc0009e0e10}, {0x195b440, 0xc00028ad80}, 0xc000b059e0, 0xc000a88c90, 0x24ffcc0, 0x0)
        /home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1369 +0xe23
    google.golang.org/grpc.(*Server).handleStream(0xc00055d000, {0x195b440, 0xc00028ad80}, 0xc000b059e0)
        /home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1780 +0x1016
    google.golang.org/grpc.(*Server).serveStreams.func2.1()
        /home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1019 +0x8b
    created by google.golang.org/grpc.(*Server).serveStreams.func2 in goroutine 84
        /home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1030 +0x135

    error: Running program '/home/aureq/work/customers/securitas-sps/5336/bin/Debug/net6.0/zendesk.dll' failed with an unhandled exception:
    Grpc.Core.RpcException: Status(StatusCode="Unknown", Detail="invocation of docker:index/getLogs:getLogs returned an error: error reading from server: EOF")
       at async Task<InvokeResponse> Pulumi.GrpcMonitor.InvokeAsync(ResourceInvokeRequest request)
       at async Task<SerializationResult> Pulumi.Deployment.InvokeRawAsync(string token, SerializationResult argsSerializationResult, InvokeOptions options) x 2
       at async Task<T> Pulumi.Deployment.InvokeAsync<T>(string token, InvokeArgs args, InvokeOptions options, bool convertResult)
       at async Task<OutputData<T>> Pulumi.Output<T>+<>c__DisplayClass12_0.<Create>g__GetData|0(?)+GetData(?)
       at async Task<OutputData<U>> Pulumi.Output<T>.ApplyHelperAsync<U>(Task<OutputData<T>> dataTask, Func<T, Output<U>> func)

Affected Resource(s)

• Docker.GetLogs

Output of pulumi about

CLI          
Version      3.119.0
Go Version   go1.22.3
Go Compiler  gc

Plugins
KIND      NAME    VERSION
resource  docker  4.5.4
language  dotnet  unknown

Host     
OS       debian
Version  12.5
Arch     x86_64

This project is written in dotnet: executable='/usr/bin/dotnet' version='6.0.423'

Current Stack: menfin/zendesk/5336

TYPE                              URN
pulumi:pulumi:Stack               urn:pulumi:5336::zendesk::pulumi:pulumi:Stack::zendesk-5336
pulumi:providers:docker           urn:pulumi:5336::zendesk::pulumi:providers:docker::docker-provider
docker:index/image:Image          urn:pulumi:5336::zendesk::docker:index/image:Image::docker-image
docker:index/container:Container  urn:pulumi:5336::zendesk::docker:index/container:Container::docker-container


Found no pending operations associated with 5336

Backend        
Name           pulumi.com
URL            https://app.pulumi.com/aureq
User           aureq
Organizations  aureq, team-ce, menfin, menfin-team, demo, pulumi
Token type     personal

Dependencies:
NAME           VERSION
Pulumi         3.64.0
Pulumi.Docker  4.5.4

Pulumi locates its logs in /tmp by default

Additional context

As a workaround to avoid the crash, it's possible to execute the container while at the same time retrieving the logs.

    var MyDockerContainer = new Pulumi.Docker.Container("docker-container", new ContainerArgs
    {
        Name = imageName,
        Image = MyDockerImage.Id,
        Attach = true,
        Logs = true,
        MustRun = false,

    }, new CustomResourceOptions
    {
        Provider = MyDockerProvider,
    });

Attach, Logs and MustRun need to be set as shown above and then MyDockerContainer.ContainerLogs should contain the logs generated during the container's execution..

Contributing

Vote on this issue by adding a 👍 reaction.
To contribute a fix for this issue, leave a comment (and link to your pull request, if you've opened one already).

[VenelinMartinov]

Thanks for reporting! From a cursory look, this looks like an issue in the upstream provider:
https://github.com/kreuzwerker/terraform-provider-docker/blob/master/internal/provider/data_source_docker_logs.go#L118 seems to assume each line of output is at least 8 bytes long, which is wrong in the example you've provided.

I believe this is the same issue as kreuzwerker/terraform-provider-docker#544 upstream, although that issue might have been lost, so it'd be worth raising a new one with the repro here.

[blampe]

Great debugging @VenelinMartinov!

As a workaround to avoid the crash, it's possible to execute the container while at the same time retrieving the logs.

Note that due to kreuzwerker/terraform-provider-docker#545 these logs will probably include some mangled prefixes. Setting discardHeaders to false on the getLogs call should also work around the issue.

While I couldn't get the same error message as our customer

@aureq what error were they seeing?

[blampe]

Removing the p1 label since this is an upstream issue with an existing workaround.