NPE creating index entry #5907
Comments
|
@zerovian thank you very much we will on this at Monday. |
|
@zerovian if I provide you patch with special logging is it possible for you to apply it to check root cause of this issue ? This issue supercritical for us so once you send us report we will release hotfix release in couple of days. I will really appreciate your help. |
|
Well I have found reason of your issue, started to fix. |
|
Well sorry, idea was wrong. Still about original question "if I provide you patch with special logging is it possible for you to apply it to check root cause of this issue ?" |
|
No problem. I can replace a .jar as needed. Some caveats though. I'm stuck on 2.1.11 due to 5831, so patch would need to be against 2.1.11. |
|
I see , sure I will fix your other issue and then will provide patch. |
|
One more suggestion could you run your code with following settings on latest version. Probably it iwll help |
|
Could you try this distribution https://drive.google.com/file/d/0B2oZq2xVp841WjVfRHBOV0hKenM/view?usp=sharing |
|
It is 2.1.11 with logger to understand cause of NPE |
|
I'll try with these and see if it fixes the performance issue (5831). If that works, then I'll grab next nightly against 2.1.15 and run our tests with that. It will take a few days to get back to you. |
|
ok. i'll try with that build |
|
thank you very much |
|
This finally triggered yesterday evening. Normally we run with disk cache at 384. It takes longer to trigger in that case, but it eventually always happens. In this case we reduced it to 128. storage.diskCache.bufferSize=128 AdminServer>Apr 05, 2016 5:06:56 PM com.orientechnologies.common.log.OLogManager com.progress.isq.ipqos.activity.MultiActivityServiceAdapter.deleteRuleAndTrendHi Apr 06, 2016 7:32:12 PM com.orientechnologies.common.log.OLogManager log |
|
orientdb memory usage keeps creeping up. There are 2 embedded databases. One is rarely touched, the other is in constant use by ~20 different threads, usually creating new records using db.save(). Database connections are pooled using OPartitionedDatabasePool. In all cases pooled connections are fetched and released before each operation. We never run out of connections from the pool, so I know i'm not leaking pooled connections. A side question here is why is orientdb complaining about high memory usage? It runs fine for a few days days, then starts failing, then we start getting record not found exceptions when we try to delete records. ( have more stack traces, but the one above usually occurs first). jconsole shows "UsedMemoryInMB" from O2QCacheMXBean at 92 almost constantly. I can provide heap dump if needed. System is still running. Using jconsole it shows a memory leak in loaded classes that goes up constantly until the error occurs, and then stops. I'm trying to track down what these classes are that are leaking. I'll get back to you today. |
|
Thank you very much, I will start fix it from Monday. |
|
@zerovian About memory consumption I suppose that is memory leak related to operations on ByteBuffers and channels, we will try to fix at Tuesday. |
|
@zerovian sorry could you provide more information ? I will add new build there I need to check one more thing. And may be one more after that :-) or not depends on what we get. |
|
What info do you need? Given it is a leak of "loaded classes" according to jconsole. I'm running your kit and jconsole and have turned on -verbose:classes in java. But I don't seem to find what is leaking. Let me know if you need me to test a new build. |
|
Follow up to earlier comments. Ignore the jconsole graph above. It seems that the red line actually tracks "total loaded" classes, but not unloaded classes. It only goes up. The blue line is correct, so no memory leak in the class definitions. Java debug information is showing the proxy classes generated by javassist being unloaded by the JVM. |
|
I think I will provide you new distribution soon. To double check on my side that jar is correct too. |
|
Hi , new distribution https://drive.google.com/file/d/0B2oZq2xVp841WjVfRHBOV0hKenM/view?usp=sharing just in case. |
|
This is exception(s) I got last night. Exception at Tue Apr 12 04:05:43 EDT 2016: com.progress.isq.ipqos.WorkErrorException |
|
I'll try with newer build. |
|
Latest stack using build you posted yesterday. Message (excp): Error during removal of entry by key |
|
Hi @zerovian I have put your stack trace as a gist to do not clutter issue with long stack traces. |
|
Hi @zerovian , I found reason for that issue, fixing it now. |
|
Did you try settings with last release of 2.1.x which I suggested to you ? Unfortunately I may fix this issue only in 2.1.x branch. |
|
Well actually fix is super simple, I may put it in 2.1.11 distr for you, but in general it will be available only in 2.1.16 |
|
I haven't gotten a chance to test with the suggested switches with a newer release. I'll assume they work and having a fix in 2.1.16 would be fine. I'll test with 2.1.16 build as soon as I get a chance. Hopefully soon. I'll note in 5831 if they address the performance issue or not. Thanks for making this a priority. |
|
Fixed, @zerovian the same fix in 2.1.11 distribution https://drive.google.com/file/d/0B2oZq2xVp841WjVfRHBOV0hKenM/view?usp=sharing . About your second issue. When you confirm that this issue is fixed you should export database to JSON and then import back and second issue will be gone too. |
|
great. I'll test the 2.1.11 build and let you know as soon as I can (might be a couple of days). |
|
Update on this. So after 2 days of running with the patched version, there are no errors on index insert or record delete. Looks good so far. |
orientdb 2.1.11
Unfortunately I don't have a reproducable for this. It takes 2-3 days for it to occur and it is somewhat random, but it eventually always occurs.
I suspect there might be another exception underneath this (possibly an OOM), but since the releaseExclusiveLock() is in the finally block and it is throwing NPE, the original exception is lost.
Looking at OCacheEntry I don't see why the dataPointer would be going null between the call to acquireExclusiveLock and releaseExclusiveLock.
com.progress.isq.ipqos.WorkErrorException: Error during insertion of key in index
at com.progress.isq.ipqos.resources.plugins.openedge.work.WorkRunnable.performPolling(WorkRunnable.java:64)
at com.progress.isq.ipqos.resources.plugins.openedge.work.DatabaseInstWork.doWork(DatabaseInstWork.java:85)
at com.progress.isq.ipqos.resources.plugins.database.DatabaseInstResource.doWork(DatabaseInstResource.java:526)
at com.progress.isq.ipqos.ScheduledWorkShell.run(ScheduledWorkShell.java:86)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: com.orientechnologies.orient.core.index.OIndexException: Error during insertion of key in index
at com.orientechnologies.orient.core.index.OIndexMultiValues.put(OIndexMultiValues.java:162)
at com.orientechnologies.orient.core.index.OIndexMultiValues.put(OIndexMultiValues.java:52)
at com.orientechnologies.orient.core.tx.OTransactionNoTx.addIndexEntry(OTransactionNoTx.java:256)
at com.orientechnologies.orient.core.index.OIndexTxAware.put(OIndexTxAware.java:97)
at com.orientechnologies.orient.core.index.OIndexTxAware.put(OIndexTxAware.java:41)
at com.orientechnologies.orient.core.index.OClassIndexManager.addIndexEntry(OClassIndexManager.java:530)
at com.orientechnologies.orient.core.index.OClassIndexManager.addIndexesEntries(OClassIndexManager.java:517)
at com.orientechnologies.orient.core.index.OClassIndexManager.onRecordAfterCreate(OClassIndexManager.java:428)
at com.orientechnologies.orient.core.hook.ODocumentHookAbstract.onTrigger(ODocumentHookAbstract.java:229)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.callbackHooks(ODatabaseDocumentTx.java:1037)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.callbackHookSuccess(ODatabaseDocumentTx.java:3038)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.executeSaveRecord(ODatabaseDocumentTx.java:1987)
at com.orientechnologies.orient.core.tx.OTransactionNoTx.saveRecord(OTransactionNoTx.java:160)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.save(ODatabaseDocumentTx.java:2532)
at com.orientechnologies.orient.object.db.OObjectDatabaseTx.save(OObjectDatabaseTx.java:470)
at com.orientechnologies.orient.object.db.OObjectDatabaseTx.save(OObjectDatabaseTx.java:405)
at com.progress.isq.ipqos.activity.ActivityDataAccess.save(ActivityDataAccess.java:60)
at com.progress.isq.ipqos.activity.ActivityService.create(ActivityService.java:73)
at com.progress.isq.ipqos.activity.ActivityService.create(ActivityService.java:60)
at com.progress.isq.ipqos.activity.ServiceAdapter.storeActivities(ServiceAdapter.java:63)
at com.progress.isq.ipqos.activity.MultiActivityServiceAdapter.processData(MultiActivityServiceAdapter.java:262)
at com.progress.isq.ipqos.activity.MultiActivityServiceAdapter.processResponse(MultiActivityServiceAdapter.java:219)
at com.progress.isq.ipqos.activity.MultiActivityServiceAdapter.processActivities(MultiActivityServiceAdapter.java:201)
at com.progress.isq.ipqos.resources.plugins.database.DatabaseActivityProcessor.processActivities(DatabaseActivityProcessor.java:431)
at com.progress.isq.ipqos.activity.MultiActivityServiceAdapter.processActivities(MultiActivityServiceAdapter.java:181)
at com.progress.isq.ipqos.activity.MultiActivityServiceAdapter.fetchAndStoreActivities(MultiActivityServiceAdapter.java:111)
at com.progress.isq.ipqos.resources.plugins.openedge.work.WorkRunnable.performPolling(WorkRunnable.java:60)
... 6 more
Caused by: java.lang.NullPointerException
at com.orientechnologies.orient.core.storage.cache.OCacheEntry.releaseExclusiveLock(OCacheEntry.java:81)
at com.orientechnologies.orient.core.storage.impl.local.paginated.atomicoperations.OAtomicOperation.commitChanges(OAtomicOperation.java:394)
at com.orientechnologies.orient.core.storage.impl.local.paginated.atomicoperations.OAtomicOperationsManager.endAtomicOperation(OAtomicOperationsManager.java:168)
at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.commitAtomicOperation(OAbstractPaginatedStorage.java:351)
at com.orientechnologies.orient.core.index.OIndexAbstract.commitStorageAtomicOperation(OIndexAbstract.java:928)
at com.orientechnologies.orient.core.index.OIndexMultiValues.put(OIndexMultiValues.java:157)
... 32 more
The text was updated successfully, but these errors were encountered: