Cloud Custodian: Unpredictable output - custodian.actions:WARNING stop implicitly filtered 0 of 1 resources key

[ashu27483]

Describe the bug

Team,
I am learning Cloud Custodian for AWS, but its syntax are not working as expected.
E.g. I am just trying to start/stop EC2 instance using below code, but sometime it worked after trying for couple of minutes, not sure if this is a bug.
policies:

• name: my-first-policy
  resource: aws.ec2
  filters:
  • "State.Name": running
  • "tag:Custodian": present
    actions:
  • stop
    Output in console:
    2021-09-29 15:11:48,749: custodian.policy:INFO policy:my-first-policy1 resource:aws.ec2 region:us-east-1 count:1 time:0.00
    2021-09-29 15:11:48,761: custodian.actions:WARNING start implicitly filtered 0 of 1 resources key:State.Name on stopped
    2021-09-29 15:11:48,761: custodian.policy:INFO policy:my-first-policy1 action:start resources:1 execution_time:0.00

2021-09-29 15:14:36,930: custodian.policy:INFO policy:my-first-policy1 resource:aws.ec2 region:us-east-1 count:1 time:1.89
2021-09-29 15:14:38,432: custodian.policy:INFO policy:my-first-policy1 action:start resources:1 execution_time:1.50

Please guide me which documents to refer to learn, I couldn't run it on Windows, so later I tried above on Linux.

What did you expect to happen?

I expected 2 + 2 to equal 4, but instead 2 + 2 equaled 6!

Cloud Provider

Amazon Web Services (AWS)

Cloud Custodian version and dependency information

Latest version

Policy

No response

Relevant log/traceback output

No response

Extra information or context

No response

[ajkerrigan]

Hi @ashu27483 - welcome to Cloud Custodian 😄 ! Based on the example policy you included, it looks like you're working through the getting started docs? Thanks for opening this issue, we want to make sure those docs are helpful.

I suspect that caching is getting in the way here. When you run a policy against the aws.ec2 resource, custodian fetches a list of all your EC2 instances and stashes them locally. That way if you run multiple policies over a short period of time, you only have to ask AWS for an instance list once. However, that cache includes the instance state. So if you stop an instance, policies will still see it as running until the cache expires (15 minutes by default). That's probably why you noticed that your policies started working after some delay.

For this specific problem, adding --cache-period 0 to your custodian run command should make the results more consistent and allow you to switch between stop and start policies (there will still be some delay as the EC2 instance starts up or shuts down). This may be worth adding to those getting started docs, though we'll need to be careful not to fall into a rabbit hole of caching and take away from a useful "first run" walkthrough!