(Customer 39) OAutomaticBackup failure blocks usage of DB, plugins, ODB Clients using binary protocol #2373

lloydchang · 2014-05-21T18:48:25Z

Steps to reproduce; ODB 1.7-SNAPSHOT

Change orientdb-server-config.xml OAutomaticBackup from false to true

   <!-- AUTOMATIC BACKUP, TO TURN ON SET THE 'ENABLED' PARAMETER TO 'true' -->
    <handler class="com.orientechnologies.orient.server.handler.OAutomaticBackup">
        <parameters>
            <parameter name="enabled" value="false" />
            <parameter name="firstTime" value="12:00:00" />
            <parameter name="delay" value="1d" />
            <parameter name="target.directory" value="OAutomaticBackup" />
            <parameter name="target.fileName" value="${DBNAME}-${DATE:yyyyMMddHHmmss}.json" /><!-- ${DBNAME} AND ${DATE:} VARIABLES ARE SUPPORTED -->
            <parameter name="db.include" value="pharos" /><!-- DEFAULT: NO ONE, THAT MEANS ALL DATABASES. USE COMMA TO SEPARATE MULTIPLE DATABASE NAMES -->
            <parameter name="db.exclude" value="" /><!-- USE COMMA TO SEPARATE MULTIPLE DATABASE NAMES -->
        </parameters>
    </handler>

so above false becomes true, e.g.

          <parameter name="enabled" value=“true" />

Then start server…
When server starts, OAutomaticBackup failure blocks usage of DB, plugins, ODB Clients using binary protocol:

2014-05-12 18:05:53:493 WARN segment file 'database.ocf' was not closed correctly last time [OSingleFileSegment]com.orientechnologies.common.exception.OException: File flush was abnormally terminated
at com.orientechnologies.orient.core.index.hashindex.local.cache.OWOWCache.flush(OWOWCache.java:593)
at com.orientechnologies.orient.core.index.hashindex.local.cache.OReadWriteDiskCache.flushFile(OReadWriteDiskCache.java:228)
at com.orientechnologies.orient.core.storage.impl.local.paginated.OClusterPositionMap.flush(OClusterPositionMap.java:90)
at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedCluster.synch(OPaginatedCluster.java:1447)
at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedCluster.close(OPaginatedCluster.java:219)
at com.orientechnologies.orient.core.storage.impl.local.paginated.OLocalPaginatedStorage.doClose(OLocalPaginatedStorage.java:1889)
at com.orientechnologies.orient.core.storage.impl.local.paginated.OLocalPaginatedStorage.close(OLocalPaginatedStorage.java:286)
at com.orientechnologies.orient.core.storage.impl.local.paginated.OLocalPaginatedStorage.open(OLocalPaginatedStorage.java:204)
at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.open(ODatabaseRaw.java:101)
at com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.open(ODatabaseWrapperAbstract.java:49)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.open(ODatabaseRecordAbstract.java:268)
at com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.open(ODatabaseWrapperAbstract.java:49)
[...]
at com.orientechnologies.orient.server.OServer.registerPlugins(OServer.java:718)
at com.orientechnologies.orient.server.OServer.activate(OServer.java:239)
at com.orientechnologies.orient.server.OServerMain.main(OServerMain.java:32)
Caused by: java.util.concurrent.ExecutionException: java.lang.NullPointerException
at java.util.concurrent.FutureTask.report(FutureTask.java:122)
at java.util.concurrent.FutureTask.get(FutureTask.java:188)
at com.orientechnologies.orient.core.index.hashindex.local.cache.OWOWCache.flush(OWOWCache.java:588)
... 18 more
Caused by: java.lang.NullPointerException
at com.orientechnologies.orient.core.index.hashindex.local.cache.OWOWCache$FileFlushTask.call(OWOWCache.java:373)
at com.orientechnologies.orient.core.index.hashindex.local.cache.OWOWCache$FileFlushTask.call(OWOWCache.java:322)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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:745)
[...]
[OAutomaticBackup] - Error on exporting database 'plocal:/opt/orient/databases/pharos' to file: OAutomaticBackup/pharos-20140512180549.json
Error on creation of shared resource
-> com.orientechnologies.common.concur.resource.OSharedContainerImpl.getResource(OSharedContainerImpl.java:55)
-> com.orientechnologies.orient.core.metadata.OMetadataDefault.init(OMetadataDefault.java:110)
-> com.orientechnologies.orient.core.metadata.OMetadataDefault.load(OMetadataDefault.java:68)
-> com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.open(ODatabaseRecordAbstract.java:291)
-> com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.open(ODatabaseWrapperAbstract.java:49)
-> com.orientechnologies.orient.server.handler.OAutomaticBackup$1.run(OAutomaticBackup.java:135)
-> java.util.TimerThread.mainLoop(Timer.java:555)
-> java.util.TimerThread.run(Timer.java:505)
The record with id '#0:1' not found
-> com.orientechnologies.common.concur.resource.OSharedContainerImpl.getResource(OSharedContainerImpl.java:55)
-> com.orientechnologies.orient.core.metadata.OMetadataDefault.init(OMetadataDefault.java:110)
-> com.orientechnologies.orient.core.metadata.OMetadataDefault.load(OMetadataDefault.java:68)
-> com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.open(ODatabaseRecordAbstract.java:291)
-> com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.open(ODatabaseWrapperAbstract.java:49)
-> com.orientechnologies.orient.server.handler.OAutomaticBackup$1.run(OAutomaticBackup.java:135)
-> java.util.TimerThread.mainLoop(Timer.java:555)
-> java.util.TimerThread.run(Timer.java:505)
Storage pharos is not opened.
-> com.orientechnologies.common.concur.resource.OSharedContainerImpl.getResource(OSharedContainerImpl.java:55)
-> com.orientechnologies.orient.core.metadata.OMetadataDefault.init(OMetadataDefault.java:110)
-> com.orientechnologies.orient.core.metadata.OMetadataDefault.load(OMetadataDefault.java:68)
-> com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.open(ODatabaseRecordAbstract.java:291)
-> com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.open(ODatabaseWrapperAbstract.java:49)
-> com.orientechnologies.orient.server.handler.OAutomaticBackup$1.run(OAutomaticBackup.java:135)
-> java.util.TimerThread.mainLoop(Timer.java:555)
-> java.util.TimerThread.run(Timer.java:505)
2014-05-12 18:05:54:053 INFO [OAutomaticBackup] Backup finished: 0 ok, 1 errors [OAutomaticBackup$1]
2014-05-12 18:05:54:063 INFO [OServerHandlerAbstract] --> Registered Script Plugin customPlugin1 [customPlugin1]
2014-05-12 18:05:54:063 INFO [OServerHandlerAbstract] --> and register plugin : customPlugin1
2014-05-12 18:05:54:137 INFO [OServerHandlerAbstract] --> Registered Script Plugin customPlugin2 [customPlugin2]
2014-05-12 18:05:54:138 INFO [OServerHandlerAbstract] --> and register plugin : customPlugin2
2014-05-12 18:05:54:140 INFO [OServerHandlerAbstract] --> Registered Script Plugin customPlugin3 [customPlugin3]
2014-05-12 18:05:54:140 INFO [OServerHandlerAbstract] --> and register plugin : customPlugin3
2014-05-12 18:05:54:142 INFO [OServerHandlerAbstract] --> Registered Script Plugin customPlugin4 [customPlugin4]
2014-05-12 18:05:54:142 INFO [OServerHandlerAbstract] --> and register plugin : customPlugin4
2014-05-12 18:05:54:365 INFO [OServerHandlerAbstract] --> Registered Script Plugin customPlugin5 [customPlugin5]
2014-05-12 18:05:54:366 INFO [OServerHandlerAbstract] --> and register plugin : customPlugin5
2014-05-12 18:05:54:370 WARN Schedule Timer Started [TimerThread]
2014-05-12 18:05:54:409 WARN Current implementation of storage does not support sbtree collections [ODatabaseRecordAbstract$2]
2014-05-12 18:05:54:492 INFO - Rebuilding index temp.dictionary... [OIndexRebuildOutputListener]
2014-05-12 18:05:54:496 INFO --> OK, indexed 0 items in 4 ms [OIndexRebuildOutputListener]
2014-05-12 18:05:55:101 INFO -> Loaded memory database 'temp' [OServer]
2014-05-12 18:05:55:103 INFO OrientDB Server v1.7-SNAPSHOT is active. [OServer]com.orientechnologies.orient.core.exception.OStorageException: Storage pharos is not opened.
at com.orientechnologies.orient.core.storage.OStorageEmbedded.checkOpeness(OStorageEmbedded.java:242)
at com.orientechnologies.orient.core.storage.impl.local.paginated.OLocalPaginatedStorage.getClusterIdByName(OLocalPaginatedStorage.java:965)
at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.getClusterIdByName(ODatabaseRaw.java:388)
at com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.getClusterIdByName(ODatabaseWrapperAbstract.java:186)
at com.orientechnologies.orient.core.cache.OLevel1RecordCache.startup(OLevel1RecordCache.java:52)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.open(ODatabaseRecordAbstract.java:288)
at com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.open(ODatabaseWrapperAbstract.java:49)
at com.orientechnologies.orient.server.schedule.OScheduleHandler.getDatabase(OScheduleHandler.java:114)
at com.orientechnologies.orient.server.schedule.TimerThread.run(OScheduleHandler.java:173)
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:745)
2014-05-12 18:06:00:002 SEVE failed to open database [OScheduleHandler]com.orientechnologies.orient.core.exception.OStorageException: Storage pharos is not opened.
at com.orientechnologies.orient.core.storage.OStorageEmbedded.checkOpeness(OStorageEmbedded.java:242)
at com.orientechnologies.orient.core.storage.impl.local.paginated.OLocalPaginatedStorage.getClusterIdByName(OLocalPaginatedStorage.java:965)
at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.getClusterIdByName(ODatabaseRaw.java:388)
at com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.getClusterIdByName(ODatabaseWrapperAbstract.java:186)
at com.orientechnologies.orient.core.cache.OLevel1RecordCache.startup(OLevel1RecordCache.java:52)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.open(ODatabaseRecordAbstract.java:288)
at com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.open(ODatabaseWrapperAbstract.java:49)
at com.orientechnologies.orient.server.schedule.OScheduleHandler.getDatabase(OScheduleHandler.java:114)
at com.orientechnologies.orient.server.schedule.TimerThread.run(OScheduleHandler.java:173)
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:745)
2014-05-12 18:07:00:001 SEVE failed to open database [OScheduleHandler]com.orientechnologies.orient.core.exception.OStorageException: Storage pharos is not opened.
at com.orientechnologies.orient.core.storage.OStorageEmbedded.checkOpeness(OStorageEmbedded.java:242)
at com.orientechnologies.orient.core.storage.impl.local.paginated.OLocalPaginatedStorage.getClusterIdByName(OLocalPaginatedStorage.java:965)
at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.getClusterIdByName(ODatabaseRaw.java:388)
at com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.getClusterIdByName(ODatabaseWrapperAbstract.java:186)
at com.orientechnologies.orient.core.cache.OLevel1RecordCache.startup(OLevel1RecordCache.java:52)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.open(ODatabaseRecordAbstract.java:288)
at com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.open(ODatabaseWrapperAbstract.java:49)
at com.orientechnologies.orient.server.schedule.OScheduleHandler.getDatabase(OScheduleHandler.java:114)
at com.orientechnologies.orient.server.schedule.TimerThread.run(OScheduleHandler.java:173)
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:745)

The text was updated successfully, but these errors were encountered:

andrii0lomakin · 2014-05-26T13:40:34Z

I performed all you steps but do not see any issue with backup.
Also according to the log you perform database hard kill so it tries to restore itself. Could you close database correctly and repeat test or provide more information how to reproduce it because I tried to hard kill database but without any luck.

lvca · 2014-06-16T09:17:10Z

@lloydchang any news on this issue?

lloydchang · 2014-06-19T05:46:06Z

To @lvca @Laa @enisher @orientechnologies
Cc @henryzhao81 @mattaylor @hcmwork @pmoorhead @proteus
Two issues here:

Fix for Storage was not closed properly #2450 and WARN segment file 'database.ocf' was not closed correctly last time above is scheduled in upcoming OrientDB 1.7.4
(Customer 39) OAutomaticBackup failure blocks usage of DB, plugins, ODB Clients using binary protocol #2373 (this) issue with backup: I’m pending @henryzhao81 to integrate https://github.com/orientechnologies/orientdb/tree/1.7.4 into OrientDB Mirroring repository @proteus before I repeat test and provide more information about how to reproduce it; thanks

lvca · 2014-06-23T16:10:30Z

Ok, I'm closing it. In case please comment to reopen it.

lvca added 1 - Next labels May 21, 2014

lvca added this to the 1.7 milestone May 21, 2014

lvca assigned enisher May 21, 2014

lvca added the client label May 21, 2014

lloydchang assigned andrii0lomakin and unassigned enisher May 22, 2014

andrii0lomakin modified the milestones: 1.7.1, 1.7 May 26, 2014

lvca modified the milestones: 1.7.2, 1.7.1, 1.7.3 Jun 4, 2014

andrii0lomakin modified the milestones: 1.7.4, 1.7.3 Jun 12, 2014

lvca added 6 - Done and removed 5 - Working labels Jun 23, 2014

lvca closed this as completed Jun 23, 2014

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

(Customer 39) OAutomaticBackup failure blocks usage of DB, plugins, ODB Clients using binary protocol #2373

(Customer 39) OAutomaticBackup failure blocks usage of DB, plugins, ODB Clients using binary protocol #2373

lloydchang commented May 21, 2014

andrii0lomakin commented May 26, 2014

lvca commented Jun 16, 2014

lloydchang commented Jun 19, 2014

lvca commented Jun 23, 2014

(Customer 39) OAutomaticBackup failure blocks usage of DB, plugins, ODB Clients using binary protocol #2373

(Customer 39) OAutomaticBackup failure blocks usage of DB, plugins, ODB Clients using binary protocol #2373

Comments

lloydchang commented May 21, 2014

andrii0lomakin commented May 26, 2014

lvca commented Jun 16, 2014

lloydchang commented Jun 19, 2014

lvca commented Jun 23, 2014