chemistry-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Lu, Wentao" <Wentao...@bchydro.com>
Subject RE: Slow when call cmis bridge using pure http call after a few days
Date Fri, 30 Dec 2016 22:56:39 GMT
Hi Florian,

The issue was fixed, it was the DNS issue, it took 10 seconds for reaching the LDAP server
for cmis authentication.

Thanks for help and Happy New Year

Wentao

-----Original Message-----
From: Florian Müller [mailto:fmui@apache.org] 
Sent: 2016, December 23 10:08 AM
To: Lu, Wentao
Cc: dev@chemistry.apache.org
Subject: Re: Slow when call cmis bridge using pure http call after a few days

Hi Wento,

It could be a network issue of some kind.
Is there a pattern? Is it slow when the bridge hasn't been accessed for a while?

There seems to be also an issue with WebLogic's HttpURLConnection.
See:
https://stackoverflow.com/questions/36148606/poor-performance-with-weblogics-httpurlconnection-implementation?rq=1
And:
https://stackoverflow.com/questions/36080108/slow-2-way-ssl-handshake-with-weblogic-net-http-httpsurlconnection

Which OpenCMIS version are you using? You could try switching the HTTP client implementation
on the bridge. Maybe that helps.


- Florian


> Hi Florian,
>
> Here is the debug trace, it looks like the slowness occurs before "Initializing AtomPub
SPI", could that be SSL shake or something else?
>
> CMIS bridge server access log,  9:19:35 - 9:19:47 (12.609 seconds),
> 2016-12-23      09:19:47        12.609  GET     /cmisbridge/atom/myrepository/content/?ID=idd_6ADB4E75-9FBB-4802-9A18-A7D80220D8B5
   200
>
> Debug log
> //no debug logs before this initializing atompub spi
> 2016-12-23 09:19:45,413 DEBUG [[ACTIVE] ExecuteThread: '19' for queue: 
> 'weblogic.kernel.Default (self-tuning)'] 
> [oD4sshOkz84__MiAx3i8UXjkp9Gh72i54art8gJeRVy9dENHqP5r!1954451694!14825
> 13585060] 
> org.apache.chemistry.opencmis.client.bindings.spi.atompub.CmisAtomPubS
> pi
> : Initializing AtomPub SPI...
> .....................................................
> 2016-12-23 09:19:47,034 INFO  [[ACTIVE] ExecuteThread: '19' for queue: 'weblogic.kernel.Default
(self-tuning)'] [oD4sshOkz84__MiAx3i8UXjkp9Gh72i54art8gJeRVy9dENHqP5r!1954451694!1482513585060]
com.bch.filenet.cmis.bridge.MyCmisService: getContentStream ends.
>
>
> Thanks
> Wentao
>
> -----Original Message-----
> From: Florian Müller [mailto:fmui@apache.org]
> Sent: 2016, December 22 1:10 PM
> To: Lu, Wentao
> Cc: dev@chemistry.apache.org
> Subject: Re: Slow when call cmis bridge using pure http call after a 
> few days
>
> Hi Wentao,
>
> we are running a bridge based product for several years now and have not seen anything
like this.
> I'll add more logging and debug code to the bridge. That should give us a better insight.
>
>
> - Florian
>
>
>
>> Hi Florian,
>>
>> I did more testing and I think the slowness is inside the cmis bridge 
>> server and kind of randomly, the second call below take 15.306 end to 
>> end (17:55:06 - 17:55:21), but only 5 seconds in FileNet CMIS
>> (17:55:16 - 17:55:21), I am wondering if there are any "lock and/or 
>> waiting" in the cmis bridge.
>>
>> CMIS bridge access log:
>> 2016-12-21      17:54:09        3.008   GET
>> /cmisbridge/atom/myrepository/content/?ID=idd_8016FF58-35FF-4147-81A4-07AA990EDBBD
>>    200
>> 2016-12-21      17:55:21        15.306  GET
>> /cmisbridge/atom/myrepository/content/?ID=idd_8016FF58-35FF-4147-81A4-07AA990EDBBD
>>    200
>> 2016-12-21      17:55:23        1.141   GET
>> /cmisbridge/atom/myrepository/content/?ID=idd_8016FF58-35FF-4147-81A4-07AA990EDBBD
>>    200
>>
>> FN CMIS access log (I enabled "time-taken" log on FileNet CMIS server):
>> 2016-12-21      17:54:06        0.017   GET
>> /fncmis/resources/Service?repositoryId=myrepository  200
>> 2016-12-21      17:54:07        0.105   GET
>> /fncmis/resources/myrepository/Content/idd_8016FF58-35FF-4147-81A4-07
>> A A990EDBBD?filter=&includeAllowableActions=&includeACL=
>> 200
>> 2016-12-21      17:54:09        2.725   GET
>> /fncmis/resources/myrepository/ContentStream/idd_8016FF58-35FF-4147-81A4-07AA990EDBBD/0/Report+E901.pdf
>>      200
>> 2016-12-21      17:55:16        0.021   GET
>> /fncmis/resources/Service?repositoryId=myrepository  200
>> 2016-12-21      17:55:16        0.104   GET
>> /fncmis/resources/myrepository/Content/idd_8016FF58-35FF-4147-81A4-07
>> A A990EDBBD?filter=&includeAllowableActions=&includeACL=
>> 200
>> 2016-12-21      17:55:21        4.693   GET
>> /fncmis/resources/myrepository/ContentStream/idd_8016FF58-35FF-4147-81A4-07AA990EDBBD/0/Report+E901.pdf
>>      200
>> 2016-12-21      17:55:22        0.017   GET
>> /fncmis/resources/Service?repositoryId=myrepository  200
>> 2016-12-21      17:55:22        0.089   GET
>> /fncmis/resources/myrepository/Content/idd_8016FF58-35FF-4147-81A4-07
>> A A990EDBBD?filter=&includeAllowableActions=&includeACL=
>> 200
>> 2016-12-21      17:55:23        0.946   GET
>> /fncmis/resources/myrepository/ContentStream/idd_8016FF58-35FF-4147-81A4-07AA990EDBBD/0/Report+E901.pdf
>>      200
>>
>> Thanks
>> Wentao
>>
>>
>> -----Original Message-----
>> From: Florian Müller [mailto:fmui@apache.org]
>> Sent: 2016, December 21 12:14 PM
>> To: Lu, Wentao; dev@chemistry.apache.org
>> Subject: Re: Slow when call cmis bridge using pure http call after a 
>> few days
>>
>>
>> Hi Wentao,
>>
>> Because your clients don't manage cookies, the LRU Cache 
>> implementation is a better fit 
>> (org.apache.chemistry.opencmis.bridge.lrucache.LruCacheBridgeServiceFactory).
>> With the HttpSessionBridgeServiceFactory and without cookies you are 
>> accumulating a lot of useless session objects on the bridge. Please 
>> check if you see the same symptoms with the LRU cache.
>>
>> If you download documents frequently, please remove this line:
>> httpConnGetContent.disconnect();
>> Without it sockets to the bridge can be reused and SSL handshakes can 
>> be avoided.
>>
>> Also make sure that you always read the full content, even if an 
>> error occurs somewhere. Otherwise the socket can get stuck.
>>
>>
>> - Florian
>>
>>> Hi Florian,
>>>
>>> Thanks for your help again.
>>>
>>> At the moment, I am not 100% sure if the slowness is occurred on 
>>> FileNet CMIS server or on the CMIS bridge server, as if I restart 
>>> the bridge server, it back to 3 seconds.
>>>
>>> Does it stay slow or do you only see spikes?   Wentao:  It stay slow 
>>> until I restart bridge server.
>>>
>>> Are you using HTTP sessions and cookies for the cache? If so, does 
>>> the client always send the correct (current) cookies?
>>>
>>> Wentao:  we extended the "HttpSessionCmisService" from the bridge 
>>> library, we did not set cookie in client code, snip of the client 
>>> code as below:
>>>
>>>         String cmisGetContentPrefix = 
>>> "https://myserver/cmisbridge/atom/myrepository/content/?ID=";
>>>         URL urlGetContent = new URL(cmisGetContentPrefix+idd);
>>>         HttpURLConnection httpConnGetContent = 
>>> (HttpURLConnection)urlGetContent.openConnection();
>>>         httpConnGetContent.setRequestProperty("Authorization","Basic
>>> "+ authStr);
>>>         InputStream inputStream = httpConnGetContent.getInputStream();
>>>         response.setHeader("Content-Type",
>>> httpConnGetContent.getContentType());
>>>         response.setHeader("Content-Disposition",
>>> httpConnGetContent.getHeaderField("Content-Disposition"));
>>>         int bytesRead = -1;
>>>         byte [] buffer = new byte[64000];
>>>         while ((bytesRead = inputStream.read(buffer)) != -1){
>>>             response.getOutputStream().write(buffer,0,bytesRead);
>>>         }
>>>         inputStream.close();
>>>         httpConnGetContent.disconnect();
>>>
>>> Thanks
>>> Wentao
>>>
>>> -----Original Message-----
>>> From: Florian Müller [mailto:fmui@apache.org]
>>> Sent: 2016, December 21 9:00 AM
>>> To: dev@chemistry.apache.org
>>> Cc: Lu, Wentao
>>> Subject: Re: Slow when call cmis bridge using pure http call after a 
>>> few days
>>>
>>> Hi Wentao,
>>>
>>> The log excerpt shows that the getRepositoryInfo call takes most of 
>>> the time. Why it takes that long should be answered by a FileNet 
>>> expert (Jay?).
>>>
>>> The log excerpt also shows that you are creating a new OpenCMIS 
>>> session to your FileNet server on the bridge. If you can cache the 
>>> OpenCMIS session object on the bridge, you avoid the 
>>> getRepositoryInfo call and save a lot of time.
>>> Probably you already do that but your cache evicts the session 
>>> object at some point. The next request has to set up a new session 
>>> that then calls getRepositoryInfo again, which takes time. That 
>>> would explain why it suddenly gets slower.
>>>
>>> Does it stay slow or do you only see spikes?
>>> Are you using HTTP sessions and cookies for the cache? If so, does 
>>> the client always send the correct (current) cookies?
>>>
>>>
>>> Btw. Use the Browser Binding, if you can. It's faster.
>>>
>>>
>>> - Florian
>>>
>>>
>>>
>>>> Hi,
>>>>
>>>> We have a custom code which can't use OpenCMIS Client library, we 
>>>> asked them to use pure http call by assembly the getContentStream 
>>>> url with http basic header. The access is via cmis bridge (version
>>>> 0.10) to backend FileNet CMIS.
>>>>
>>>> The call was fast (less than 3 second) at the beginning, but after 
>>>> a few days, it become slow, the response time was 20 seconds until 
>>>> we restart cmis bridge instance, access log as below
>>>>
>>>> CMIS bridge accesslog
>>>> 2016-12-14      16:32:02        20.551  GET
>>>> /cmisbridge/atom/myrepository/content/?ID=idd_8413BC70-2875-4517-A709-84D0D7AF9803
>>>>    200
>>>>
>>>> FileNet CMIS log
>>>> 127.0.0.1 - myview [14/Dec/2016:16:31:51 -0800] "GET 
>>>> /fncmis/resources/Service?repositoryId=myrepository HTTP/1.1" 200
>>>> 20978
>>>> 127.0.0.1 - myview [14/Dec/2016:16:32:01 -0800] "GET 
>>>> /fncmis/resources/ myrepository 
>>>> /Content/idd_8413BC70-2875-4517-A709-84D0D7AF9803?filter=&includeAl
>>>> l
>>>> o
>>>> wableActions=&includeACL=H
>>>> TTP/1.1" 200 30753
>>>> 127.0.0.1 - myview [14/Dec/2016:16:32:01 -0800] "GET
>>>> /fncmis/resources/myrepository/ContentStream/idd_8413BC70-2875-4517
>>>> -
>>>> A
>>>> 709-84D0D7AF9803/0/Report+E707.pdf
>>>> HTTP/1.1" 200 993683
>>>>
>>>> I am wondering if there were any resources not been released 
>>>> properly when we use http call directly, any ideas where the 
>>>> slowness may come from? The other client apps using opencmis java 
>>>> or .net library do not have this issue.
>>>>
>>>> Thanks
>>>> Wentao
>>>> ________________________________
>>>> This email and its attachments are intended solely for the personal 
>>>> use of the individual or entity named above. Any use of this 
>>>> communication by an unintended recipient is strictly prohibited. If 
>>>> you have received this email in error, any publication, use, 
>>>> reproduction, disclosure or dissemination of its contents is 
>>>> strictly prohibited. Please immediately delete this message and its 
>>>> attachments from your computer and servers. We would also 
>>>> appreciate if you would contact us by a collect call or return 
>>>> email to notify us of this error. Thank you for your cooperation.
>>>> -BCHydroDisclaimerID5.2.8.1541


Mime
View raw message