Hi,

in your app's request_log (under Stackdriver Logging), do the requests 
reflect the high latency in the field protoPayload.latency? Or is the 
latency issue isolated to Endpoints itself (those are logged to 
request_latency_in_ms 
<https://cloud.google.com/endpoints/docs/frameworks/ref-endpoints-logs> in 
Endpoints 
logs 
<https://cloud.google.com/endpoints/docs/frameworks/monitoring-your-api#logs>)? 
The latter includes the time taken by Endpoints and the backend (your app) 
together.

And what type of scaling is defined in app.yaml? Maybe you are affected by 
one of the known issues. From the Cloud Endpoints documentation 
<https://cloud.google.com/endpoints/docs/known-issues#poor_performance_on_automatic_scaling_instances>
 
for standard environment:

Automatic scaling instances do not support background threads, which are 
> used by the Endpoints Management Framework. The Framework will still 
> function, but with potentially reduced performance.


If you use automatic scaling, maybe you could try if the performance 
improves with basic or manual scaling. I have used Endpoints with automatic 
scaling before and haven't noticed such latency issues as in your case 
(Python standard environment though).

Best regards,
Ani
 
On Monday, June 11, 2018 at 12:45:50 PM UTC+2, Azeem Haider wrote:
>
> I'm using App Engine Standard Environment with Google Cloud Endpoints v2 
> for java.
> Using objectify for DataStore.
>
> I just make a simple call but it takes a lot more time to get the results. 
> There are very little users those are using my Endpoints, It's in the 
> testing phase.
>
> EndPoint Function: 
>
> public User getUser(@Named("userId") Long userId){
>         return ofy().load().key(Key.create(User.class, userId)).now();
>     }
>
>
> It Just a very simple function no authentication call etc. Just Put the 
> userId and get the result. There are only a few users almost 5.
>
> When I call from API Explorer. Same Endpoint function running, again and 
> again. Execute without OAuth
>
> First Call:        ----  time to execute: 8652 ms       ----  May be delay 
> due to start new instance because App Engine shut down instance when there 
> is no traffic
> Second Call:   ----  time to execute: 7625 ms       
> Third Call       ----   time to execute: 4665 ms 
> Fourth Call     -----  time to execute: 2873 ms
>  
> After this rest of all call are between in 4000 ms - 2000 ms  Only few 
> time again it goes around to 7000 ms.
>
>
> But When I call it from Android using Client Library. It takes too much 
> time to get a result even more than API Explorer.
>
>  Activity Code: ( Using AsyncTask )
>
> doInBackground(Long... params){
>                 
>         Zeem.Builder builder = new 
> Zeem.Builder(AndroidHttp.newCompatibleTransport(), new JacksonFactory(), 
> null);
>         Zeem zeem = builder.build();
>
>         zeem.userApi.getUser(5720147234914304).execute(); // 
> 5720147234914304 is userId
>                         
> }
>
>
> First time when I run this is it takes more time I think some kind of SSL.
>
> Here is the Log When I first time Run.
>
>
> D/libc-netbsd: [getaddrinfo]: hostname=my-project-id.appspot.com; 
> servname=(null); cache_mode=(null), netid=0; mark=0
>                [getaddrinfo]: ai_addrlen=0; ai_canonname=(null); 
> ai_flags=4; ai_family=0
> D/NativeCrypto: ssl=0xae85ba00 NativeCrypto_SSL_do_handshake fd=0xaef31480 
> shc=0xaef31484 timeout_millis=20000 client_mode=1 npn=0x0
>                 doing handshake ++
> D/NativeCrypto: ssl=0xae85ba00 info_callback where=0x10 ret=1
>                 ssl=0xae85ba00 handshake start in UNKWN  before/connect 
> initialization
>                 ssl=0xae85ba00 info_callback calling handshakeCompleted
>                 ssl=0xae85ba00 info_callback completed
> D/NativeCrypto: ssl=0xae85ba00 info_callback where=0x1001 ret=1
>                 ssl=0xae85ba00 SSL_connect:UNKWN  before/connect 
> initialization
>                 ssl=0xae85ba00 info_callback ignored
> D/NativeCrypto: ssl=0xae85ba00 info_callback where=0x1001 ret=1
>                 ssl=0xae85ba00 SSL_connect:23WCHA SSLv2/v3 write client 
> hello A
>                 ssl=0xae85ba00 info_callback ignored
> D/NativeCrypto: ssl=0xae85ba00 info_callback where=0x1002 ret=-1
> D/NativeCrypto: ssl=0xae85ba00 SSL_connect:error exit in 23RSHA SSLv2/v3 
> read server hello A
>                 ssl=0xae85ba00 info_callback ignored
>                 doing handshake -- ret=-1
>                 ssl=0xae85ba00 NativeCrypto_SSL_do_handshake ret=-1 
> errno=11 sslError=2 timeout_millis=20000
> D/NativeCrypto: doing handshake ++
>                 ssl=0xae85ba00 info_callback where=0x1001 ret=1
>                 ssl=0xae85ba00 SSL_connect:3RSH_A SSLv3 read server hello A
>                 ssl=0xae85ba00 info_callback ignored
> D/NativeCrypto: ssl=0xae85ba00 info_callback where=0x1002 ret=-1
>                 ssl=0xae85ba00 SSL_connect:error exit in 3RSC_A SSLv3 read 
> server certificate A
>                 ssl=0xae85ba00 info_callback ignored
>                 ssl=0xae85ba00 info_callback where=0x1002 ret=-1
>                 ssl=0xae85ba00 SSL_connect:error exit in 3RSC_A SSLv3 read 
> server certificate A
>                 ssl=0xae85ba00 info_callback ignored
>                 doing handshake -- ret=-1
>                 ssl=0xae85ba00 NativeCrypto_SSL_do_handshake ret=-1 
> errno=11 sslError=2 timeout_millis=20000
> D/NativeCrypto: doing handshake ++
> E/NativeCrypto: ssl=0xae85ba00 cert_verify_callback 
> x509_store_ctx=0xaef312c8 arg=0x0
>                 ssl=0xae85ba00 cert_verify_callback calling 
> verifyCertificateChain authMethod=ECDHE_RSA
> D/NativeCrypto: ssl=0xae85ba00 cert_verify_callback => 1
>                 ssl=0xae85ba00 info_callback where=0x1001 ret=1
> D/NativeCrypto: ssl=0xae85ba00 SSL_connect:3RSC_A SSLv3 read server 
> certificate A
>                 ssl=0xae85ba00 info_callback ignored
> D/NativeCrypto: ssl=0xae85ba00 info_callback where=0x1001 ret=1
>                 ssl=0xae85ba00 SSL_connect:3RSKEA SSLv3 read server key 
> exchange A
>                 ssl=0xae85ba00 info_callback ignored
>                 ssl=0xae85ba00 info_callback where=0x1001 ret=1
>                 ssl=0xae85ba00 SSL_connect:3RSD_A SSLv3 read server done A
>                 ssl=0xae85ba00 info_callback ignored
> D/NativeCrypto: ssl=0xae85ba00 info_callback where=0x1001 ret=1
>                 ssl=0xae85ba00 SSL_connect:3WCKEA SSLv3 write client key 
> exchange A
>                 ssl=0xae85ba00 info_callback ignored
> D/NativeCrypto: ssl=0xae85ba00 info_callback where=0x1001 ret=1
>                 ssl=0xae85ba00 SSL_connect:3WCCSA SSLv3 write change 
> cipher spec A
>                 ssl=0xae85ba00 info_callback ignored
>                 ssl=0xae85ba00 info_callback where=0x1001 ret=1
>                 ssl=0xae85ba00 SSL_connect:3WFINA SSLv3 write finished A
>                 ssl=0xae85ba00 info_callback ignored
>                 ssl=0xae85ba00 info_callback where=0x1001 ret=1
>                 ssl=0xae85ba00 SSL_connect:3FLUSH SSLv3 flush data
>                 ssl=0xae85ba00 info_callback ignored
> D/NativeCrypto: ssl=0xae85ba00 info_callback where=0x1002 ret=-1
>                 ssl=0xae85ba00 SSL_connect:error exit in UNKWN  SSLv3 read 
> server session ticket A
>                 ssl=0xae85ba00 info_callback ignored
> D/NativeCrypto: doing handshake -- ret=-1
>                 ssl=0xae85ba00 NativeCrypto_SSL_do_handshake ret=-1 
> errno=11 sslError=2 timeout_millis=20000
> D/NativeCrypto: doing handshake ++
>                 ssl=0xae85ba00 info_callback where=0x1001 ret=1
>                 ssl=0xae85ba00 SSL_connect:UNKWN  SSLv3 read server 
> session ticket A
>                 ssl=0xae85ba00 info_callback ignored
> D/NativeCrypto: ssl=0xae85ba00 info_callback where=0x1001 ret=1
>                 ssl=0xae85ba00 SSL_connect:3RFINA SSLv3 read finished A
>                 ssl=0xae85ba00 info_callback ignored
>                 ssl=0xae85ba00 info_callback where=0x20 ret=1
>                 ssl=0xae85ba00 handshake done in SSLOK  SSL negotiation 
> finished successfully
>                 ssl=0xae85ba00 info_callback calling handshakeCompleted
>                 ssl=0xae85ba00 info_callback completed
>                 ssl=0xae85ba00 info_callback where=0x1002 ret=1
>                 ssl=0xae85ba00 SSL_connect:ok exit in SSLOK  SSL 
> negotiation finished successfully
>                 ssl=0xae85ba00 info_callback ignored
>                 doing handshake -- ret=1
>                 ssl=0xae85ba00 NativeCrypto_SSL_get_certificate => NULL
> I/System.out: gba_cipher_suite:TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
> I/System.out: [OkHttp] sendRequest>>
> I/System.out: [OkHttp] sendRequest<<
> D/NativeCrypto: ssl=0xae85ba00 sslWrite buf=0xae8ce800 len=230 
> write_timeout_millis=0
> D/NativeCrypto: ssl=0xae85ba00 sslRead buf=0xae8ce800 len=2048,timeo=20000
> D/NativeCrypto: ssl=0xae85ba00 sslRead buf=0xae8ce800 len=2048,timeo=20000
> D/NativeCrypto: ssl=0xae85ba00 sslRead buf=0xae8ce800 len=2048,timeo=20000
>
>
> After this whenever I run it a little bit fast but not fast enough, it 
> takes around 6-7 sec sometimes more and sometimes less, you can say average 
> 5 sec. Which is not good.
>
> D/OpenSSLLib: OpensslErr:Module:13(114:155); 
> file:external/openssl/crypto/asn1/asn1_lib.c 
> ;Line:145;Function:ASN1_get_object
> D/OpenSSLLib: OpensslErr:Module:13(114:155); 
> file:external/openssl/crypto/asn1/asn1_lib.c 
> ;Line:145;Function:ASN1_get_object
> V/ActivityThread: Performing resume of ActivityRecord{36eaf480 
> token=android.os.BinderProxy@13894ab9 
> {com.azeem.socialtest/com.azeem.socialtest.Comment.CommentActivity}}
> D/ActivityThread: ACT-AM_ON_RESUME_CALLED ActivityRecord{36eaf480 
> token=android.os.BinderProxy@13894ab9 
> {com.azeem.socialtest/com.azeem.socialtest.Comment.CommentActivity}}
> V/ActivityThread: Resume ActivityRecord{36eaf480 
> token=android.os.BinderProxy@13894ab9 
> {com.azeem.socialtest/com.azeem.socialtest.Comment.CommentActivity}} 
> started activity: false, hideForNow: false, finished: false
> V/PhoneWindow: DecorView setVisiblity: visibility = 4 ,Parent =null, this 
> =com.android.internal.policy.impl.PhoneWindow$DecorView{1d09a97b I.E..... 
> R.....I. 0,0-0,0}
> D/Surface: Surface::setBuffersDimensions(this=0xb45af700,w=720,h=1184)
> I/System.out: [CDS]rx timeout:20000
> I/System.out: [CDS]rx timeout:20000
>               [OkHttp] sendRequest>>
>               [OkHttp] sendRequest<<
> D/NativeCrypto: ssl=0xae85ba00 sslWrite buf=0xae8d5800 len=289 
> write_timeout_millis=0
> D/NativeCrypto: ssl=0xae85ba00 sslRead buf=0xae8d5800 len=2048,timeo=20000
>
>
> Here is the trace from Cloud Console.
>
> Please let me know how can I make it fast. I seen youtube, snapchat are 
> much faster,  as I know they are also in Google Cloud Platform. And I 
> notice instagram is much much faster
> then these it get result within sec or two. I think Instagram is using 
> Amazon web services. Is Amazon web service is faster then Google cloud 
> Platform ? 
>
> OR
>
> Is there any problem in my code ? or I'm doing something wrong ? Please 
> let me know about these, how can I improve the speed. 
>
> THANKS.
>
>

-- 
You received this message because you are subscribed to the Google Groups 
"Google App Engine" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to google-appengine+unsubscr...@googlegroups.com.
To post to this group, send email to google-appengine@googlegroups.com.
Visit this group at https://groups.google.com/group/google-appengine.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/google-appengine/7454fadd-9c03-415a-8298-08761d32d914%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Reply via email to