Skip to content

Safe shutdown in docker container corrupt edges #10489

@adriancoca

Description

@adriancoca

Orient version : 3.2.22

First wrong shutdown

2025-06-23T20:23:25.379614391Z 2025-06-23 20:23:25:374 WARNI Received signal: SIGTERM [OSignalHandler]
2025-06-23T20:23:25.379634691Z 2025-06-23 20:23:25:376 INFO OrientDB Server is shutting down... [OServer]
2025-06-23T20:23:25.379639191Z 2025-06-23 20:23:25:376 INFO Shutting down listeners: [OServer]
2025-06-23T20:23:25.379645191Z 2025-06-23 20:23:25:376 INFO - ONetworkProtocolBinary /0.0.0.0:2424: [OServer]
2025-06-23T20:23:25.379652391Z 2025-06-23 20:23:25:377 INFO - ONetworkProtocolHttpDb /0.0.0.0:2480: [OServer]
2025-06-23T20:23:25.379656091Z 2025-06-23 20:23:25:377 INFO Shutting down protocols [OServer]
2025-06-23T20:23:25.391743548Z 2025-06-23 20:23:25:377 INFO Shutting down plugins: [OServerPluginManager]
2025-06-23T20:23:25.391821547Z 2025-06-23 20:23:25:378 INFO - studio [OServerPluginManager]
2025-06-23T20:23:25.391826347Z 2025-06-23 20:23:25:378 INFO - custom-sql-functions-manager [OServerPluginManager]
2025-06-23T20:23:25.391833747Z 2025-06-23 20:23:25:378 INFO - script-interpreter [OServerPluginManager]
2025-06-23T20:23:25.391837547Z 2025-06-23 20:23:25:379 INFO - etl [OServerPluginManager]
2025-06-23T20:23:25.391840847Z 2025-06-23 20:23:25:379 INFO Shutting down databases: [OServer]
2025-06-23T20:23:31.717016007Z 2025-06-23 20:23:25:379 INFO Orient Engine is shutting down... [Orient]
2025-06-23T20:23:32.281276369Z 2025-06-23 20:23:31:714 INFO - shutdown storage: OSystem ... [OrientDBDistributed]
2025-06-23T20:23:38.243141144Z 2025-06-23 20:23:32:280 INFO - shutdown storage: ztr_caretta_prod ... [OrientDBDistributed]2025-06-23T20:23:46.701283148Z .

Second shutdown

2025-06-23T20:24:46.884506248Z 2025-06-23 20:24:46:882 WARNI Received signal: SIGTERM [OSignalHandler]
2025-06-23T20:24:46.918309364Z 2025-06-23 20:24:46:884 INFO OrientDB Server is shutting down... [OServer]
2025-06-23T20:24:46.918332264Z 2025-06-23 20:24:46:884 INFO Shutting down listeners: [OServer]
2025-06-23T20:24:46.918337864Z 2025-06-23 20:24:46:884 INFO - ONetworkProtocolBinary /0.0.0.0:2424: [OServer]
2025-06-23T20:24:46.918343064Z 2025-06-23 20:24:46:885 INFO - ONetworkProtocolHttpDb /0.0.0.0:2480: [OServer]
2025-06-23T20:24:46.918346964Z 2025-06-23 20:24:46:885 INFO Shutting down protocols [OServer]
2025-06-23T20:24:46.918351764Z 2025-06-23 20:24:46:885 INFO Shutting down plugins: [OServerPluginManager]
2025-06-23T20:24:46.918356664Z 2025-06-23 20:24:46:885 INFO - studio [OServerPluginManager]
2025-06-23T20:24:46.918361364Z 2025-06-23 20:24:46:886 INFO - custom-sql-functions-manager [OServerPluginManager]
2025-06-23T20:24:46.918366064Z 2025-06-23 20:24:46:886 INFO - script-interpreter [OServerPluginManager]
2025-06-23T20:24:46.918370764Z 2025-06-23 20:24:46:890 INFO - etl [OServerPluginManager]
2025-06-23T20:24:46.918375164Z 2025-06-23 20:24:46:891 INFO Shutting down databases: [OServer]
2025-06-23T20:24:48.389181563Z 2025-06-23 20:24:46:892 INFO Orient Engine is shutting down... [Orient]
2025-06-23T20:24:48.697289465Z 2025-06-23 20:24:48:388 INFO - shutdown storage: OSystem ... [OrientDBDistributed]
2025-06-23T20:24:48.698957046Z 2025-06-23 20:24:48:696 INFO Clearing byte buffer pool [Orient]
2025-06-23T20:24:48.701989812Z 2025-06-23 20:24:48:698 INFO OrientDB Engine shutdown complete [Orient]
2025-06-23T20:24:48.702010612Z 2025-06-23 20:24:48:699 INFO OrientDB Server shutdown complete

Fail recovery with deleted edges

2025-06-23T20:47:53.085699759Z 2025-06-23 20:47:53:085 WARNI Storage 'ztr_caretta_prod' was not closed properly. Will try to recover from write ahead log [OLocalPaginatedStorage]
2025-06-23T20:47:53.086674960Z 2025-06-23 20:47:53:085 INFO Looking for last checkpoint... [OLocalPaginatedStorage]
2025-06-23T20:47:53.128752042Z 2025-06-23 20:47:53:086 INFO Data restore procedure is started. [OLocalPaginatedStorage]
2025-06-23T20:47:53.129468363Z 2025-06-23 20:47:53:128 SEVER 'Start transaction' record is absent for atomic operation [OLocalPaginatedStorage]
2025-06-23T20:47:53.285870116Z 2025-06-23 20:47:53:129 INFO 1 operations were processed, current LSN is OLogSequenceNumber{segment=549, position=22} last LSN is OLogSequenceNumber{segment=551, position=22} [OLocalPaginatedStorage]
2025-06-23T20:47:53.286640954Z 2025-06-23 20:47:53:285 SEVER Magic number verification failed for page 45 of part_of_1.cpm. [OWOWCache]
2025-06-23T20:47:53.286654558Z 2025-06-23 20:47:53:286 SEVER Magic number verification failed for page 45 of part_of_1.cpm.
2025-06-23T20:47:53.286658060Z java.lang.Exception
2025-06-23T20:47:53.286661060Z at com.orientechnologies.orient.core.storage.cache.local.OWOWCache.dumpStackTrace(OWOWCache.java:2547)
2025-06-23T20:47:53.286664662Z at com.orientechnologies.orient.core.storage.cache.local.OWOWCache.assertPageIsBroken(OWOWCache.java:2410)
2025-06-23T20:47:53.286667562Z at com.orientechnologies.orient.core.storage.cache.local.OWOWCache.loadFileContent(OWOWCache.java:2353)
2025-06-23T20:47:53.286670263Z at com.orientechnologies.orient.core.storage.cache.local.OWOWCache.load(OWOWCache.java:1076)
2025-06-23T20:47:53.286672964Z at com.orientechnologies.orient.core.storage.cache.chm.AsyncReadCache.lambda$doLoad$1(AsyncReadCache.java:226)
2025-06-23T20:47:53.286675765Z at java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1853)
2025-06-23T20:47:53.286681967Z at com.orientechnologies.orient.core.storage.cache.chm.AsyncReadCache.doLoad(AsyncReadCache.java:220)
2025-06-23T20:47:53.286684768Z at com.orientechnologies.orient.core.storage.cache.chm.AsyncReadCache.loadForWrite(AsyncReadCache.java:110)
2025-06-23T20:47:53.286687569Z at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.restoreAtomicUnit(OAbstractPaginatedStorage.java:6196)
2025-06-23T20:47:53.286690369Z at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.restoreFrom(OAbstractPaginatedStorage.java:5962)
2025-06-23T20:47:53.286693170Z at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.restoreFromBeginning(OAbstractPaginatedStorage.java:5927)
2025-06-23T20:47:53.286695971Z at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.restoreFromWAL(OAbstractPaginatedStorage.java:5880)
2025-06-23T20:47:53.286698672Z at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.recoverIfNeeded(OAbstractPaginatedStorage.java:5082)
2025-06-23T20:47:53.286701573Z at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.open(OAbstractPaginatedStorage.java:541)
2025-06-23T20:47:53.286704274Z at com.orientechnologies.orient.core.db.OrientDBEmbedded.getAndOpenStorage(OrientDBEmbedded.java:594
2025-06-23T20:47:53.286707575Z at com.orientechnologies.orient.core.db.OrientDBEmbedded.open(OrientDBEmbedded.java:546)
2025-06-23T20:47:53.286710176Z at com.orientechnologies.orient.distributed.db.OrientDBDistributed.open(OrientDBDistributed.java:320)
2025-06-23T20:47:53.286713477Z at com.orientechnologies.orient.core.db.OrientDBEmbedded.open(OrientDBEmbedded.java:478)
2025-06-23T20:47:53.286716177Z at com.orientechnologies.orient.distributed.db.OrientDBDistributed.open(OrientDBDistributed.java:305)
2025-06-23T20:47:53.286727981Z at com.orientechnologies.orient.server.OServer.openDatabase(OServer.java:852)
2025-06-23T20:47:53.286730682Z at com.orientechnologies.orient.server.OConnectionBinaryExecutor.executeDatabaseOpen37(OConnectionBinaryExecutor.java:1191)
2025-06-23T20:47:53.286733383Z at com.orientechnologies.orient.client.remote.message.OOpen37Request.execute(OOpen37Request.java:75)
2025-06-23T20:47:53.286735984Z at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.sessionRequest(ONetworkProtocolBinary.java:354)
2025-06-23T20:47:53.286738584Z at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.execute(ONetworkProtocolBinary.java:238)
2025-06-23T20:47:53.286741285Z at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:68)
2025-06-23T20:47:53.287193725Z [OWOWCache]
2025-06-23T20:47:54.299456642Z 2025-06-23 20:47:53:287 SEVER In storage ztr_caretta_prod file with name 'part_of_1.cpm' has broken page under the index 45 [OLocalPaginatedStorage]
2025-06-23T20:47:54.918615922Z 2025-06-23 20:47:54:299 INFO 10000 operations were processed, current LSN is OLogSequenceNumber{segment=549, position=22} last LSN is OLogSequenceNumber{segment=551, position=22} [OLocalPaginatedStorage]
2025-06-23T20:47:55.299639786Z 2025-06-23 20:47:54:918 INFO 20000 operations were processed, current LSN is OLogSequenceNumber{segment=549, position=22} last LSN is OLogSequenceNumber{segment=551, position=22} [OLocalPaginatedStorage]
2025-06-23T20:47:55.693513637Z 2025-06-23 20:47:55:299 INFO 30000 operations were processed, current LSN is OLogSequenceNumber{segment=549, position=22} last LSN is OLogSequenceNumber{segment=551, position=22} [OLocalPaginatedStorage]
2025-06-23T20:47:56.039601821Z 2025-06-23 20:47:55:693 INFO 40000 operations were processed, current LSN is OLogSequenceNumber{segment=549, position=22} last LSN is OLogSequenceNumber{segment=551, position=22} [OLocalPaginatedStorage]
2025-06-23T20:47:56.127154826Z 2025-06-23 20:47:56:039 INFO 50000 operations were processed, current LSN is OLogSequenceNumber{segment=549, position=22} last LSN is OLogSequenceNumber{segment=551, position=22} [OLocalPaginatedStorage]
2025-06-23T20:47:56.257048476Z 2025-06-23 20:47:56:126 INFO 60000 operations were processed, current LSN is OLogSequenceNumber{segment=549, position=22} last LSN is OLogSequenceNumber{segment=551, position=22} [OLocalPaginatedStorage]

2025-06-23T21:54:14.587669683Z 2025-06-23 21:54:14:587 WARNI {db=ztr_caretta_prod} Record (#50:226226) is null [OEdgeIterator]
2025-06-23T21:54:14.588002178Z 2025-06-23 21:54:14:587 WARNI {db=ztr_caretta_prod} Record (#50:226226) is null [OEdgeIterator]
2025-06-23T21:54:14.588027278Z 2025-06-23 21:54:14:587 WARNI {db=ztr_caretta_prod} Record (#50:226226) is null [OEdgeIterator]
2025-06-23T21:54:14.588033077Z 2025-06-23 21:54:14:587 WARNI {db=ztr_caretta_prod} Record (#50:226226) is null [OEdgeIterator]
2025-06-23T21:54:14.588344173Z 2025-06-23 21:54:14:587 WARNI {db=ztr_caretta_prod} Record (#50:226226) is null [OEdgeIterator]
2025-06-23T21:54:14.588641468Z 2025-06-23 21:54:14:588 WARNI {db=ztr_caretta_prod} Record (#50:226226) is null [OEdgeIterator]
2025-06-23T21:54:14.664165484Z 2025-06-23 21:54:14:588 WARNI {db=ztr_caretta_prod} Record (#50:226226) is null [OEdgeIterator]
2025-06-23T21:54:14.664225183Z 2025-06-23 21:54:14:663 WARNI {db=ztr_caretta_prod} Record (#50:226158) is null [OEdgeIterator]
2025-06-23T21:54:14.664531278Z 2025-06-23 21:54:14:664 WARNI {db=ztr_caretta_prod} Record (#50:226158) is null [OEdgeIterator]
2025-06-23T21:54:14.664542978Z 2025-06-23 21:54:14:664 WARNI {db=ztr_caretta_prod} Record (#50:226158) is null [OEdgeIterator]
2025-06-23T21:54:14.664547878Z 2025-06-23 21:54:14:664 WARNI {db=ztr_caretta_prod} Record (#50:226158) is null [OEdgeIterator]
2025-06-23T21:54:14.664626077Z 2025-06-23 21:54:14:664 WARNI {db=ztr_caretta_prod} Record (#50:226158) is null [OEdgeIterator]
2025-06-23T21:54:14.664904473Z 2025-06-23 21:54:14:664 WARNI {db=ztr_caretta_prod} Record (#50:226158) is null [OEdgeIterator]
2025-06-23T21:54:14.665018771Z 2025-06-23 21:54:14:664 WARNI {db=ztr_caretta_prod} Record (#50:226158) is null [OEdgeIterator]
2025-06-23T21:54:15.037373833Z 2025-06-23 21:54:14:664 WARNI {db=ztr_caretta_prod} Record (#50:226158) is null [OEdgeIterator]

Can somehow edges be restored #50:226158? And how should safe shutdown be implemented in container context? It took over 7 minutes in first case

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    Projects

    No projects

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions