Golang web service issues under heavy traffic

[ankit.i...@gmail.com]

I have written a web application in golang which basically extracts the url query parameters, checks if the response is cached in redis for that particular request and returns a Json response accordingly. In cases where response is not available from redis instance, I'm redirect the request to another service in golang which does some processing on the request parameters before sending a json response and also setting the cache in redis. I'm sharing my code below:

    func api(w http.ResponseWriter, r *http.Request) {
    link := r.URL.Query().Get("url")
    log.Printf(link)
    heading := r.URL.Query().Get("heading")
    escapedHeading := url.QueryEscape(heading)
   
    conn := pool.Get()
    defer conn.Close()
    reply, err := redis.Bytes(conn.Do("GET", escapedHeading))
   
    if err != nil {
    log.Printf("Error for link %v:%v", link, err)
    http.Redirect(w, r, "http://redirectservice/api?&link="+link+"&heading="+escapedHeading, 301)
    }
    w.Write(reply)
   
    }

However, after doing some load testing using two different request which has not been cached in redis, I'm having some unusual issue. The first reuqest is properly executed and gets cached in Redis but the second request seems to miss the link completely and therefore, it is sending empty string in link to my redirect api service which is breaking my application completely. I'm attaching the logs below for more refrence:

    2015/03/31 22:16:50 http://www.examle.com/somelink
    2015/03/31 22:16:50 http://www.examle.com/somelink
    2015/03/31 22:16:50 http://www.examle.com/somelink
    2015/03/31 22:16:50 http://www.examle.com/somelink
    2015/03/31 22:16:50 2015/03/31 22:16:50 Error for link :redigo: nil returned
    2015/03/31 22:16:50 2015/03/31 22:16:50 Error for link :redigo: nil returned
    2015/03/31 22:16:50 2015/03/31 22:16:50 Error for link :redigo: nil returned
    2015/03/31 22:16:50 2015/03/31 22:16:50 Error for link :redigo: nil returned

As evident from the logs, it seems that the link gets missed completely for the second case to the extent that `log.Printf(link)` does not get logged at all. For load testing, I'm maintaining a constant load of 20 requests over a period of 15 seconds for two completely unique requests (i.e. they have not been cached in redis).What's very strange is that if I make a direct request on the second link for my browser, it works perfectly normal so I believe this strange behaviour has to do something with high traffic/concurrency which I do not have much experience with. Any help in this regard will be greatly appreciated. Let me know if any more information is needed. 

[Thomas Bushnell, BSG]

Assuming it's http://godoc.org/github.com/garyburd/redigo/redis that you're using, it says that concurrent calls to the Send method are not supported. 

--
You received this message because you are subscribed to the Google Groups "golang-nuts" group.
To unsubscribe from this group and stop receiving emails from it, send an email to golang-nuts...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Harmen B]

On Wed, Apr 1, 2015 at 1:25 AM, <ankit.i...@gmail.com> wrote:

I have written a web application in golang which basically extracts the url query parameters, checks if the response is cached in redis for that particular request and returns a Json response accordingly. In cases where response is not available from redis instance, I'm redirect the request to another service in golang which does some processing on the request parameters before sending a json response and also setting the cache in redis. I'm sharing my code below:

    func api(w http.ResponseWriter, r *http.Request) {
    link := r.URL.Query().Get("url")
    log.Printf(link)
    heading := r.URL.Query().Get("heading")
    escapedHeading := url.QueryEscape(heading)
   
    conn := pool.Get()
    defer conn.Close()
    reply, err := redis.Bytes(conn.Do("GET", escapedHeading))
   
    if err != nil {
    log.Printf("Error for link %v:%v", link, err)
    http.Redirect(w, r, "http://redirectservice/api?&link="+link+"&heading="+escapedHeading, 301)

Besides what Thomas said, don't forget the `return` here in your error branch.

 

    }
    w.Write(reply)
   
    }

However, after doing some load testing using two different request which has not been cached in redis, I'm having some unusual issue. The first reuqest is properly executed and gets cached in Redis but the second request seems to miss the link completely and therefore, it is sending empty string in link to my redirect api service which is breaking my application completely. I'm attaching the logs below for more refrence:

    2015/03/31 22:16:50 http://www.examle.com/somelink
    2015/03/31 22:16:50 http://www.examle.com/somelink
    2015/03/31 22:16:50 http://www.examle.com/somelink
    2015/03/31 22:16:50 http://www.examle.com/somelink
    2015/03/31 22:16:50 2015/03/31 22:16:50 Error for link :redigo: nil returned
    2015/03/31 22:16:50 2015/03/31 22:16:50 Error for link :redigo: nil returned
    2015/03/31 22:16:50 2015/03/31 22:16:50 Error for link :redigo: nil returned
    2015/03/31 22:16:50 2015/03/31 22:16:50 Error for link :redigo: nil returned

As evident from the logs, it seems that the link gets missed completely for the second case to the extent that `log.Printf(link)` does not get logged at all. For load testing, I'm maintaining a constant load of 20 requests over a period of 15 seconds for two completely unique requests (i.e. they have not been cached in redis).What's very strange is that if I make a direct request on the second link for my browser, it works perfectly normal so I believe this strange behaviour has to do something with high traffic/concurrency which I do not have much experience with. Any help in this regard will be greatly appreciated. Let me know if any more information is needed. 

--

[kylea...@gmail.com]

I may be missing something, but it appears the author is using a connection pool per the Redigo docs. Concurrent calls to Send shouldn't be a problem here, provided the pool is set up properly and a connection is retrieved from the pool in the handler that attempts to add the information to redis.

"As evident from the logs, it seems that the link gets missed completely for the second case to the extent that `log.Printf(link)` does not get logged at all."

It actually is being logged. The error message "Error for link..." indicates that the "link" variable is the empty string. Note how you have two timestamps on the below log line. Since "link" is the empty string, the first timestamp comes from the log.Printf() statement.

2015/03/31 22:16:50 2015/03/31 22:16:50 Error for link :redigo: nil returned

Unfortunately I can only make guesses as the root cause at this point, but hopefully refuting the assumption that things aren't being logged and pointing out that "link" is the empty string helps you see something you haven't yet. How does the handler that adds information to Redis behave if "link" is the empty string?

[Florin Patan]

I might be wrong but maybe you shouldn't do "defer conn.Close()" if you do use a connection pool but rather put back then connection in the pool?