Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Displayed time in Kreya is significantly longer than the actual gRPC API response time. #130

Closed
DaveNay opened this issue Feb 8, 2023 · 12 comments
Labels
bug Something isn't working

Comments

@DaveNay
Copy link

DaveNay commented Feb 8, 2023

Describe the bug
Displayed time in Kreya is significantly longer than the actual gRPC API response time. The timer in Kreya continues to increase after the results are displayed.

To Reproduce
Steps to reproduce the behavior:

  1. Run a gRPC server application
  2. Perform a unary gRPC call in Kreya
  3. Compare the time displayed in Kreya with the actual server response time.

Expected behavior
I would expect the displayed time in Kreya to be closer to the logged API response time (with some overhead).

Screenshots
Time displayed in Kreya:

image

Response time in console log:

image

Environment (if possible, copy the information from the error dialog or the About menu):

  • OS: Windows 10 Enterprise/ASP. Net Core 7 gRPC
  • Kreya Version:
    {
    "kreyaVersion": "1.9.0",
    "platform": "Win32",
    "userAgent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Edg/109.0.1518.78"
    }

Additional context
The displayed response time in BloomRPC is much closer to the logged time:

image

@DaveNay DaveNay added the bug Something isn't working label Feb 8, 2023
@CommonGuy
Copy link
Contributor

Could you post the content of the "Trace" tab (with confidental information removed)? Kreya measures the total time it takes to call the gRPC method, which includes things like DNS resolution. But a discrepancy of over 3 seconds is indeed quite large.

@CommonGuy CommonGuy added the status:needs-info To investigate this, more information is needed label Feb 8, 2023
@DaveNay
Copy link
Author

DaveNay commented Feb 8, 2023

@CommonGuy, the Trace tab is empty. Does it need to be explicitly enabled?

image

There should be no DNS resolution, I am running everything on Localhost for now:

image

@CommonGuy
Copy link
Contributor

Very strange. Traces should always be displayed.

Localhost still uses DNS resolution and may be a cause for delays, see #78.

Is the behaviour consistent? What happens if you change the endpoint to http://127.0.0.1:7300 (IPv4) or http://[::1]:7300 (IPv6)? Do other gRPC services such as http://grpcb.in:9000 cause the same problem?

@DaveNay
Copy link
Author

DaveNay commented Feb 8, 2023

Hmmmm....switching to 127.0.0.1:7300 seems to fix it!

image

image

@DaveNay
Copy link
Author

DaveNay commented Feb 8, 2023

Nope...false hope. I restarted Kreya with the endpoint saved and it went back to the slow response time.

image

@CommonGuy
Copy link
Contributor

If you invoke the operation multiple times, does the delay persist? Or is it only with the first call?

If you first select the Trace tab and then send the operation, does anything show up at all?

Could you share the contents of %APPDATA%\Kreya\kreya.log?

@DaveNay
Copy link
Author

DaveNay commented Feb 8, 2023

It is not limited to the first call.

Selecting Trace tab and then Send does not change anything; the Trace tab is still empty.

There is no kreya.log file in that location. 😢

image

@DaveNay
Copy link
Author

DaveNay commented Feb 8, 2023

@CommonGuy As a further test, I uninstalled Kreya, deleted the %APPDATA%\Kreya folder, and verified that C:\Program Files\Kreya was deleted during uninstall.

I then downloaded a clean copy of Kreya and installed it.

After this there was zero change in behavior:

  • The reported time in Kreya is excessively long.
  • The Trace tab in Kreya is empty.
  • There is no kreya.log file in %APPDATA%\Kreya
  • The kreya.db SQLite database IS present in %APPDATA%\Kreya

@alteredego
Copy link

alteredego commented Mar 7, 2023

This behaviour also happens for me. The Kreya response time has ~+3s added to it. If it helps debug any further, when I tried to change my connection to an ip address I had a failed SSL certificate warning which also responded in +3s

I also have no Trace information and no recently updated kreya.log file. I've just updated today to v1.10.0.

@CommonGuy
Copy link
Contributor

So far, I wasn't able to reproduce this... Do you have any special configuration on your machine that you know of?

Are the gRPC servers which you are calling hosted locally or on a different machine?

@alteredego
Copy link

I have docker+wsl2 installed locally and I have multiple network interfaces. I haven't seen any kind of local connection delays outside of Kreya though?

I'm also not seeing anything in the Trace tab for both failed or successful queries?

@CommonGuy CommonGuy added status:waiting-for-release Implemented, waiting for next stable release and removed status:needs-info To investigate this, more information is needed labels Mar 22, 2023
@CommonGuy
Copy link
Contributor

We just released Kreya 1.10.1, which should fix the delayed response time.

If you still do not see traces in the Trace tab, please open a new separate issue so we can investigate that (couldn't reproduce it yet).

@CommonGuy CommonGuy removed the status:waiting-for-release Implemented, waiting for next stable release label Mar 23, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

3 participants