Recursive Permission Changes results in Error communicating with server

We tried to make OpenKM as intuitive as possible, but an advice is always welcome.
Forum rules
Please, before asking something see the documentation wiki or use the search feature of the forum. And remember we don't have a crystal ball or mental readers, so if you post about an issue tell us which OpenKM are you using and also the browser and operating system version. For more info read How to Report Bugs Effectively.
Post Reply
cgeek
Fresh Boarder
Fresh Boarder
Posts: 2
Joined: Mon Feb 13, 2017 11:42 am

Recursive Permission Changes results in Error communicating with server

Post by cgeek » Mon Feb 13, 2017 12:16 pm

Hi,

I've got OpenKM 6.3.0 installed on an AWS Instance running on Ubuntu 14.04.5 LTS. There is approximately 200GB of data stored in the system. I've tested and confirmed the issue in Chrome (Mac OS Sierra) and Firefox (Windows 10 64 bit).

When I attempt to do a recursive permission change on a folder with a large number of files and subdirectories inside it, the web interface seems to time out while the process on the server continues to run to completion and successfully changes the permissions. I've tested it a number of times and at approximately the five minute mark I get a pop up with one of the messages below (the first if adding permissions and the second if removing them).

Code: Select all

Error communicating with server (AddUser)

Code: Select all

Error communicating with server (RevokeUser)
I've monitored the logs and system resource usage while the process is running and found no related errors. The process seems to complete successfully (see below).

Code: Select all

2017-02-13 21:44:50,329 [ajp-bio-127.0.0.1-8009-exec-2293] INFO  com.openkm.dao.NodeBaseDAO- grantUserPermissions.Time: 00:10:59.851
I've already changed the system.execution.timeout property to 20 (well beyond the time used by the task at hand) with no effect.

The only errors in the log seem to be related to OCR or text extraction (see below) so I'm fairly sure those aren't related.

Code: Select all

2017-02-13 21:40:00,096 [Thread-10188] INFO  com.openkm.extractor.TextExtractorWorker- processSerial.Working on {docUuid=REDACTED, docPath=/okm:root/REDACTED.pdf, docVerUuid=REDACTED, date=Thu Jul 03 05:23:29 EST 2014}
2017-02-13 21:40:01,510 [Thread-10188] WARN  org.hibernate.util.JDBCExceptionReporter- SQL Error: 1366, SQLState: HY000
2017-02-13 21:40:01,510 [Thread-10188] ERROR org.hibernate.util.JDBCExceptionReporter- Incorrect string value: '\xEF\x81\xA00.5...' for column 'NDC_TEXT' at row 1
2017-02-13 21:40:01,512 [Thread-10188] WARN  com.openkm.extractor.TextExtractorWorker- could not update: [com.openkm.dao.bean.NodeDocument#001a0047-f0d7-45a4-a23d-ac3d2b180e30]
com.openkm.core.DatabaseException: could not update: [com.openkm.dao.bean.NodeDocument#REDACTED]
	at com.openkm.dao.NodeDocumentDAO.textExtractorHelper(NodeDocumentDAO.java:1384)
	at com.openkm.extractor.TextExtractorWorker.processSerial(TextExtractorWorker.java:164)
	at com.openkm.extractor.TextExtractorWorker.processQueue(TextExtractorWorker.java:149)
	at com.openkm.extractor.TextExtractorWorker.run(TextExtractorWorker.java:100)
	at sun.reflect.GeneratedMethodAccessor197.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at bsh.Reflect.invokeMethod(Reflect.java:134)
	at bsh.Reflect.invokeObjectMethod(Reflect.java:80)
	at bsh.BSHPrimarySuffix.doName(BSHPrimarySuffix.java:176)
	at bsh.BSHPrimarySuffix.doSuffix(BSHPrimarySuffix.java:120)
	at bsh.BSHPrimaryExpression.eval(BSHPrimaryExpression.java:80)
	at bsh.BSHPrimaryExpression.eval(BSHPrimaryExpression.java:47)
	at bsh.Interpreter.eval(Interpreter.java:645)
	at bsh.Interpreter.eval(Interpreter.java:739)
	at bsh.Interpreter.eval(Interpreter.java:728)
	at com.openkm.util.ExecutionUtils.runScript(ExecutionUtils.java:112)
	at com.openkm.core.Cron$RunnerBsh.run(Cron.java:103)
	at java.lang.Thread.run(Thread.java:662)
Caused by: org.hibernate.exception.GenericJDBCException: could not update: [com.openkm.dao.bean.NodeDocument#REDACTED]
	at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:140)
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:128)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
	at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2613)
	at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2495)
	at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2822)
	at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:113)
	at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:273)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:265)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:185)
	at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
	at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51)
	at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1216)
	at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:383)
	at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:133)
	at com.openkm.dao.HibernateUtil.commit(HibernateUtil.java:299)
	at com.openkm.dao.NodeDocumentDAO.textExtractorHelper(NodeDocumentDAO.java:1379)
	... 18 more
Caused by: java.sql.SQLException: Incorrect string value: '\xEF\x81\xA00.5...' for column 'NDC_TEXT' at row 1
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1075)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3562)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3494)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1960)
	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2114)
	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2696)
	at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2105)
	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2398)
	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2316)
	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2301)
	at org.apache.tomcat.dbcp.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
	at org.apache.tomcat.dbcp.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
	at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2595)
	... 31 more
Does anyone have any insight into this issue? I've found numerous accounts of similar error messages but for different methods and with different symptoms so they're not much help.

Any assistance you can offer would be much appreciated.

Cheers,
Jack

jllort
Moderator
Moderator
Posts: 9380
Joined: Fri Dec 21, 2007 11:23 am
Location: Sineu - ( Illes Balears ) - Spain
Contact:

Re: Recursive Permission Changes results in Error communicating with server

Post by jllort » Tue Feb 14, 2017 3:04 pm

How many nodes are you changing, more or less ? The problem in community version is that the change in all the cases it does into a single database commit, when you have a lot of nodes affected is a problem. Probably the error you getting from the UI has not direct relation with this issue. You are applying the change from root node ? give us some idea about what are you doing.

cgeek
Fresh Boarder
Fresh Boarder
Posts: 2
Joined: Mon Feb 13, 2017 11:42 am

Re: Recursive Permission Changes results in Error communicating with server

Post by cgeek » Thu Feb 16, 2017 12:56 am

jllort wrote:How many nodes are you changing, more or less ? The problem in community version is that the change in all the cases it does into a single database commit, when you have a lot of nodes affected is a problem. Probably the error you getting from the UI has not direct relation with this issue. You are applying the change from root node ? give us some idea about what are you doing.
Hi jllort,

Thanks for your help.

There are many thousands of folders and many thousands more files in this OpenKM installation. I'm not trying to do a recursive permissions change at the root, but rather on subfolder. I estimate this subfolder has 1-2 thousand folders with at least double the number of files. I haven't found a way to count down through subfolders though so it is only an estimate.

My investigation indicates that the permissions change does finish successfully it's just the that the web interface times out at about five minutes, is that correct?

Cheers,
Jack

jllort
Moderator
Moderator
Posts: 9380
Joined: Fri Dec 21, 2007 11:23 am
Location: Sineu - ( Illes Balears ) - Spain
Contact:

Re: Recursive Permission Changes results in Error communicating with server

Post by jllort » Fri Feb 17, 2017 11:27 am

Is correct, because the UI has called and RPC ( remote process call ) to a servlet what started making changes, and you are getting a timeout of this RPC call what is still binding looking for the servlet finishes. That's why in professional version we introduced the background process while changing more than 100 nodes, to prevent this kind of issue. In future we will propagate this change to community version.

Post Reply

Who is online

Users browsing this forum: Google [Bot] and 1 guest