Re: [go-nuts] Performance hit when using goroutine

2018-05-22 Thread Dave Cheney 
The execution tracer will show this as it tracks resources that goroutines 
block on. 

Seriously I’m just going to keep suggesting the execution tracer until you try 
it :)

-- 
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.
For more options, visit https://groups.google.com/d/optout.

Re: [go-nuts] Performance hit when using goroutine

2018-05-22 Thread Burak Serdar 
On Tue, May 22, 2018 at 12:21 AM, Hawari Rahman
 wrote:
> Hi Burak,
>
> Thank you for your reply,
> Inside the HydrateCollection function there are database queries (at least
> three), run using the same *sql.DB throughout the application.
>
>> Is it possible that
>> whatever connection HydrateCollection is operating on cannot handle
>> multiple concurrent requests?
>
>
> In that case, what should I look out for? I've always assumed that using a
> global *sql.DB will always suffice.


One thing you can try is to get multiple db connections instead of
using a shared one. If your db driver is serializing concurrent
operations on the same connection, the goroutines would run
sequentially, which seems to be the case.


>
> On Tuesday, May 22, 2018 at 12:36:25 PM UTC+7, Burak Serdar wrote:
>>
>> On Mon, May 21, 2018 at 11:12 PM, Hawari Rahman
>>  wrote:
>> > Hi Everyone,
>> >
>> > So for the background, I have an API for retrieving data from a
>> > database.
>> > For an endpoint there exists two function calls:
>> > - SelectCollections - for retrieving the collection records
>> > - HydrateCollection - for hydrating each collections (the second
>> > function is
>> > called on each results of the SelectCollections function).
>> >
>> > Previously we run the HydrateCollections sequentially using a for loop,
>> > and
>> > it results in the following:
>> >
>> > 2018/05/22 10:59:05 HydrateCollection took 41.497134ms
>> > 2018/05/22 10:59:05 HydrateCollection took 42.695152ms
>> > 2018/05/22 10:59:05 HydrateCollection took 22.870913ms
>> > 2018/05/22 10:59:05 HydrateCollection took 17.833512ms
>> > 2018/05/22 10:59:05 HydrateCollection took 18.765984ms
>> > 2018/05/22 10:59:05 HydrateCollection took 16.338906ms
>> > 2018/05/22 10:59:05 HydrateCollection took 14.660654ms
>> > 2018/05/22 10:59:05 HydrateCollection took 20.818716ms
>> > 2018/05/22 10:59:05 HydrateCollection took 18.57054ms
>> > 2018/05/22 10:59:05 Resolving Items took 172.9182ms
>> > 2018/05/22 10:59:05 SelectCollections took 173.992051ms
>> >
>> > After using goroutines to run HydrateCollections now the results is as
>> > follows:
>> >
>> > 2018/05/22 11:21:36 HydrateCollection took 9.187861ms
>> > 2018/05/22 11:21:36 HydrateCollection took 63.651507ms
>> > 2018/05/22 11:21:36 HydrateCollection took 79.199976ms
>> > 2018/05/22 11:21:36 HydrateCollection took 122.349986ms
>> > 2018/05/22 11:21:37 HydrateCollection took 150.627746ms
>> > 2018/05/22 11:21:37 HydrateCollection took 168.432517ms
>> > 2018/05/22 11:21:37 HydrateCollection took 171.602705ms
>> > 2018/05/22 11:21:37 HydrateCollection took 179.127794ms
>> > 2018/05/22 11:21:37 HydrateCollection took 185.137562ms
>> > 2018/05/22 11:21:37 Resolving items took 185.434821ms
>> > 2018/05/22 11:21:37 SelectCollections took 187.358141ms
>>
>> It is difficult to guess without knowing what HydrateCollection does.
>> But these numbers are increasing monotonically. Is it possible that
>> whatever connection HydrateCollection is operating on cannot handle
>> multiple concurrent requests? Maybe some transaction isolation
>> problem? So all HydrateCollection instances start running at the same
>> time, but the second one cannot actually start its work until the
>> first is done, and third cannot start until the second is done, etc.?
>> You can test if that's the case by logging the start-end times of
>> HydrateCollections and the collections each are working on.
>>
>> >
>> >
>> > Why does the HydrateCollection take a significant performance hit now
>> > that
>> > I'm using goroutine?
>> >
>> > HydrateCollection function takes a pointer to Collection struct, and
>> > mutating it inside the goroutine, so I think that it may be a problem.
>> > Also
>> > the HydrateCollection itself is a method of a Repository pointer which
>> > holds
>> > a database connection, the same Repository pointer is used by
>> > SelectCollections.
>> >
>> > hydrateChan := make(chan error, len(collections))
>> > for index := range collections {
>> > go func(coll *Collection) {
>> > hydrateChan <- r.hydrateCollection(coll)
>> > }([index])
>> > }
>> >
>> > for i := 0; i < len(collections); i++ {
>> > err := <-hydrateChan
>> > if err != nil {
>> > logrus.Error(err)
>> > }
>> > }
>> >
>> > Is there something that I need to address in the previous code snippet?
>> >
>> > --
>> > 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.
>
> --
> 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.
> For more options, visit

Re: [go-nuts] Performance hit when using goroutine

2018-05-22 Thread Justin Israel 
On Tue, May 22, 2018, 6:35 PM Hawari Rahman 
wrote:

> After some more detailed investigation, it seems the most time consuming
> process is a "Select by IDs" query. So to hydrate a Collection object, I
> need to retrieve another objects through a SELECT WHERE id = ANY(?)" query
> in postgres. I'm curious on how the performance can differs greatly when
> concurrency is introduced.
>

Is the query doing a table scan vs using the index?

> --
> 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.
> For more options, visit https://groups.google.com/d/optout.
>

-- 
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.
For more options, visit https://groups.google.com/d/optout.

Re: [go-nuts] Performance hit when using goroutine

2018-05-22 Thread Jan Mercl 
On Tue, May 22, 2018 at 7:12 AM Hawari Rahman 
wrote:

> Is there something that I need to address in the previous code snippet?

It's necessary to analyze and understand the code to figure out if adding
concurrency makes sense. Just running many tasks in goroutines does not per
se guarantee any improvements. Actually it can be the opposite.

Later you wrote that all of the goroutines access a DB. It's possible that
some/all DB methods do lock the DB. So only one goroutine at a time can
actually do something useful. The code is then essentially serial and
adding many goroutines to execute it just adds scheduling and communication
overhead for no good reason.

Also, even where concurrency makes sense, launching too many goroutines can
make things again worse. Only benchmarks can tell for sure, but often the
right number of workers is roughly the same as the number of CPU cores
available.

-- 

-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.
For more options, visit https://groups.google.com/d/optout.

Re: [go-nuts] Performance hit when using goroutine

2018-05-22 Thread Hawari Rahman 
After some more detailed investigation, it seems the most time consuming 
process is a "Select by IDs" query. So to hydrate a Collection object, I 
need to retrieve another objects through a SELECT WHERE id = ANY(?)" query 
in postgres. I'm curious on how the performance can differs greatly when 
concurrency is introduced.

-- 
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.
For more options, visit https://groups.google.com/d/optout.

Re: [go-nuts] Performance hit when using goroutine

2018-05-22 Thread Hawari Rahman 
Hi Burak,

Thank you for your reply,
Inside the HydrateCollection function there are database queries (at least 
three), run using the same *sql.DB throughout the application.

Is it possible that 
> whatever connection HydrateCollection is operating on cannot handle 
> multiple concurrent requests?
>

In that case, what should I look out for? I've always assumed that using a 
global *sql.DB will always suffice.

On Tuesday, May 22, 2018 at 12:36:25 PM UTC+7, Burak Serdar wrote:
>
> On Mon, May 21, 2018 at 11:12 PM, Hawari Rahman 
>  wrote: 
> > Hi Everyone, 
> > 
> > So for the background, I have an API for retrieving data from a 
> database. 
> > For an endpoint there exists two function calls: 
> > - SelectCollections - for retrieving the collection records 
> > - HydrateCollection - for hydrating each collections (the second 
> function is 
> > called on each results of the SelectCollections function). 
> > 
> > Previously we run the HydrateCollections sequentially using a for loop, 
> and 
> > it results in the following: 
> > 
> > 2018/05/22 10:59:05 HydrateCollection took 41.497134ms 
> > 2018/05/22 10:59:05 HydrateCollection took 42.695152ms 
> > 2018/05/22 10:59:05 HydrateCollection took 22.870913ms 
> > 2018/05/22 10:59:05 HydrateCollection took 17.833512ms 
> > 2018/05/22 10:59:05 HydrateCollection took 18.765984ms 
> > 2018/05/22 10:59:05 HydrateCollection took 16.338906ms 
> > 2018/05/22 10:59:05 HydrateCollection took 14.660654ms 
> > 2018/05/22 10:59:05 HydrateCollection took 20.818716ms 
> > 2018/05/22 10:59:05 HydrateCollection took 18.57054ms 
> > 2018/05/22 10:59:05 Resolving Items took 172.9182ms 
> > 2018/05/22 10:59:05 SelectCollections took 173.992051ms 
> > 
> > After using goroutines to run HydrateCollections now the results is as 
> > follows: 
> > 
> > 2018/05/22 11:21:36 HydrateCollection took 9.187861ms 
> > 2018/05/22 11:21:36 HydrateCollection took 63.651507ms 
> > 2018/05/22 11:21:36 HydrateCollection took 79.199976ms 
> > 2018/05/22 11:21:36 HydrateCollection took 122.349986ms 
> > 2018/05/22 11:21:37 HydrateCollection took 150.627746ms 
> > 2018/05/22 11:21:37 HydrateCollection took 168.432517ms 
> > 2018/05/22 11:21:37 HydrateCollection took 171.602705ms 
> > 2018/05/22 11:21:37 HydrateCollection took 179.127794ms 
> > 2018/05/22 11:21:37 HydrateCollection took 185.137562ms 
> > 2018/05/22 11:21:37 Resolving items took 185.434821ms 
> > 2018/05/22 11:21:37 SelectCollections took 187.358141ms 
>
> It is difficult to guess without knowing what HydrateCollection does. 
> But these numbers are increasing monotonically. Is it possible that 
> whatever connection HydrateCollection is operating on cannot handle 
> multiple concurrent requests? Maybe some transaction isolation 
> problem? So all HydrateCollection instances start running at the same 
> time, but the second one cannot actually start its work until the 
> first is done, and third cannot start until the second is done, etc.? 
> You can test if that's the case by logging the start-end times of 
> HydrateCollections and the collections each are working on. 
>
> > 
> > 
> > Why does the HydrateCollection take a significant performance hit now 
> that 
> > I'm using goroutine? 
> > 
> > HydrateCollection function takes a pointer to Collection struct, and 
> > mutating it inside the goroutine, so I think that it may be a problem. 
> Also 
> > the HydrateCollection itself is a method of a Repository pointer which 
> holds 
> > a database connection, the same Repository pointer is used by 
> > SelectCollections. 
> > 
> > hydrateChan := make(chan error, len(collections)) 
> > for index := range collections { 
> > go func(coll *Collection) { 
> > hydrateChan <- r.hydrateCollection(coll) 
> > }([index]) 
> > } 
> > 
> > for i := 0; i < len(collections); i++ { 
> > err := <-hydrateChan 
> > if err != nil { 
> > logrus.Error(err) 
> > } 
> > } 
> > 
> > Is there something that I need to address in the previous code snippet? 
> > 
> > -- 
> > 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. 
>

-- 
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.
For more options, visit https://groups.google.com/d/optout.

Re: [go-nuts] Performance hit when using goroutine

2018-05-21 Thread Burak Serdar 
On Mon, May 21, 2018 at 11:12 PM, Hawari Rahman
 wrote:
> Hi Everyone,
>
> So for the background, I have an API for retrieving data from a database.
> For an endpoint there exists two function calls:
> - SelectCollections - for retrieving the collection records
> - HydrateCollection - for hydrating each collections (the second function is
> called on each results of the SelectCollections function).
>
> Previously we run the HydrateCollections sequentially using a for loop, and
> it results in the following:
>
> 2018/05/22 10:59:05 HydrateCollection took 41.497134ms
> 2018/05/22 10:59:05 HydrateCollection took 42.695152ms
> 2018/05/22 10:59:05 HydrateCollection took 22.870913ms
> 2018/05/22 10:59:05 HydrateCollection took 17.833512ms
> 2018/05/22 10:59:05 HydrateCollection took 18.765984ms
> 2018/05/22 10:59:05 HydrateCollection took 16.338906ms
> 2018/05/22 10:59:05 HydrateCollection took 14.660654ms
> 2018/05/22 10:59:05 HydrateCollection took 20.818716ms
> 2018/05/22 10:59:05 HydrateCollection took 18.57054ms
> 2018/05/22 10:59:05 Resolving Items took 172.9182ms
> 2018/05/22 10:59:05 SelectCollections took 173.992051ms
>
> After using goroutines to run HydrateCollections now the results is as
> follows:
>
> 2018/05/22 11:21:36 HydrateCollection took 9.187861ms
> 2018/05/22 11:21:36 HydrateCollection took 63.651507ms
> 2018/05/22 11:21:36 HydrateCollection took 79.199976ms
> 2018/05/22 11:21:36 HydrateCollection took 122.349986ms
> 2018/05/22 11:21:37 HydrateCollection took 150.627746ms
> 2018/05/22 11:21:37 HydrateCollection took 168.432517ms
> 2018/05/22 11:21:37 HydrateCollection took 171.602705ms
> 2018/05/22 11:21:37 HydrateCollection took 179.127794ms
> 2018/05/22 11:21:37 HydrateCollection took 185.137562ms
> 2018/05/22 11:21:37 Resolving items took 185.434821ms
> 2018/05/22 11:21:37 SelectCollections took 187.358141ms

It is difficult to guess without knowing what HydrateCollection does.
But these numbers are increasing monotonically. Is it possible that
whatever connection HydrateCollection is operating on cannot handle
multiple concurrent requests? Maybe some transaction isolation
problem? So all HydrateCollection instances start running at the same
time, but the second one cannot actually start its work until the
first is done, and third cannot start until the second is done, etc.?
You can test if that's the case by logging the start-end times of
HydrateCollections and the collections each are working on.

>
>
> Why does the HydrateCollection take a significant performance hit now that
> I'm using goroutine?
>
> HydrateCollection function takes a pointer to Collection struct, and
> mutating it inside the goroutine, so I think that it may be a problem. Also
> the HydrateCollection itself is a method of a Repository pointer which holds
> a database connection, the same Repository pointer is used by
> SelectCollections.
>
> hydrateChan := make(chan error, len(collections))
> for index := range collections {
> go func(coll *Collection) {
> hydrateChan <- r.hydrateCollection(coll)
> }([index])
> }
>
> for i := 0; i < len(collections); i++ {
> err := <-hydrateChan
> if err != nil {
> logrus.Error(err)
> }
> }
>
> Is there something that I need to address in the previous code snippet?
>
> --
> 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.
> For more options, visit https://groups.google.com/d/optout.

-- 
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.
For more options, visit https://groups.google.com/d/optout.