Help tracing a slow Pulumi Up…. We’re trying to understand an extremely slow `pulumi up…` run. When...
m

Matt W

over 1 year ago
Help tracing a slow Pulumi Up…. We’re trying to understand an extremely slow
pulumi up…
run. When we run
pulumi refresh
it takes ~1m or so to get the data back - and that feels reasonable, given that we have a few hundred resources. When we then run a
pulumi up
where even only 1 resource changes, the run takes over 9 minutes. The primary API we are interfacing with is the PagerDuty API using the Pulumi PagerDuty provider. I’ve run
pulumi up --tracing…
and I have some trace files. Using the
AppDash
is a little confusing though and I am not sure how to really get much use out of it. The one thing I see is the
Profile View
at the bottom and sorting by `Cumulative Time(ms)`: When I do that, I get a MASSIVE output of
RegisterResource
calls, … like … thousands and thousands of lines. We don’t have thousands of resources. There are over 11,500 lines in this output. There are 932
RegisterResourceOutputs
calls… 1864
RegisterResource
calls
..
%  cat pulumi.cumulative.out | awk '{print $1}' | sort | uniq -c | sort -n 
   1 /pulumirpc.Engine/SetRootResource
   1 execNodejs
   1 locateModule
   1 pf.CheckConfig
   1 pf.Configure
   1 pf.ValidateProviderConfig
   1 pulumi-plan
   1 sdkv2.CheckConfig
   1 sdkv2.Configure
   1 sdkv2.GetPluginInfo
   1 sdkv2.ValidateProviderConfig
   2 /pulumirpc.LanguageRuntime/GetPluginInfo
   2 /pulumirpc.LanguageRuntime/GetRequiredPlugins
   2 /pulumirpc.LanguageRuntime/Run
   2 Cumulative
   2 Name
   3 newPlugin
   4 /pulumirpc.ResourceProvider/CheckConfig
   4 /pulumirpc.ResourceProvider/Configure
   4 /pulumirpc.ResourceProvider/DiffConfig
   4 /pulumirpc.ResourceProvider/GetPluginInfo
   4 Time
  12 /pulumirpc.ResourceMonitor/SupportsFeature
 130 sdkv2.Invoke
 260 /pulumirpc.ResourceMonitor/Invoke
 260 /pulumirpc.ResourceProvider/Invoke
 459 sdkv2.Check
 459 sdkv2.Diff
 928 /pulumirpc.ResourceProvider/Check
 928 /pulumirpc.ResourceProvider/Diff
 932 /pulumirpc.ResourceMonitor/RegisterResourceOutputs
1864 /pulumirpc.ResourceMonitor/RegisterResource
5240 /pulumirpc.Engine/Log
I don’t see much detail though in the trace view… is there something I am missing in order to figure out why we see so many calls? Also, it feels like the calls get cumulatively slower as we go. While looking at the
--debug --verbose=7
logs, I would swear that the
pulumi up
command is making S3 calls after each and every resource update. Is that possible?