Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Snapshot deletion failing #4

Open
volk12 opened this issue Jun 13, 2017 · 8 comments
Open

Snapshot deletion failing #4

volk12 opened this issue Jun 13, 2017 · 8 comments

Comments

@volk12
Copy link

volk12 commented Jun 13, 2017

I get the same error as the other open issue, creating a new one not to confuse discussion.
Here is the log from last night's run.

START RequestId: 298ce261-4ff5-11e7-b20c-116eea350642 Version: $LATEST
2017-06-13T05:00:16.184Z 298ce261-4ff5-11e7-b20c-116eea350642 Time to delete Managed Server - DFW_DATETODEL-1497322822087
2017-06-13T05:00:16.185Z 298ce261-4ff5-11e7-b20c-116eea350642 image that is going to be deregistered: Managed Server - DFW_DATETODEL-1497322822087
2017-06-13T05:00:16.185Z 298ce261-4ff5-11e7-b20c-116eea350642 image id: ami-00cd9416
2017-06-13T05:00:16.185Z 298ce261-4ff5-11e7-b20c-116eea350642 { ImageId: 'ami-00cd9416' }
2017-06-13T05:00:16.367Z 298ce261-4ff5-11e7-b20c-116eea350642 Not yet time to delete Managed Server - DFW_DATETODEL-1497409222824
2017-06-13T05:00:16.367Z 298ce261-4ff5-11e7-b20c-116eea350642 Time to delete Managed Server - DFW_DATETODEL-1497299795687
2017-06-13T05:00:16.367Z 298ce261-4ff5-11e7-b20c-116eea350642 image that is going to be deregistered: Managed Server - DFW_DATETODEL-1497299795687
2017-06-13T05:00:16.367Z 298ce261-4ff5-11e7-b20c-116eea350642 image id: ami-a5eeb0b3
2017-06-13T05:00:16.368Z 298ce261-4ff5-11e7-b20c-116eea350642 { ImageId: 'ami-a5eeb0b3' }
2017-06-13T05:00:16.425Z 298ce261-4ff5-11e7-b20c-116eea350642 Not yet time to delete Managed Server - DFW_DATETODEL-1497582025126
2017-06-13T05:00:16.425Z 298ce261-4ff5-11e7-b20c-116eea350642 Not yet time to delete Managed Server - DFW_DATETODEL-1497495618537
2017-06-13T05:00:16.886Z 298ce261-4ff5-11e7-b20c-116eea350642 Image Deregistered
2017-06-13T05:00:16.945Z 298ce261-4ff5-11e7-b20c-116eea350642 Image Deregistered
2017-06-13T05:00:26.431Z 298ce261-4ff5-11e7-b20c-116eea350642 Time to delete Managed Server - DFW_DATETODEL-1497322822087
2017-06-13T05:00:26.431Z 298ce261-4ff5-11e7-b20c-116eea350642 snap-0ebc3f736cc4176b1
2017-06-13T05:00:26.587Z 298ce261-4ff5-11e7-b20c-116eea350642 snap-0195dc9146f620493
2017-06-13T05:00:26.645Z 298ce261-4ff5-11e7-b20c-116eea350642 snap-034f66a28d8b59186
2017-06-13T05:00:26.646Z 298ce261-4ff5-11e7-b20c-116eea350642 snap-0559aba9dd9dfb868
2017-06-13T05:00:26.707Z 298ce261-4ff5-11e7-b20c-116eea350642 TypeError: Cannot read property 'SnapshotId' of undefined
at null._onTimeout (/var/task/index.js:76:73)
at Timer.listOnTimeout (timers.js:92:15)
END RequestId: 298ce261-4ff5-11e7-b20c-116eea350642
REPORT RequestId: 298ce261-4ff5-11e7-b20c-116eea350642 Duration: 12167.37 ms Billed Duration: 12200 ms Memory Size: 128 MB Max Memory Used: 44 MB
RequestId: 298ce261-4ff5-11e7-b20c-116eea350642 Process exited before completing request

START RequestId: 298ce261-4ff5-11e7-b20c-116eea350642 Version: $LATEST
2017-06-13T05:01:26.805Z 298ce261-4ff5-11e7-b20c-116eea350642 Not yet time to delete Managed Server - DFW_DATETODEL-1497409222824
2017-06-13T05:01:26.805Z 298ce261-4ff5-11e7-b20c-116eea350642 Not yet time to delete Managed Server - DFW_DATETODEL-1497582025126
2017-06-13T05:01:26.805Z 298ce261-4ff5-11e7-b20c-116eea350642 Not yet time to delete Managed Server - DFW_DATETODEL-1497495618537
2017-06-13T05:01:36.817Z 298ce261-4ff5-11e7-b20c-116eea350642 Not yet time to delete Managed Server - DFW_DATETODEL-1497409222824
2017-06-13T05:01:36.817Z 298ce261-4ff5-11e7-b20c-116eea350642 Not yet time to delete Managed Server - DFW_DATETODEL-1497582025126
2017-06-13T05:01:36.817Z 298ce261-4ff5-11e7-b20c-116eea350642 Not yet time to delete Managed Server - DFW_DATETODEL-1497495618537
END RequestId: 298ce261-4ff5-11e7-b20c-116eea350642
REPORT RequestId: 298ce261-4ff5-11e7-b20c-116eea350642 Duration: 11771.28 ms Billed Duration: 11800 ms Memory Size: 128 MB Max Memory Used: 42 MB

I have the following permissions for the IAM role:

{
"Version": "2012-10-17",
"Statement": [
{
"Effect": "Allow",
"Action": [
"logs:CreateLogGroup",
"logs:CreateLogStream",
"logs:PutLogEvents"
],
"Resource": "arn:aws:logs:::"
},
{
"Effect": "Allow",
"Action": [
"ec2:CreateImage",
"ec2:CreateTags",
"ec2:DeleteSnapshot",
"ec2:DeregisterImage",
"ec2:DescribeImages",
"ec2:DescribeInstances",
"ec2:CreateNetworkInterface",
"ec2:DescribeNetworkInterfaces",
"ec2:DeleteNetworkInterface"
],
"Resource": "
"
}
]
}

It should have found and deleted 8 snapshots, 4 for each AMI:
snap-0195dc9146f620493,
snap-034f66a28d8b59186,
snap-0559aba9dd9dfb868,
snap-0ebc3f736cc4176b1,
snap-0824f5772cbd01b29,
snap-01c6172b946fea805,
snap-0bd52e7b4cad93d71,
snap-00d74ed75f2f9aaa5

@webdigi
Copy link
Owner

webdigi commented Jun 14, 2017

Thanks for that. It looks like a timeout. In the lambda script can you please check configuration and the timeout is set to 5 minutes?

@webdigi webdigi mentioned this issue Jun 14, 2017
@volk12
Copy link
Author

volk12 commented Jun 14, 2017

i made the change 10000ms to 300000ms and will see how it runs tonight.

   setTimeout(function() {
        for (var j in data.Images) {
            imagename = data.Images[j].Name
            if (checkIfAMIneedsDeleting(imagename) === true) {
                for (var k in data.Images[j].BlockDeviceMappings) {
                    snap = data.Images[j].BlockDeviceMappings[k].Ebs.SnapshotId;
                    console.log(snap);
                    var snapparams = {
                        SnapshotId: snap
                    };
                    ec2.deleteSnapshot(snapparams, function(err, data) {
                        if (err) console.log(err, err.stack); // an error occurred
                        else console.log("Snapshot Deleted"); // successful response
                    });
                }
            }
        }
    }, 300000);

Wouldn't it be more efficient to put the snapshot id's into an array when it finds an AMI to delete, then pushing the array to the delete snapshot function after?

@webdigi
Copy link
Owner

webdigi commented Jun 14, 2017

@volk12 - please try the run tonight and see how it goes.

Pull requests are always welcome after you test it ! 👍

@volk12
Copy link
Author

volk12 commented Jun 15, 2017

Failed worse with the 5min wait. does not seem like it tries to find the snapshots now. Full log:

START RequestId: 7e418fc2-5187-11e7-83ca-83c77018b7ab Version: $LATEST
2017-06-15T05:00:29.378Z 7e418fc2-5187-11e7-83ca-83c77018b7ab Not yet time to delete Managed Server - DFW_DATETODEL-1497668421875
2017-06-15T05:00:29.397Z 7e418fc2-5187-11e7-83ca-83c77018b7ab Not yet time to delete Managed Server - DFW_DATETODEL-1497754827839
2017-06-15T05:00:29.397Z 7e418fc2-5187-11e7-83ca-83c77018b7ab Time to delete Managed Server - DFW_DATETODEL-1497495618537
2017-06-15T05:00:29.417Z 7e418fc2-5187-11e7-83ca-83c77018b7ab image that is going to be deregistered: Managed Server - DFW_DATETODEL-1497495618537
2017-06-15T05:00:29.417Z 7e418fc2-5187-11e7-83ca-83c77018b7ab image id: ami-f65309e0
2017-06-15T05:00:29.417Z 7e418fc2-5187-11e7-83ca-83c77018b7ab { ImageId: 'ami-f65309e0' }
2017-06-15T05:00:30.057Z 7e418fc2-5187-11e7-83ca-83c77018b7ab Image Deregistered
END RequestId: 7e418fc2-5187-11e7-83ca-83c77018b7ab
REPORT RequestId: 7e418fc2-5187-11e7-83ca-83c77018b7ab Duration: 300000.59 ms Billed Duration: 300000 ms Memory Size: 128 MB Max Memory Used: 43 MB
2017-06-15T05:05:27.653Z 7e418fc2-5187-11e7-83ca-83c77018b7ab Task timed out after 300.00 seconds

START RequestId: 7e418fc2-5187-11e7-83ca-83c77018b7ab Version: $LATEST
2017-06-15T05:06:35.419Z 7e418fc2-5187-11e7-83ca-83c77018b7ab Not yet time to delete Managed Server - DFW_DATETODEL-1497668421875
2017-06-15T05:06:35.457Z 7e418fc2-5187-11e7-83ca-83c77018b7ab Not yet time to delete Managed Server - DFW_DATETODEL-1497754827839
END RequestId: 7e418fc2-5187-11e7-83ca-83c77018b7ab
REPORT RequestId: 7e418fc2-5187-11e7-83ca-83c77018b7ab Duration: 300003.67 ms Billed Duration: 300000 ms Memory Size: 128 MB Max Memory Used: 42 MB
2017-06-15T05:11:33.845Z 7e418fc2-5187-11e7-83ca-83c77018b7ab Task timed out after 300.00 seconds

START RequestId: 7e418fc2-5187-11e7-83ca-83c77018b7ab Version: $LATEST
2017-06-15T05:13:21.620Z 7e418fc2-5187-11e7-83ca-83c77018b7ab Not yet time to delete Managed Server - DFW_DATETODEL-1497668421875
2017-06-15T05:13:21.657Z 7e418fc2-5187-11e7-83ca-83c77018b7ab Not yet time to delete Managed Server - DFW_DATETODEL-1497754827839
END RequestId: 7e418fc2-5187-11e7-83ca-83c77018b7ab
REPORT RequestId: 7e418fc2-5187-11e7-83ca-83c77018b7ab Duration: 300000.29 ms Billed Duration: 300000 ms Memory Size: 128 MB Max Memory Used: 42 MB
2017-06-15T05:18:20.029Z 7e418fc2-5187-11e7-83ca-83c77018b7ab Task timed out after 300.00 seconds

@webdigi
Copy link
Owner

webdigi commented Jun 16, 2017

How many AMIs/ images do you have running on this?

@volk12
Copy link
Author

volk12 commented Jun 16, 2017

Testing with one instance. right now. Backing up nightly with 3 day retention.
image

AMI has four snapshots associated.
image

Once I finish testing I plan to backup 5 instances, each with 3 to 5 volumes.

Creation is working just fine, the only error I have left is snapshot deletion.

@iceman23pk
Copy link

I ran into similar issue. In my case I had some ephemeral stores attached for which there is no Ebs property associated. This change seems to fix my issue:

    setTimeout(function() {
        for (var j in data.Images) {
            imagename = data.Images[j].Name
            if (checkIfAMIneedsDeleting(imagename) === true) {
                for (var k in data.Images[j].BlockDeviceMappings) {
                    if ('Ebs' in data.Images[j].BlockDeviceMappings[k]) {
                      snap = data.Images[j].BlockDeviceMappings[k].Ebs.SnapshotId;
                      console.log(snap);
                      var snapparams = {
                          SnapshotId: snap
                      };
                      ec2.deleteSnapshot(snapparams, function(err, data) {
                          if (err) console.log(err, err.stack); // an error occurred
                          else console.log("Snapshot Deleted"); // successful response
                      });
                   }
                }
            }
        }
    }, 10000);

ybudimirov added a commit to ybudimirov/AWS-AMI-Automated-Creation-Deletion that referenced this issue Sep 4, 2018
Snapshot deletion failing webdigi#4
webdigi added a commit that referenced this issue Sep 4, 2018
Snapshot deletion failing #4
@electricpocket
Copy link

We also had this problem with "TypeError: Cannot read property 'SnapshotId' of undefined"
Turns out our servers have gained some ephemeral storage volumes ( which we don't use or need) and these are not EBS. So the script crashes when it tries to read data.Images[j].BlockDeviceMappings[k].Ebs.SnapshotId on them and therefore fails to complete.

The check for Ebs in the BlockDeviceMappings structures as detailed above fixed this for us

if ('Ebs' in data.Images[j].BlockDeviceMappings[k])

Thanks

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants