Re: [go-nuts] json decode is very slow
Excellent advice Jesper! On Sunday, 3 May 2020 10:34:12 UTC+1, Jesper Louis Andersen wrote: > > The general rule is to run a corollary of Dijkstra: experiments can only > show the presence of problems in a system, not their absence :) > > That is, seek to validate your assumptions rather than trying to guess > what is wrong with the system. > > The obvious things to check against are HTTP/1.1 vs HTTP/2 operation. > There are times where the multiplexing nature of HTTP/2 needs some more > gentle coercion in order to run fast. And I wouldn't a priori assume your > proxy takes all of the request given the sizes of the inputs. I'd much > rather assume it will use some kind of small buffering. Otherwise, your > proxy are sitting with 512 kilobyte of data in a buffer and that is going > to be a problem given enough connections. It might do buffering up to 4k or > something such however. Above that, it is likely to start streaming the > data in a little bit at a time. This is definitely something to do some > investigation on. > > If you cut out GCP/GKE/ISTIO you can verify if the culprit is Go itself, > or something in front of it. Since you have a fast and a slow system, you > can slot each in and look for differences in how the system is operating. > > On Thu, Apr 30, 2020 at 1:14 PM Sarath Prabath Redlapalli Jaya < > harrysa...@gmail.com > wrote: > >> Thanks Amnon & Hi Jesper, >> >> You're correct. Most of the time is actually spent in *ioutil.ReadAll()* . >> Trying to debug network issues related to GCP, GKE & the functionality of >> ISTIO sidecar reverse proxy, but seems okay so far couldn't find anything. >> >> But, I've performed an interesting experiment. >> >> Tried the same API in Ruby with Sinatra by mirroring the traffic. When >> instrumented the API Response Times, all were <= 100 ms. Any clues on how >> to debug this?I can't seem to find much on inner workings of >> http.Request.Body -> io.ReadCloser >> >> Also, If we're are looking for flaky end-user connections i.e., mobile >> wireless devices etc., the connection termination is at reverse proxy >> itself and the lag in reading request shouldn't be observed at the >> application level. Correct me if I'm wrong. >> >> Regards >> >> On Thu, Apr 30, 2020 at 2:34 PM Jesper Louis Andersen < >> jesper.lo...@gmail.com > wrote: >> >>> On Tue, Apr 28, 2020 at 6:48 PM Sarath Prabath Redlapalli Jaya < >>> harrysa...@gmail.com > wrote: >>> We've instrument the above code block and reading request body bytes is taking very long i.e., upto 5 secs sometimes reaching upto 20 seconds at the throughput of ~4-5K RPM The Request Body Size Metrics are as follows Average: 73190 Bytes 90th percentile: 170862 Bytes 99th percentile: 467638 Bytes >>> Let us assume we have 500 kilobytes of data. At 20 seconds processing >>> time, you are looking at something like 25 bytes per millisecond, which >>> seems rather low for a decent CPU. Try measuring the time it takes to >>> ioutil.ReadAll from the Reader I assume you have access to. My hunch is you >>> are spending most of the time there, and relatively little on decoding the >>> JSON data you have. Once you've done this, you will have some more >>> knowledge of where to look: the network, or the JSON decoder. >>> >>> If this is a web request, you should also look at how time it takes the >>> other end to feed data to the GCP process. Chances are that the problem is >>> in the other end, and you are looking at a slow sender, especially if you >>> have a large set of mobile devices out there with variety in their internet >>> connections. >>> >>> > > -- > J. > -- 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+unsubscr...@googlegroups.com. To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/84af6b68-8c5c-440a-aabb-32c590764a79%40googlegroups.com.
Re: [go-nuts] json decode is very slow
The general rule is to run a corollary of Dijkstra: experiments can only show the presence of problems in a system, not their absence :) That is, seek to validate your assumptions rather than trying to guess what is wrong with the system. The obvious things to check against are HTTP/1.1 vs HTTP/2 operation. There are times where the multiplexing nature of HTTP/2 needs some more gentle coercion in order to run fast. And I wouldn't a priori assume your proxy takes all of the request given the sizes of the inputs. I'd much rather assume it will use some kind of small buffering. Otherwise, your proxy are sitting with 512 kilobyte of data in a buffer and that is going to be a problem given enough connections. It might do buffering up to 4k or something such however. Above that, it is likely to start streaming the data in a little bit at a time. This is definitely something to do some investigation on. If you cut out GCP/GKE/ISTIO you can verify if the culprit is Go itself, or something in front of it. Since you have a fast and a slow system, you can slot each in and look for differences in how the system is operating. On Thu, Apr 30, 2020 at 1:14 PM Sarath Prabath Redlapalli Jaya < harrysarath2...@gmail.com> wrote: > Thanks Amnon & Hi Jesper, > > You're correct. Most of the time is actually spent in *ioutil.ReadAll()* . > Trying to debug network issues related to GCP, GKE & the functionality of > ISTIO sidecar reverse proxy, but seems okay so far couldn't find anything. > > But, I've performed an interesting experiment. > > Tried the same API in Ruby with Sinatra by mirroring the traffic. When > instrumented the API Response Times, all were <= 100 ms. Any clues on how > to debug this?I can't seem to find much on inner workings of > http.Request.Body -> io.ReadCloser > > Also, If we're are looking for flaky end-user connections i.e., mobile > wireless devices etc., the connection termination is at reverse proxy > itself and the lag in reading request shouldn't be observed at the > application level. Correct me if I'm wrong. > > Regards > > On Thu, Apr 30, 2020 at 2:34 PM Jesper Louis Andersen < > jesper.louis.ander...@gmail.com> wrote: > >> On Tue, Apr 28, 2020 at 6:48 PM Sarath Prabath Redlapalli Jaya < >> harrysarath2...@gmail.com> wrote: >> >>> We've instrument the above code block and reading request body bytes is >>> taking very long i.e., upto 5 secs sometimes reaching upto 20 seconds at >>> the throughput of ~4-5K RPM >>> >>> >>> The Request Body Size Metrics are as follows >>> >>> Average: 73190 Bytes >>> 90th percentile: 170862 Bytes >>> 99th percentile: 467638 Bytes >>> >>> >> Let us assume we have 500 kilobytes of data. At 20 seconds processing >> time, you are looking at something like 25 bytes per millisecond, which >> seems rather low for a decent CPU. Try measuring the time it takes to >> ioutil.ReadAll from the Reader I assume you have access to. My hunch is you >> are spending most of the time there, and relatively little on decoding the >> JSON data you have. Once you've done this, you will have some more >> knowledge of where to look: the network, or the JSON decoder. >> >> If this is a web request, you should also look at how time it takes the >> other end to feed data to the GCP process. Chances are that the problem is >> in the other end, and you are looking at a slow sender, especially if you >> have a large set of mobile devices out there with variety in their internet >> connections. >> >> -- J. -- 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+unsubscr...@googlegroups.com. To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/CAGrdgiW4tkAs1cmS4r0nOcaEXcTL%3D2nbofBL9qUa%3D%3DRZuT11hQ%40mail.gmail.com.
Re: [go-nuts] json decode is very slow
Thanks Amnon & Hi Jesper, You're correct. Most of the time is actually spent in *ioutil.ReadAll()* . Trying to debug network issues related to GCP, GKE & the functionality of ISTIO sidecar reverse proxy, but seems okay so far couldn't find anything. But, I've performed an interesting experiment. Tried the same API in Ruby with Sinatra by mirroring the traffic. When instrumented the API Response Times, all were <= 100 ms. Any clues on how to debug this?I can't seem to find much on inner workings of http.Request.Body -> io.ReadCloser Also, If we're are looking for flaky end-user connections i.e., mobile wireless devices etc., the connection termination is at reverse proxy itself and the lag in reading request shouldn't be observed at the application level. Correct me if I'm wrong. Regards On Thu, Apr 30, 2020 at 2:34 PM Jesper Louis Andersen < jesper.louis.ander...@gmail.com> wrote: > On Tue, Apr 28, 2020 at 6:48 PM Sarath Prabath Redlapalli Jaya < > harrysarath2...@gmail.com> wrote: > >> We've instrument the above code block and reading request body bytes is >> taking very long i.e., upto 5 secs sometimes reaching upto 20 seconds at the >> throughput of ~4-5K RPM >> >> >> The Request Body Size Metrics are as follows >> >> Average: 73190 Bytes >> 90th percentile: 170862 Bytes >> 99th percentile: 467638 Bytes >> >> > Let us assume we have 500 kilobytes of data. At 20 seconds processing > time, you are looking at something like 25 bytes per millisecond, which > seems rather low for a decent CPU. Try measuring the time it takes to > ioutil.ReadAll from the Reader I assume you have access to. My hunch is you > are spending most of the time there, and relatively little on decoding the > JSON data you have. Once you've done this, you will have some more > knowledge of where to look: the network, or the JSON decoder. > > If this is a web request, you should also look at how time it takes the > other end to feed data to the GCP process. Chances are that the problem is > in the other end, and you are looking at a slow sender, especially if you > have a large set of mobile devices out there with variety in their internet > connections. > > -- 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+unsubscr...@googlegroups.com. To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/CADOH-f9mhKy0e3B9exCe8P3BNmgO5OMCXwGsNN1VjWSg3ofNqQ%40mail.gmail.com.
Re: [go-nuts] json decode is very slow
On Tue, Apr 28, 2020 at 6:48 PM Sarath Prabath Redlapalli Jaya < harrysarath2...@gmail.com> wrote: > We've instrument the above code block and reading request body bytes is > taking very long i.e., upto 5 secs sometimes reaching upto 20 seconds at the > throughput of ~4-5K RPM > > > The Request Body Size Metrics are as follows > > Average: 73190 Bytes > 90th percentile: 170862 Bytes > 99th percentile: 467638 Bytes > > Let us assume we have 500 kilobytes of data. At 20 seconds processing time, you are looking at something like 25 bytes per millisecond, which seems rather low for a decent CPU. Try measuring the time it takes to ioutil.ReadAll from the Reader I assume you have access to. My hunch is you are spending most of the time there, and relatively little on decoding the JSON data you have. Once you've done this, you will have some more knowledge of where to look: the network, or the JSON decoder. If this is a web request, you should also look at how time it takes the other end to feed data to the GCP process. Chances are that the problem is in the other end, and you are looking at a slow sender, especially if you have a large set of mobile devices out there with variety in their internet connections. -- 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+unsubscr...@googlegroups.com. To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/CAGrdgiWYeMuFvV-kO4kYDQbVHKCHKw%3D4A13PSPKCywiDfn2L%3DQ%40mail.gmail.com.
