Skip to content

Need some help to understand some weird behavior #1475

@elC0mpa

Description

@elC0mpa

Hello, first of all would like to thank you for maintaining this great library

I had some weird behavior related to logrus some time ago and now I would like to understand it in a better way, and there is no better way to do that that in an issue here 😂

Ok, basically I had the following code:

func (c *CommercialPoliciesClient) applyResellerAndAgencyCommercialPolicies(request *Request, agencyCommercialPolicies map[string]common.CommercialPolicy, resellerCommercialPolicies map[string]common.CommercialPolicy) ([]common.Itinerary, error) {
	var result []common.Itinerary

	var mutex sync.RWMutex

	wp := workerpool.New(c.maxWorkers)

	resellerCurrencyRatiosCache := newCurrencyRatiosCache(request.SearchRequest, c.currencyConnector)
	agencyCurrencyRatiosCache := newCurrencyRatiosCache(GetAgencySearchRequest(request.SearchRequest), c.currencyConnector)

	for index := range request.Itineraries {
		i := index

		wp.Submit(func() {
			defer mutex.Unlock()

			mutex.Lock()

			resellerPolicy, ok := resellerCommercialPolicies[request.Itineraries[i].ID]
			if !ok {
                                logrus.Warnf("ignore itinerary[%s] because have not reseller commercial policy", request.Itineraries[i].ID)
				return
			}

			agencyPolicy, ok := agencyCommercialPolicies[request.Itineraries[i].ID]
			if !ok {
                                logrus.Warnf("ignore itinerary[%s] because have not agency commercial policy", request.Itineraries[i].ID)
				return
			}

			c.applyCommercialPolicy(resellerCurrencyRatiosCache, c.applicable, resellerPolicy, &request.Itineraries[i])
			c.applyCommercialPolicy(agencyCurrencyRatiosCache, c.applicable, agencyPolicy, &request.Itineraries[i])

			result = append(result, request.Itineraries[i])
		})
	}

	wp.StopWait()

	return result, nil
}

Take into consideration that usually itineraries were like 2000, and usually around 500 itineraries didn't have commercial policies. I realized that this was taking more than expected, for example, it was taking around 10 seconds. After some profiling I realized the delay was being caused by the logrus library, something that really impressed me. I deleted these logrus instructions and now it always takes less than one second. I just want to understand why was this happening.
I assume that because of I am waiting for all the concurrent executions to finish, and I am logging inside these, it can write to the OS stdout just one message at the time, but this is just an assumption.

Please help me to understand what happened here. Thank you!!!!

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions