cancel
Showing results for 
Search instead for 
Did you mean: 

Alfresco is very slow objectList.hasNext() CMIS

elcamino
Confirmed Champ
Confirmed Champ

Hello

Im working on a simple file explorer. User simply clicks on a folder & a folder list is displayed. There are over 200 sub folders inside a my test folder. But it is taking forever.

I measured the performance of the code & found out that that there are 2 major time delays, 5 seconds & 8 seconds. As result fetching 200 filenames takes 13 seconds. You can not really expect the user to wait 13 seconds each time he tried to navigate to a new folder.

Is there a solution to this problem?

Log file & the code are attached below.

First time delay happens at objectList.hasNext() line

2018-11-03  14:35:31.341    9608    --- :   4852.2536ms objectList.hasNext()

Second delay happens after first 100 files are fetched

note that I set operationalcontext.setMaxItemsPerPage(100000);

2018-11-03  14:35:26.462    9608    --- :   0.0937ms    getCmisSession()    
2018-11-03  14:35:26.462    9608    --- :   0.0392ms    createOperationContext()    
2018-11-03  14:35:26.487    9608    --- :   24.6645ms   getObjectByPath()    
2018-11-03  14:35:26.488    9608    --- :   0.0534ms    folder.getChildren().iterator()
...
2018-11-03  14:35:31.347    9608    --- :   0.0025ms    NodeNr.99   CMIS_FOLDER
2018-11-03  14:35:31.348    9608    --- :   0.0024ms    NodeNr.100  CMIS_FOLDER
2018-11-03  14:35:39.051    9608    --- :   0.0065ms    NodeNr.101  CMIS_FOLDER
2018-11-03  14:35:39.051    9608    --- :   0.0029ms    NodeNr.102  CMIS_FOLDER
...
2018-11-03  14:35:39.237    9608    --- :   12774.8885ms    Total method execution Time!
4 REPLIES 4

afaust
Legendary Innovator
Legendary Innovator

Without knowing what Alfresco version you are using, what variant of CMIS transport you are using, and what your Alfresco server configuration / infrastructure looks like, it is hard to give you a complete answer.

From what your output looks like it should be clear what happens at the first call of hasNext(): the CMIS client API is actually performing the call to getChildren(), i.e. is retrieving the results only then. It is likely that at the 100th element, it is doing something similar, i.e. load the next page of results. Although you have created a minimal operation context, you are not using it in the getChildren() call, so your reduced set of data to be loaded and number of elements per page to load are not taken into account at all.

Windows 10, 64 bit

Alfresco Community (Build: 201707)
===============================

Contains:
    - Alfresco Platform:    5.2.g
    - Alfresco Share:        5.2.f

   - Alfresco-opencmis-extension v.1.1

I have taken your advise & added context to getChildren() & reduced the paginator to 500. Now with 200 items second slowdown is not happening. But it is still slow. I made another test by fetching 2 items. Hire is the code & test result. What is the deal with the objectList.next() ?

Folder folder = (Folder) cmisSession.getObjectByPath(path, minimalOperationContext);
Iterator<CmisObject> objectList = folder.getChildren(minimalOperationContext).iterator();
while (true) {
CmisObject object = objectList.next();
// print log
if (object == null) { break; }
}
2018-11-04    13:47:42.219    ---        0.0962ms        getCmisSession()    
2018-11-04    13:47:42.219    ---        0.03ms          createOperationContext()    
2018-11-04    13:47:42.262    ---        42.8426ms       getObjectByPath()    
2018-11-04    13:47:42.262    ---        0.0354ms        folder.getChildren(minOpContext).iterator()    
2018-11-04    13:47:45.782    ---        3519.9573ms     objectList.next()    
2018-11-04    13:47:45.782    ---        0.0073ms        NodeNr.1            CMIS_DOCUMENT
2018-11-04    13:47:45.782    ---        0.0016ms        objectList.next()    
2018-11-04    13:47:45.782    ---        0.0028ms        NodeNr.2            CMIS_DOCUMENT
2018-11-04    13:47:45.866    ---        84.0332ms       objectList.next()    
2018-11-04    13:47:45.866    ---        3647.5247ms     Total method execution Time!

afaust
Legendary Innovator
Legendary Innovator

Ok, so now that you have eliminated the inefficiency caused by the operation context, it is time to actually check / consider the DB. In a correctly set up (and optimised) system, this call should typically not take longer than a second. So, please check / monitor the following:

  • Is this the first time the system is accessed after a restart? I.e. are you restarting your system every time when taking the measurements or has the data already been accessed at least once before? (If already accessed once before, performance should be way below that 1s mark)
  • Are statistics regularly updated / vacuum processes performed on the database?
  • Did / can you check the performance of low-level DB queries using p6spy?

elcamino
Confirmed Champ
Confirmed Champ

After further investigation & testing on different machines with Alfresco installation located in different locations, it turned out that all other machines had decent speed. Turned out the clients machine I was working (no direct access) with had its HDD full. (Logs filled the drive I was told.)

Anyway problem is resolved, thank you for being helpful.