Join GitHub today
GitHub is home to over 50 million developers working together to host and review code, manage projects, and build software together.
Sign upWrapping simple query in Grape method causing big slowdown (3s+) #1890
Comments
|
Something is fishy, but it's nice to be looking at an OSS project with all
its guts!
Is it the entity rendering that's causing this? The Rails controller
version is returning a JSON with @suggestions.collect { |tag| tag.name
}.uniq but the Grape API is returning a DocList that is then presented via
an Entity. I would start there, how long does DocList.to_json or
.serializable_hash
take?
You might want to work on better instrumentation. Something like a NewRelic
should be able to show you exactly where you are spending time. The graphs
provided don't detail any internals.
Hope this helps.
…On Tue, Jun 25, 2019 at 9:01 PM Jeffrey Warren ***@***.***> wrote:
Hi, we're struggling to work through an issue where a Rails controller and
a Grape API endpoint both run the same underlying ActiveRecord query -
literally the same code, and do nothing else, but the controller version
runs in average 116ms and the Grape version in average 3.5s.
Here are the two in Skylight, which is great, but doesn't give us the
granularity we need to investigate further:
Navbar:
https://oss.skylight.io/app/applications/GZDPChmcfm1Q/1561487700/6h/endpoints/Srch::Search%20%5BGET%5D%20srch%2Ftags
Suggested:
https://oss.skylight.io/app/applications/GZDPChmcfm1Q/1561487520/6h/endpoints/TagController%23suggested?responseType=json
The code is documented and linked to here: publiclab/plots2#5951
<publiclab/plots2#5951>
We'd love some advice on how to further investigate, or potentially what
else makes these two requests different?
—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub
<#1890?email_source=notifications&email_token=AAEEM7YRCQEZSGJBSVDYA7DP4K5XDA5CNFSM4H3NPCM2YY3PNVWWK3TUL52HS4DFUVEXG43VMWVGG33NNVSW45C7NFSM4G3V4IYQ>,
or mute the thread
<https://github.com/notifications/unsubscribe-auth/AAEEM77W3JPQS4DUOMPBBYLP4K5XDANCNFSM4H3NPCMQ>
.
--
dB. | Moscow - Geneva - Seattle - New York
code.dblock.org - t:@dblockdotorg <http://twitter.com/#!/dblockdotorg> - ig:
@artdblockdotorg <https://www.instagram.com/artdblockdotorg> - github/dblock
<https://github.com/dblock>
|
|
Thanks a lot for the quick reply! I tried generating the doclist in the
console on the production machine and it was not slow, certainly not
seconds long. That's a good suggestion about instrumentation. I think
skylight has guidance for something like this too, so I'll look into it.
Yeah, having recently started using skylight it's nice to be able to post
it's analysis alongside our code links and the live site API all in the
open! I hope it's helpful for you too.
On Tue, Jun 25, 2019, 10:34 PM Daniel Doubrovkine (dB.) @dblockdotorg <
notifications@github.com> wrote:
… Something is fishy, but it's nice to be looking at an OSS project with all
its guts!
Is it the entity rendering that's causing this? The Rails controller
version is returning a JSON with @suggestions.collect { |tag| tag.name
}.uniq but the Grape API is returning a DocList that is then presented via
an Entity. I would start there, how long does DocList.to_json or
.serializable_hash
take?
You might want to work on better instrumentation. Something like a NewRelic
should be able to show you exactly where you are spending time. The graphs
provided don't detail any internals.
Hope this helps.
On Tue, Jun 25, 2019 at 9:01 PM Jeffrey Warren ***@***.***>
wrote:
> Hi, we're struggling to work through an issue where a Rails controller
and
> a Grape API endpoint both run the same underlying ActiveRecord query -
> literally the same code, and do nothing else, but the controller version
> runs in average 116ms and the Grape version in average 3.5s.
>
> Here are the two in Skylight, which is great, but doesn't give us the
> granularity we need to investigate further:
>
> Navbar:
>
https://oss.skylight.io/app/applications/GZDPChmcfm1Q/1561487700/6h/endpoints/Srch::Search%20%5BGET%5D%20srch%2Ftags
>
> Suggested:
>
https://oss.skylight.io/app/applications/GZDPChmcfm1Q/1561487520/6h/endpoints/TagController%23suggested?responseType=json
>
> The code is documented and linked to here: publiclab/plots2#5951
> <publiclab/plots2#5951>
>
> We'd love some advice on how to further investigate, or potentially what
> else makes these two requests different?
>
> —
> You are receiving this because you are subscribed to this thread.
> Reply to this email directly, view it on GitHub
> <
#1890?email_source=notifications&email_token=AAEEM7YRCQEZSGJBSVDYA7DP4K5XDA5CNFSM4H3NPCM2YY3PNVWWK3TUL52HS4DFUVEXG43VMWVGG33NNVSW45C7NFSM4G3V4IYQ
>,
> or mute the thread
> <
https://github.com/notifications/unsubscribe-auth/AAEEM77W3JPQS4DUOMPBBYLP4K5XDANCNFSM4H3NPCMQ
>
> .
>
--
dB. | Moscow - Geneva - Seattle - New York
code.dblock.org - ***@***.*** <http://twitter.com/#!/dblockdotorg> -
ig:
@artdblockdotorg <https://www.instagram.com/artdblockdotorg> -
github/dblock
<https://github.com/dblock>
—
You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub
<#1890?email_source=notifications&email_token=AAAF6JZ53RG7PNSIE5XCKZTP4LIPDA5CNFSM4H3NPCM2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODYSEGWI#issuecomment-505693017>,
or mute the thread
<https://github.com/notifications/unsubscribe-auth/AAAF6JZA7WQKLG5ECDWXW2TP4LIPDANCNFSM4H3NPCMQ>
.
|
|
I can see there's only 1 request. Could perhaps a part of that time is spent in pre-loading the app for the first time? |
|
Thanks, I don't think so, because this is a production app in constant use. And I can select multiple requests and get a similar result:
But I wonder if it could be something like that... some kind of boot time thing for Grape? But I don't imagine Grape itself has a lot of overhead or anything. |
|
OK, trying to add instrumentation at publiclab/plots2#6000 |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Hi, we're struggling to work through an issue where a Rails controller and a Grape API endpoint both run the same underlying ActiveRecord query - literally the same code, and do nothing else, but the controller version runs in average 116ms and the Grape version in average 3.5s.
Here are the two in Skylight, which is great, but doesn't give us the granularity we need to investigate further:
Navbar: https://oss.skylight.io/app/applications/GZDPChmcfm1Q/1561487700/6h/endpoints/Srch::Search%20%5BGET%5D%20srch%2Ftags
Suggested: https://oss.skylight.io/app/applications/GZDPChmcfm1Q/1561487520/6h/endpoints/TagController%23suggested?responseType=json
The code is documented and linked to here: publiclab/plots2#5951
We'd love some advice on how to further investigate, or potentially what else makes these two requests different?