Missing TF_LOGs when expecting to receive them when creating an EKS Cluster #1617

zbuchheit · 2024-01-10T19:26:06Z

What happened?

When attempting to use the TF_LOG environment variable, I was expecting to see resulting relevant log changes, but it doesn't appear to change the output of the logs. It seems the TF logs aren't being passed through.

Example

import * as aws from "@pulumi/aws";
import * as eks from "@pulumi/eks";
import * as pulumi from "@pulumi/pulumi";

const name = "zach-example";

const config = new pulumi.Config();
const eksNodeInstanceType =
  config.get("eksNodeInstanceType") || aws.ec2.InstanceType.T3_Small;


const cluster = new eks.Cluster("zbuchheit-cluster", {
  version: "1.28",
  instanceType: eksNodeInstanceType,
  tags: {
    Name: `${name}-cluster`,
    Owner: "zbuchheit",
  },
});

cluster.kubeconfig.apply((kubeconfig) => {
    console.log(kubeconfig)
});

export const clusterConfig = pulumi.secret(cluster.kubeconfig);
export const kubeVersion = cluster.eksCluster.version;
export const kubeName = cluster.eksCluster.name;

Command Run

TF_LOG=INFO pulumi up --logtostderr --logflow -v=10 2> tf_info.txt

Output of `pulumi about`

CLI          
Version      3.100.0
Go Version   go1.21.5
Go Compiler  gc

Plugins
NAME        VERSION
aws         6.0.3
aws         5.42.0
aws         5.31.0
awsx        1.0.5
docker      3.6.1
eks         1.0.3
kubernetes  4.1.1
kubernetes  3.30.2
nodejs      unknown
random      4.14.0

Host     
OS       darwin
Version  14.2.1
Arch     arm64

This project is written in nodejs: executable='/Users/zbuchheit/.nvm/versions/node/v18.17.1/bin/node' version='v18.17.1'

Current Stack: zbuchheit-pulumi-corp/aws-ts-eks/dev

Found no resources associated with dev

Found no pending operations associated with dev

Backend        
Name           pulumi.com
URL            https://app.pulumi.com/zbuchheit-pulumi-corp
User           zbuchheit-pulumi-corp
Organizations  zbuchheit-pulumi-corp,
Token type     personal

Dependencies:
NAME                VERSION
@pulumi/random      4.14.0
@types/node         16.18.46
@pulumi/aws         6.0.3
@pulumi/awsx        1.0.5
@pulumi/eks         1.0.3
@pulumi/kubernetes  4.1.1
@pulumi/pulumi      3.80.0

Additional context

No response

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).

The text was updated successfully, but these errors were encountered:

t0yv0 · 2024-01-19T17:08:42Z

It appears that the logs are coming through. If there is a specific activity you need to diagnose the provider that is still not coming through TF_LOG=TRACE please let us know so we can fix.

Gory details of experiments attempted so far. There are several ways TF providers emit logs.

The new recommended way is to use "github.com/hashicorp/terraform-plugin-log/tflog" API to emit
messages via a context.Context attached loggers
The old way is to use "log" package and do something like the following (note the level is
embedded in the string).

log.Printf("[WARN] ...")

In the experiment conducted today I see tflog-style logs coming through, for example under
TF_LOG=TRACE:

I0119 10:12:24.269257   35397 log.go:81]   fwserver/block_validation.go:227: sdk.framework:
  Called provider defined validator.List: description="list must contain at most 1 elements"

Also seeing log-style logs coming through, for example:

I0119 11:34:12.092544   37378 log.go:81] eventSink::Debug(<{%reset%}>pulumi-aws: starting to validate credentials. Disable this by AWS_SKIP_CREDENTIALS_VALIDATION or skipCredentialsValidation option<{%reset%}>)

This entry originates from the following upstream code:

log.Printf("[INFO] pulumi-aws: starting to validate credentials. " +
        "Disable this by AWS_SKIP_CREDENTIALS_VALIDATION or " +
        "skipCredentialsValidation option")

To make triple-sure, I have instrumented the upstream provider to injected this code to into
resourceClusterCreate:

log.Printf("[WARN] EKS Cluster CREATE")

And was able to observe it under TF_LOG=TRACE:

I0119 11:34:43.994100   37378 log.go:81] EKS Cluster CREATE
I0119 11:34:43.994126   37378 log.go:81] eventSink::Debug(<{%reset%}>EKS Cluster CREATE<{%reset%}>)

Looks like there is a limitation that the translated logs lose their level, which makes them less
grep-friendly. Unfortunately.

t0yv0 · 2024-01-19T17:17:08Z

I'm testing pulumi-aws v6.18.0:

CLI          
Version      3.99.0
Go Version   go1.21.5
Go Compiler  gc

Plugins
NAME        VERSION
aws         6.18.0
aws         6.18.0
awsx        2.4.0
awsx        2.4.0
docker      4.5.1
docker      4.5.1
docker      3.6.1
docker      3.6.1
eks         2.1.0+dirty
kubernetes  4.7.0
nodejs      unknown

Host     
OS       darwin
Version  14.2.1
Arch     x86_64

This project is written in nodejs: executable='/Users/t0yv0/bin/node' version='v18.18.2'

Current Stack: t0yv0/bridge-1617/test2

TYPE                                               URN
pulumi:pulumi:Stack                                urn:pulumi:test2::bridge-1617::pulumi:pulumi:Stack::bridge-1617-test2
pulumi:providers:aws                               urn:pulumi:test2::bridge-1617::pulumi:providers:aws::default_6_0_4
eks:index:Cluster                                  urn:pulumi:test2::bridge-1617::eks:index:Cluster::t0yv0-cluster
eks:index:ServiceRole                              urn:pulumi:test2::bridge-1617::eks:index:Cluster$eks:index:ServiceRole::t0yv0-cluster-eksRole
eks:index:ServiceRole                              urn:pulumi:test2::bridge-1617::eks:index:Cluster$eks:index:ServiceRole::t0yv0-cluster-instanceRole
pulumi:providers:eks                               urn:pulumi:test2::bridge-1617::pulumi:providers:eks::default
eks:index:RandomSuffix                             urn:pulumi:test2::bridge-1617::eks:index:Cluster$eks:index:RandomSuffix::t0yv0-cluster-cfnStackName
aws:iam/role:Role                                  urn:pulumi:test2::bridge-1617::eks:index:Cluster$eks:index:ServiceRole$aws:iam/role:Role::t0yv0-cluster-instanceRole-role
aws:iam/role:Role                                  urn:pulumi:test2::bridge-1617::eks:index:Cluster$eks:index:ServiceRole$aws:iam/role:Role::t0yv0-cluster-eksRole-role
aws:ec2/securityGroup:SecurityGroup                urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:ec2/securityGroup:SecurityGroup::t0yv0-cluster-eksClusterSecurityGroup
aws:iam/rolePolicyAttachment:RolePolicyAttachment  urn:pulumi:test2::bridge-1617::eks:index:Cluster$eks:index:ServiceRole$aws:iam/rolePolicyAttachment:RolePolicyAttachment::t0yv0-cluster-instanceRole-3eb088f2
aws:iam/rolePolicyAttachment:RolePolicyAttachment  urn:pulumi:test2::bridge-1617::eks:index:Cluster$eks:index:ServiceRole$aws:iam/rolePolicyAttachment:RolePolicyAttachment::t0yv0-cluster-instanceRole-e1b295bd
aws:iam/rolePolicyAttachment:RolePolicyAttachment  urn:pulumi:test2::bridge-1617::eks:index:Cluster$eks:index:ServiceRole$aws:iam/rolePolicyAttachment:RolePolicyAttachment::t0yv0-cluster-instanceRole-03516f97
aws:iam/rolePolicyAttachment:RolePolicyAttachment  urn:pulumi:test2::bridge-1617::eks:index:Cluster$eks:index:ServiceRole$aws:iam/rolePolicyAttachment:RolePolicyAttachment::t0yv0-cluster-eksRole-4b490823
aws:ec2/securityGroupRule:SecurityGroupRule        urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:ec2/securityGroupRule:SecurityGroupRule::t0yv0-cluster-eksClusterInternetEgressRule
aws:iam/instanceProfile:InstanceProfile            urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:iam/instanceProfile:InstanceProfile::t0yv0-cluster-instanceProfile
aws:eks/cluster:Cluster                            urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:eks/cluster:Cluster::t0yv0-cluster-eksCluster
pulumi:providers:kubernetes                        urn:pulumi:test2::bridge-1617::eks:index:Cluster$pulumi:providers:kubernetes::t0yv0-cluster-eks-k8s
aws:ec2/securityGroup:SecurityGroup                urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:ec2/securityGroup:SecurityGroup::t0yv0-cluster-nodeSecurityGroup
kubernetes:core/v1:ConfigMap                       urn:pulumi:test2::bridge-1617::eks:index:Cluster$kubernetes:core/v1:ConfigMap::t0yv0-cluster-nodeAccess
aws:ec2/securityGroupRule:SecurityGroupRule        urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:ec2/securityGroupRule:SecurityGroupRule::t0yv0-cluster-eksNodeInternetEgressRule
aws:ec2/securityGroupRule:SecurityGroupRule        urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:ec2/securityGroupRule:SecurityGroupRule::t0yv0-cluster-eksClusterIngressRule
aws:ec2/securityGroupRule:SecurityGroupRule        urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:ec2/securityGroupRule:SecurityGroupRule::t0yv0-cluster-eksNodeClusterIngressRule
eks:index:VpcCni                                   urn:pulumi:test2::bridge-1617::eks:index:Cluster$eks:index:VpcCni::t0yv0-cluster-vpc-cni
aws:ec2/securityGroupRule:SecurityGroupRule        urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:ec2/securityGroupRule:SecurityGroupRule::t0yv0-cluster-eksNodeIngressRule
aws:ec2/launchConfiguration:LaunchConfiguration    urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:ec2/launchConfiguration:LaunchConfiguration::t0yv0-cluster-nodeLaunchConfiguration
aws:ec2/securityGroupRule:SecurityGroupRule        urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:ec2/securityGroupRule:SecurityGroupRule::t0yv0-cluster-eksExtApiServerClusterIngressRule
aws:cloudformation/stack:Stack                     urn:pulumi:test2::bridge-1617::eks:index:Cluster$aws:cloudformation/stack:Stack::t0yv0-cluster-nodes
pulumi:providers:kubernetes                        urn:pulumi:test2::bridge-1617::eks:index:Cluster$pulumi:providers:kubernetes::t0yv0-cluster-provider


Found no pending operations associated with test2

Backend        
Name           pulumi.com
URL            https://app.pulumi.com/t0yv0
User           t0yv0
Organizations  t0yv0, pulumi
Token type     personal

Dependencies:
NAME            VERSION
@pulumi/aws     6.18.0
@pulumi/awsx    2.4.0
@pulumi/eks     2.1.0
@pulumi/pulumi  3.102.0
@types/node     18.19.8

Pulumi locates its logs in /var/folders/gk/cchgxh512m72f_dmkcc3d09h0000gp/T/com.apple.shortcuts.mac-helper// by default

zbuchheit · 2024-01-19T17:21:04Z

thanks, let me test as well to see if I am observing the same thing

t0yv0 · 2024-01-19T17:23:50Z

Bridge https://github.com/pulumi/pulumi-terraform-bridge/releases/tag/v3.69.0 improved log capture. First version of the provider having the fix: https://github.com/pulumi/pulumi-aws/releases/tag/v6.17.0

Thank you!

t0yv0 · 2024-01-19T17:26:25Z

Filed #1632 that logs aren't greppable by level.

zbuchheit · 2024-01-19T17:51:08Z

I am seeing the tf logs now. Just to make sure I have a clear understanding, I would likely expect to see this in any TF bridged provider version that is has a pulumi-terraform-bridge version < v3.69.0?

t0yv0 · 2024-01-19T17:53:22Z

Yes, after bridge v3.69.0 you should expect to see all the logs. Before v3.69.0 only log.Printf style logs came through, and tflog-based ones did not.

t0yv0 · 2024-01-19T17:55:13Z

Can we close the issue or you need some more functionality here? Appreciated!

zbuchheit · 2024-01-19T20:22:51Z

yep! I will close it out now. Thanks!

zbuchheit added kind/bug Some behavior is incorrect or out of spec needs-triage Needs attention from the triage team labels Jan 10, 2024

t0yv0 added customer/feedback Feedback from customers impact/reliability Something that feels unreliable or flaky and removed needs-triage Needs attention from the triage team labels Jan 10, 2024

t0yv0 mentioned this issue Jan 11, 2024

Bridge quality investment possibilities #1621

Closed

ericrudder added customer/lighthouse p1 A bug severe enough to be the next item assigned to an engineer labels Jan 18, 2024

t0yv0 self-assigned this Jan 19, 2024

zbuchheit closed this as completed Jan 19, 2024

t0yv0 added the resolution/no-repro This issue wasn't able to be reproduced label Jan 19, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Missing TF_LOGs when expecting to receive them when creating an EKS Cluster #1617

Missing TF_LOGs when expecting to receive them when creating an EKS Cluster #1617

zbuchheit commented Jan 10, 2024

t0yv0 commented Jan 19, 2024 •

edited

Loading

t0yv0 commented Jan 19, 2024

zbuchheit commented Jan 19, 2024

t0yv0 commented Jan 19, 2024

t0yv0 commented Jan 19, 2024

zbuchheit commented Jan 19, 2024

t0yv0 commented Jan 19, 2024 •

edited

Loading

t0yv0 commented Jan 19, 2024

zbuchheit commented Jan 19, 2024

Missing TF_LOGs when expecting to receive them when creating an EKS Cluster #1617

Missing TF_LOGs when expecting to receive them when creating an EKS Cluster #1617

Comments

zbuchheit commented Jan 10, 2024

What happened?

Example

Command Run

Output of pulumi about

Additional context

Contributing

t0yv0 commented Jan 19, 2024 • edited Loading

t0yv0 commented Jan 19, 2024

zbuchheit commented Jan 19, 2024

t0yv0 commented Jan 19, 2024

t0yv0 commented Jan 19, 2024

zbuchheit commented Jan 19, 2024

t0yv0 commented Jan 19, 2024 • edited Loading

t0yv0 commented Jan 19, 2024

zbuchheit commented Jan 19, 2024

Output of `pulumi about`

t0yv0 commented Jan 19, 2024 •

edited

Loading

t0yv0 commented Jan 19, 2024 •

edited

Loading