AWS BID Price Instances - Cloud Profiles - Not Closing Instances Down

Permanently deleted user

Created June 21, 2019 18:38

Hi All

Has anyone had an issue using Teamcity - currently using version 2019.1 - with cloud profiles. Using them to start AWS EC2 instances on a bid price basis.
This has been working very well and there is just a limit of 3 agents on the teamcity install.

I noticed the other day - that a couple of days before 20+ ec2 instances were started- this was from Teamcity, but they failed to tag the instance and teamcity failed to stop them.

So I am trying to workout what may trigger this - that Teamcity would forget what agents it started.

-

I cleared them down and its ran OK for a couple of days - but today I notice another left orphaned which will just cost money unless the bid gets pulled.
Only thing I can see from AWS is that the bid was cancelled but the instance is still running. So something in the initiation phase when it asks for a ec2 instance to start, to then tag it - which it does not get to is where the problem seems to be.

-

Not sure if there is code relating to this plugin I can see to what order it is calling things within AWS / and or logs so I can analyse.

thanks

Kevin

3 comments

Denis Lapuente

Created July 08, 2019 14:46

Hi Kevin,

sorry for the delay. If the issue is still going on, please collect the teamcity-clouds.log, teamcity-server.log (please make sure it covers the time period where one of the agents faced the issue) and send them to us via the "Submit a request" button on top of this page for review.

Permanently deleted user

Created July 08, 2019 16:22

Hi Denis

I have the files, but we only have a Professional install - so don't believe I can attach them.

I get the following happening in the logs - see below ; says unable to tag instance - will now terminate it - but does not.

Note I have adjusted some of the sensitive info in the logs.

thanks

Kevin

2019-07-01 10:13:42,930] INFO [2 Flush Queue 1] - .instances.StartInstanceAction - Starting cloud instance: profile 'CUSTRR-DEVQA-EC2'{id=amazon-1, projectId=project1}, AmazonImage{id=ami-AMINUMBER}, hash=zW29BHASUq2eMj6Vy6JFmDToisfepITr, reason=Automatic start: Compatible with queued build CUST RentalResult / gradle-emerald(promotionId=116)
[2019-07-01 10:13:42,935] INFO [2 Flush Queue 1] - .server.impl.CloudEventsLogger - Cloud instance entered 'scheduled to start' state, profile 'CUSTRR-DEVQA-EC2'{id=amazon-1, projectId=project1}, Amazon Instance{instanceId=z-ami-AMINUMBER-2, imageId=ami-AMINUMBER, amazonInstanceId=null, status: Scheduled to start}
[2019-07-01 10:13:42,935] INFO [2 Flush Queue 1] - .server.impl.CloudEventsLogger - Cloud instance start succeeded: profile 'CUSTRR-DEVQA-EC2'{id=amazon-1, projectId=project1}, Amazon Instance{instanceId=z-ami-AMINUMBER-2, imageId=ami-AMINUMBER, amazonInstanceId=null, status: Scheduled to start}
[2019-07-01 10:13:43,349] WARN [477b10c7f5ac1f3] - azon.sync.AmazonSyncClientImpl - Error performing tagging operation: jetbrains.buildServer.clouds.amazon.error.AmazonCloudException: Amazon EC2 connection (profile 'CUSTRR-DEVQA-EC2'{id=amazon-1}, operation:createTags). Unable to tag [sir-cfciz21g]: 'The spot instance request ID 'sir-cfciz21g' does not exist (Service: AmazonEC2; Status Code: 400; Error Code: InvalidSpotInstanceRequestID.NotFound; Request ID: 5ebfe885-8ba2-4cc7-9e3b-c10a2fa2601c)' (enable debug to see stacktrace)
[2019-07-01 10:13:43,350] WARN [477b10c7f5ac1f3] - azon.sync.AmazonSyncClientImpl - Unable to tag spot instance request sir-cfciz21g. Will now terminate it
[2019-07-01 10:13:43,435] INFO [477b10c7f5ac1f3] - s.amazon.image.AmazonImageImpl - Amazon instance started: instanceId=z-ami-AMINUMBER-2, amazonInstanceId=sir-cfciz21g, imageId=ami-AMINUMBER, userData=CloudInstanceUserData{myAgentName=<none>, myAuthToken='', myServerAddress='http://:8111', myProfileDescription='CUST Dynamic Agents DEV-QA - EC2', myIdleTimeout=40 min, myCustomAgentConfigurationParameters={cloud.amazon.agent-name-prefix=DEVQA, ec2.is-spot-instance=true, system.cloud.profile_id=amazon-1, teamcity.cloud.agent.remove.policy=remove, teamcity.cloud.instance.hash=zW29BHASUq2eMj6Vy6JFmDToisfepITr}}
[2019-07-01 10:13:43,442] INFO [3 Flush Queue 1] - .instances.StartInstanceAction - Starting cloud instance: profile 'CUSTRR-DEVQA-EC2'{id=amazon-1, projectId=project1}, AmazonImage{id=ami-AMINUMBER}, hash=Pa5oLX66EK1jjkUAhpLEqRBFN1qvTOAk, reason=Automatic start: Compatible with queued build CUST RentalResult / gradle-emerald(promotionId=116)
[2019-07-01 10:13:43,445] INFO [3 Flush Queue 1] - .server.impl.CloudEventsLogger - Cloud instance entered 'scheduled to start' state, profile 'CUSTRR-DEVQA-EC2'{id=amazon-1, projectId=project1}, Amazon Instance{instanceId=z-ami-AMINUMBER-3, imageId=ami-AMINUMBER, amazonInstanceId=null, status: Scheduled to start}
[2019-07-01 10:13:43,445] INFO [3 Flush Queue 1] - .server.impl.CloudEventsLogger - Cloud instance start succeeded: profile 'CUSTRR-DEVQA-EC2'{id=amazon-1, projectId=project1}, Amazon Instance{instanceId=z-ami-AMINUMBER-3, imageId=ami-AMINUMBER, amazonInstanceId=null, status: Scheduled to start}
[2019-07-01 10:13:43,642] WARN [477b10c7f5ac1f3] - azon.sync.AmazonSyncClientImpl - Error performing tagging operation: jetbrains.buildServer.clouds.amazon.error.AmazonCloudException: Amazon EC2 connection (profile 'CUSTRR-DEVQA-EC2'{id=amazon-1}, operation:createTags). Unable to tag [sir-gre8wa9k]: 'The spot instance request ID 'sir-gre8wa9k' does not exist (Service: AmazonEC2; Status Code: 400; Error Code: InvalidSpotInstanceRequestID.NotFound; Request ID: aed59ede-1c79-40a6-89e8-7de6ad7b1eb7)' (enable debug to see stacktrace)
[2019-07-01 10:13:43,643] WARN [477b10c7f5ac1f3] - azon.sync.AmazonSyncClientImpl - Unable to tag spot instance request sir-gre8wa9k. Will now terminate it
[2019-07-01 10:13:43,793] INFO [477b10c7f5ac1f3] - s.amazon.image.AmazonImageImpl - Amazon instance started: instanceId=z-ami-AMINUMBER-3, amazonInstanceId=sir-gre8wa9k, imageId=ami-AMINUMBER, userData=CloudInstanceUserData{myAgentName=<none>, myAuthToken='', myServerAddress='http://172:8111', myProfileDescription='CUST Dynamic Agents DEV-QA - EC2', myIdleTimeout=40 min, myCustomAgentConfigurationParameters={cloud.amazon.agent-name-prefix=DEVQA, ec2.is-spot-instance=true, system.cloud.profile_id=amazon-1, teamcity.cloud.agent.remove.policy=remove, teamcity.cloud.instance.hash=Pa5oLX66EK1jjkUAhpLEqRBFN1qvTOAk}}
[2019-07-01 10:13:43,950] INFO [3 Flush Queue 1] - .instances.StartInstanceAction - Starting cloud instance: profile 'CUSTRR-DEVQA-EC2'{id=amazon-1, projectId=project1}, AmazonImage{id=ami-AMINUMBER}, hash=jRUXq3iCMdM7ec4juWjoeMHv5X84FRDZ, reason=Automatic start: Compatible with queued build CUST RentalResult / gradle-emerald(promotionId=116)
[2019-07-01 10:13:43,951] INFO [3 Flush Queue 1] - .server.impl.CloudEventsLogger - Cloud instance entered 'scheduled to start' state, profile 'CUSTRR-DEVQA-EC2'{id=amazon-1, projectId=project1}, Amazon Instance{instanceId=z-ami-AMINUMBER-4, imageId=ami-AMINUMBER, amazonInstanceId=null, status: Scheduled to start}
[2019-07-01 10:13:43,951] INFO [3 Flush Queue 1] - .server.impl.CloudEventsLogger - Cloud instance start succeeded: profile 'CUSTRR-DEVQA-EC2'{id=amazon-1, projectId=project1}, Amazon Instance{instanceId=z-ami-AMINUMBER-4, imageId=ami-AMINUMBER, amazonInstanceId=null, status: Scheduled to start}
[2019-07-01 10:13:44,135] WARN [477b10c7f5ac1f3] - azon.sync.AmazonSyncClientImpl - Error performing tagging operation: jetbrains.buildServer.clouds.amazon.error.AmazonCloudException: Amazon EC2 connection (profile 'CUSTRR-DEVQA-EC2'{id=amazon-1}, operation:createTags). Unable to tag [sir-edjgwbbk]: 'The spot instance request ID 'sir-edjgwbbk' does not exist (Service: AmazonEC2; Status Code: 400; Error Code: InvalidSpotInstanceRequestID.NotFound; Request ID: 3d6855e1-250a-4b21-9a47-9b7ccfc7ab03)' (enable debug to see stacktrace)
[2019-07-01 10:13:44,135] WARN [477b10c7f5ac1f3] - azon.sync.AmazonSyncClientImpl - Unable to tag spot instance request sir-edjgwbbk. Will now terminate it
[2019-07-01 10:13:44,196] WARN [477b10c7f5ac1f3] - on.async.AmazonAsyncClientImpl - Amazon connection error during Start New Instance for image: ami-AMINUMBER: Amazon EC2 connection (profile 'CUSTRR-DEVQA-EC2'{id=amazon-1}, operation:cancelSpotInstanceRequests). Failed to cancel spot instance request sir-edjgwbbk: 'The spot instance request ID 'sir-edjgwbbk' does not exist (Service: AmazonEC2; Status Code: 400; Error Code: InvalidSpotInstanceRequestID.NotFound; Request ID: 374d90b8-2fe8-4e98-b743-ef6596dd871c)'
[2019-07-01 10:13:47,399] INFO [uled executor 3] - .server.impl.CloudEventsLogger - Cloud instance entered 'scheduled to start' state, profile 'CUSTRR-DEVQA-EC2'{id=amazon-1, projectId=project1}, Amazon Instance{instanceId=sir-edjgwbbk, imageId=ami-AMINUMBER, status: Scheduled to start}
[2019-07-01 10:13:49,729] INFO [49 Check quotas] - mpl.CloudInstancesProviderImpl - Instance 'sir-edjgwbbk' is marked for termination after current build finishes
[2019-07-01 10:13:49,731] INFO [49 Check quotas] - .quota.QuotedAmazonCloudClient - Amazon Instance{instanceId=sir-edjgwbbk, imageId=ami-AMINUMBER, status: Scheduled to start}, started at Mon Jul 01 10:13:44 UTC 2019 was scheduled for termination. Too much instances are running: There are 4 running instance(s) per image, but allowed only 3.
[2019-07-01 10:15:30,844] INFO [io-8111-exec-29] - server.impl.CloudManagerFacade - Cloud client for agent: 46 registered: true authorized: false was of type: jetbrains.buildServer.clouds.amazon.client.quota.QuotedAmazonCloudClient@773bbe8f and returned agent name: DEVQA-i-0ad9a64ebdd34f82f
[2019-07-01 10:19:45,399] INFO [nning Instances] - r.impl.DBCloudStateManagerImpl - Image: ami-AMINUMBER, Instance: sir-edjgwbbk, profile=amazon-1 is marked with state: stopped.
[2019-07-01 10:19:45,404] INFO [nning Instances] - r.impl.DBCloudStateManagerImpl - Image: ami-AMINUMBER, Instance: sir-gre8wa9k, profile=amazon-1 is marked with state: stopped.
[2019-07-01 10:19:45,409] INFO [nning Instances] - r.impl.DBCloudStateManagerImpl - Image: ami-AMINUMBER, Instance: sir-cfciz21g, profile=amazon-1 is marked with state: stopped.
[2019-07-01 10:19:45,890] INFO [5 Flush Queue 1] - .instances.StartInstanceAction - Starting cloud instance: profile 'CUSTRR-DEVQA-EC2'{id=amazon-1, projectId=project1}, AmazonImage{id=am

Denis Lapuente

Created July 08, 2019 17:40

The submit a request button on top should work for professional edition users as well, allowing to attach files. I am not aware of any change to this so if you haven't tried it and just were under that impression, please don't hesitate to use it. We'd rather have the full logs I mentioned, as you can see, while some useful information is in the logs, we would like to have a bigger picture plus there might be something else that might be useful for us to understand what happens.

If it doesn't work for some reason, please send them to our email support address teamcity-support@jetbrains.com , indicating this thread as a reference so if I don't pick it up straightaway somebody will be able to forward it to me.

Please sign in to leave a comment.