Azure: Improve of getting image list #1266

ish-hcc · 2024-08-01T02:10:52Z

Azure

Image List

Time check

New request: List appeared within about 10 minutes.
Request again: List appeared within about 30 seconds.

powerkimhub · 2024-08-01T03:01:46Z

@ish-hcc

개선 작업 캄사 드립니다.
1H-Caching 관련 문의 드립니다.
- Azure의 경우 Region에 상관 없이 Image 목록이 동일한지요?
- Caching 된 Memory Size가 어느 정도 수준인지요?

ish-hcc · 2024-08-01T06:25:30Z

@powerkimhub

Region 별로 이미지 리스트를 캐싱해야 하는 부분을 놓쳤네요 수정 작업 진행 후 테스트시 메모리 사용량 확인해 봤을때 다음과 같습니다

실행 직후 IDLE 상태: 22.5MB
koreacentral 이미지 리스트 가져오고 난 후 IDLE 상태: 49.5MB
koreacentral 이미지 리스트 가져오는 동안: 100~200MB 정도 사이
koreacentral, wetus 이미지 리스트 가져오고 난 후 IDLE 상태: 104.7MB
4번 이후에 japaneast 이미지 리스트 가져오는 동안: 130~300MB 정도 사이
koreacentral, wetus, japaneast 이미지 리스트 가져오고 난 후 IDLE 상태: 150MB
japaneast 재요청 후 IDLE 상태: 241MB

ish-hcc · 2024-08-01T06:31:47Z

@powerkimhub
추가: 일정 시간 지나고 나니 IDLE 상태, 현 시점으로 메모리 사용량이 79.8MB 로 나옵니다

powerkimhub · 2024-08-01T13:04:38Z

@ish-hcc

다음과 같은 몇 가지 시험을 진행하였습니다.
참고해주시기 바랍니다.

시험 대상 서버 버전

Only get latest image verison
QPS(Query/Sec) 초과 추적 분석을 위해서 에러 로그 추가

추가 위치: imageHandler.VMImageClient()와 같이 errList를 호출하는 4곳(맨아래 코드 블록 참고)

   vmImage, err := imageHandler.VMImageClient.Get(ctx, imageHandler.Region.Region, pName, oName, sName, imageVersion)
if err != nil {
     cblogger.Error(fmt.Sprintf("4.>>>>>> %s", err.Error()))    <==========
     errMutex.Lock()
         errList = append(errList, err.Error())

시험 방법(대상 Region: northeu)

Rest API 호출(브라우저 에러 free)

time curl -sX GET http://localhost:1024/spider/vmimage -H 'Content-Type: application/json' -d '{"ConnectionName": "azure-northeu-config"}' |json_pp > 2.json

시험 결과

호출한 Client 쪽 결과: 약19분 소요

real    19m13.985s
user    0m3.513s
sys     0m0.182s

결과 이미지 건수: 18,022개
```
$ grep NameId 2.json |wc -l
18022
```

그런데, Server는 다음과 같은 QPS 초과 에러 로그를 여러개 출력하고 있습니다.

코드 로직에 따르면,
에러가 발생하면, errList가 size >0이므로 에러를 반환해야 합니다.

[CB-SPIDER].[ERROR]: 2024-08-01 20:50:23 ImageHandler.go:254, github.com/cloud-barista/cb-spider/cloud-control-manager/cloud-driver/drivers/azure/resources.(*AzureImageHandler).ListImage.func1.1.1() - 3.>>>>>> compute.VirtualMachineImagesClient#List: Failure responding to request: StatusCode=429 -- Original Error: autorest/azure: Service returned an error. Status=429 Code="SubscriptionRequestsThrottled" Message="Number of 'read' requests for subscription actor 'a20fed83-96bd-4480-92a9-140b8e3b7c3a:a13efed9-6e7a-4f45-b440-aad4c3e9e1d0' exceeded. Please try again after '1' seconds after additional tokens are available. Refer to https://aka.ms/arm-throttling for additional information." 
[CB-SPIDER].[ERROR]: 2024-08-01 20:53:11 ImageHandler.go:254, github.com/cloud-barista/cb-spider/cloud-control-manager/cloud-driver/drivers/azure/resources.(*AzureImageHandler).ListImage.func1.1.1() - 3.>>>>>> compute.VirtualMachineImagesClient#List: Failure responding to request: StatusCode=429 -- Original Error: autorest/azure: Service returned an error. Status=429 Code="SubscriptionRequestsThrottled" Message="Number of 'read' requests for subscription actor 'a20fed83-96bd-4480-92a9-140b8e3b7c3a:a13efed9-6e7a-4f45-b440-aad4c3e9e1d0' exceeded. Please try again after '3' seconds after additional tokens are available. Refer to https://aka.ms/arm-throttling for additional information."

[issue-1]

Go routine 내부에서 발생하는 에러 수집이 안되는 이슈
다음 Go routing 함수 호출에 local 변수로 errList가 string slice로 재정의 되고 있음
- 각 Thread가 개별 errList에 에러 수집 => Go routine 빠져 나오면, Global errList는 항상 0 size
```
go func(ctx context.Context, wait *sync.WaitGroup, mutex *sync.Mutex, errList []string, errMutex *sync.Mutex, pName string) {
```

[issue-2]

다음 코드 블록에서 publisherNames[i]에 사용되는 i 값이
Go routine 밖에서 count 되기 때문에 생각하지 않은 publisherNames이 호출될 수 있음
```
  		  }(imageHandler.Ctx, &wait, mutex, errList, errMutex, publisherNames[i])
```

[임시 반영 후 재시험]

issue-1: 다음처럼 errList 인자 제거

go func(ctx context.Context, wait *sync.WaitGroup, mutex *sync.Mutex, errMutex *sync.Mutex, pName string) {

issue-2: 다음 처럼, i번째 publisherNames을 구해서 go routing으로 들어감

  	  for j := 0; j < routineMax; j++ {
  		  pName := publisherNames[i]     <=======

[임시 반영 코드 시험 결과]

Client curl 호출이 코드 로직대로 QPS 발생 error list를 출력하고, 종료됨.

[제안 사항]

서버에서 에러 상황 트레이스 할 수 있도록 에러 로그 추가 부탁 드립니다.
위 issue 부분 개선(아래 임시 코드 참고)
QPS 초과 에러 발생시 에러 메시지 가이드대로 1~3초 등 waiting 후에 재시도하는 에러 방어 코드 추가 필요 합니다.
- return시 해당 이미지는 결과에서 제외 될 것임
결과 검증을 위해서 azure cli를 통한 이미지 목록 수와
- API 호출로 얻은 이미지 목록 수 비교 부탁드립니다.
현재 Driver 수준에서는 캐시 적용은 제외해주셔도 되겠습니다.
- 10개 이상의 드라이버들이 각 리전별로 캐싱을 제공하기 시작하면,
- 새로운 이슈가 발생할 것 같습니다.
- 이러한 메타 정보 캐싱을 위해서 별도의 MC-Meta 프레임워크가 추진 중에 있습니다.

[참고:임시 반영 코드]

디버깅 분석을 위한 임시 코드입니다.

활용하시려면 코드 점검 후 활용이 필요한 코드입니다.

func (imageHandler *AzureImageHandler) ListImage() ([]*irs.ImageInfo, error) {
    // log HisCall
    hiscallInfo := GetCallLogScheme(imageHandler.Region, call.VMIMAGE, Image, "ListImage()")
    start := call.Start()
    var imageList []*irs.ImageInfo

    publishers, err := imageHandler.VMImageClient.ListPublishers(imageHandler.Ctx, imageHandler.Region.Region)
    if err != nil {
  	  createErr := errors.New(fmt.Sprintf("Failed to List Image. err = %s", err.Error()))
  	  cblogger.Error(createErr)
  	  LoggingError(hiscallInfo, createErr)
  	  return nil, createErr
    }

    var publisherNames []string
    for _, p := range *publishers.Value {
  	  if p.Name == nil ||
  		  strings.Contains(strings.ToLower(*p.Name), "test") {
  		  continue
  	  }
  	  publisherNames = append(publisherNames, *p.Name)
    }
    sort.Strings(publisherNames)

    var routineMax = 200
    var wait sync.WaitGroup
    var mutex = &sync.Mutex{}
    var lenPublisherNames = len(publisherNames)
    var errList []string
    var errMutex = &sync.Mutex{}

    for i := 0; i < lenPublisherNames; {
  	  if lenPublisherNames-i < routineMax {
  		  routineMax = lenPublisherNames - i
  	  }

  	  wait.Add(routineMax)

  	  for j := 0; j < routineMax; j++ {
  		  pName := publisherNames[i]
  		  go func(ctx context.Context, wait *sync.WaitGroup, mutex *sync.Mutex, errMutex *sync.Mutex, pName string) {
  			  defer wait.Done()
  			  offers, err := imageHandler.VMImageClient.ListOffers(ctx, imageHandler.Region.Region, pName)
  			  if err != nil {
  				  cblogger.Error(fmt.Sprintf("1.>>>>>> %s", err.Error()))
  				  errMutex.Lock()
  				  errList = append(errList, err.Error())
  				  errMutex.Unlock()

  				  return
  			  }

  			  if offers.Value == nil {
  				  return
  			  }

  			  var offerNames []string
  			  for _, o := range *offers.Value {
  				  if o.Name == nil ||
  					  strings.Contains(strings.ToLower(*o.Name), "test") ||
  					  strings.Contains(strings.ToLower(*o.Name), "preview") ||
  					  strings.Contains(strings.ToLower(*o.Name), "daily") {
  					  continue
  				  }
  				  offerNames = append(offerNames, *o.Name)
  			  }
  			  sort.Strings(offerNames)

  			  var lenOfferNames = len(offerNames)
  			  var wait2 sync.WaitGroup
  			  var routineMax2 = 150

  			  for i := 0; i < lenOfferNames; {
  				  if lenOfferNames-i < routineMax2 {
  					  routineMax2 = lenOfferNames - i
  				  }

  				  wait2.Add(routineMax2)

  				  for j := 0; j < routineMax2; j++ {
  					  go func(wait2 *sync.WaitGroup, oName string) {
  						  defer wait2.Done()

  						  skus, err := imageHandler.VMImageClient.ListSkus(ctx, imageHandler.Region.Region, pName, oName)
  						  if err != nil {
  							  cblogger.Error(fmt.Sprintf("2.>>>>>> %s", err.Error()))
  							  errMutex.Lock()
  							  errList = append(errList, err.Error())
  							  errMutex.Unlock()

  							  return
  						  }

  						  if skus.Value == nil {
  							  return
  						  }

  						  var skuNames []string
  						  for _, s := range *skus.Value {
  							  if s.Name == nil {
  								  continue
  							  }
  							  skuNames = append(skuNames, *s.Name)
  						  }
  						  sort.Strings(skuNames)

  						  var lenSkuNames = len(skuNames)
  						  var wait3 sync.WaitGroup
  						  var routineMax3 = 100

  						  for i := 0; i < lenSkuNames; {
  							  if lenSkuNames-i < routineMax3 {
  								  routineMax3 = lenSkuNames - i
  							  }

  							  wait3.Add(routineMax3)

  							  for j := 0; j < routineMax3; j++ {
  								  go func(wait3 *sync.WaitGroup, sName string) {
  									  defer wait3.Done()

  									  imageVersionList, err := imageHandler.VMImageClient.List(ctx, imageHandler.Region.Region, pName, oName, sName, "", nil, "")
  									  if err != nil {
  										  errMutex.Lock()
  										  cblogger.Error(fmt.Sprintf("3.>>>>>> %s", err.Error()))
  										  errList = append(errList, err.Error())
  										  errMutex.Unlock()

  										  return
  									  }

  									  if imageVersionList.Value == nil {
  										  return
  									  }

  									  if len(*imageVersionList.Value) == 0 {
  										  return
  									  }

  									  latest := (*imageVersionList.Value)[len(*imageVersionList.Value)-1]
  									  if latest.ID == nil {
  										  return
  									  }

  									  imageIdArr := strings.Split(*latest.ID, "/")
  									  imageVersion := imageIdArr[len(imageIdArr)-1]

  									  vmImage, err := imageHandler.VMImageClient.Get(ctx, imageHandler.Region.Region, pName, oName, sName, imageVersion)
  									  if err != nil {
  										  cblogger.Error(fmt.Sprintf("4.>>>>>> %s", err.Error()))
  										  errMutex.Lock()
  										  errList = append(errList, err.Error())
  										  errMutex.Unlock()

  										  return
  									  }
  									  vmImageInfo := imageHandler.setterVMImage(vmImage)
  									  mutex.Lock()
  									  imageList = append(imageList, vmImageInfo)
  									  mutex.Unlock()
  								  }(&wait3, skuNames[i])

  								  i++
  								  if i == lenPublisherNames {
  									  break
  								  }
  							  }

  							  wait3.Wait()
  						  }

  					  }(&wait2, offerNames[i])

  					  i++
  					  if i == lenOfferNames {
  						  break
  					  }
  				  }

  				  wait2.Wait()
  			  }
  		  }(imageHandler.Ctx, &wait, mutex, errMutex, pName)

  		  i++
  		  if i == lenPublisherNames {
  			  break
  		  }
  	  }

  	  wait.Wait()
    }
    if len(errList) > 0 {
  	  cblogger.Error(strings.Join(errList, "\n"))
  	  return nil, errors.New(strings.Join(errList, "\n"))
    }

    LoggingInfo(hiscallInfo, start)
    return imageList, nil
}

powerkimhub · 2024-08-01T13:10:46Z

@ish-hcc

참고로, old 버전 이미지도 제공하는 이전 버전의 경우는 QPS 초과 에러가 발생하면서도
25분 정도에 49,970건 정도의 이미지 결과를 제공했었습니다.
하지만, 현재 상태에서 소요 시간과 건수는 캐바캐였을 것 같습니다.
QPS 초과 에러가 많이 발생할 수록 API 호출 종료 시간은 빨라질 것이고,
반환 되는 결과 목록 수는 줄어들 것이라 생각됩니다.

… issue

…ue to an error

ish-hcc · 2024-08-02T08:18:23Z

Comparing the number of images in cb-spider and the number of images in az CLI...

Azure: Only get latest image verison

d4ef599

ish-hcc self-assigned this Aug 1, 2024

ish-hcc requested a review from powerkimhub August 1, 2024 02:32

powerkimhub mentioned this pull request Aug 1, 2024

[Azure:Image] Can't fetch image list #1260

Closed

ish-hcc force-pushed the fix_azure_image branch from 07fdc61 to d4ef599 Compare August 2, 2024 03:43

ish-hcc added 3 commits August 2, 2024 12:46

Azure: Add error logs to ListImage() and fix pulisher name go routine…

e60a7ed

… issue

Azure: Fixed an issue where some images were excluded from the list d…

b23b8a6

…ue to an error

Azure: Get all of images

35583b3

Update ImageHandler.go

2c49697

powerkimhub approved these changes Aug 2, 2024

View reviewed changes

powerkimhub linked an issue Aug 2, 2024 that may be closed by this pull request

[Azure:Image] Can't fetch image list #1260

Closed

powerkimhub merged commit c2d90a1 into cloud-barista:master Aug 2, 2024
3 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Azure: Improve of getting image list #1266

Azure: Improve of getting image list #1266

ish-hcc commented Aug 1, 2024 •

edited

Loading

powerkimhub commented Aug 1, 2024

ish-hcc commented Aug 1, 2024 •

edited

Loading

ish-hcc commented Aug 1, 2024 •

edited

Loading

powerkimhub commented Aug 1, 2024

powerkimhub commented Aug 1, 2024

ish-hcc commented Aug 2, 2024

Azure: Improve of getting image list #1266

Azure: Improve of getting image list #1266

Conversation

ish-hcc commented Aug 1, 2024 • edited Loading

Azure

Image List

Time check

powerkimhub commented Aug 1, 2024

ish-hcc commented Aug 1, 2024 • edited Loading

ish-hcc commented Aug 1, 2024 • edited Loading

powerkimhub commented Aug 1, 2024

powerkimhub commented Aug 1, 2024

ish-hcc commented Aug 2, 2024

ish-hcc commented Aug 1, 2024 •

edited

Loading

ish-hcc commented Aug 1, 2024 •

edited

Loading

ish-hcc commented Aug 1, 2024 •

edited

Loading