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-07AA990EDBBD?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-07AA990EDBBD?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-07AA990EDBBD?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:f...@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:f...@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=&includeAllo
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
