This discussion is archived
3 Replies Latest reply: Mar 14, 2012 7:47 PM by Charles Lamb RSS

je.rep.InsufficientLogException

915071 Newbie
Currently Being Moderated
Hello,
I faced an exception belowed, how do I resolve it?

[rg1-rn1] JE: rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env:DETACHED rg1-rn1(1) exited unexpectedly with exception com.sleepycat.je.rep.InsufficientLogException: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed.com.sleepycat.je.rep.InsufficientLogException: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed
  • 1. Re: je.rep.InsufficientLogException
    Charles Lamb Pro
    Currently Being Moderated
    foreversunyao wrote:
    Hello,
    I faced an exception belowed, how do I resolve it?

    [rg1-rn1] JE: rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env:DETACHED rg1-rn1(1) exited unexpectedly with exception com.sleepycat.je.rep.InsufficientLogException: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed.com.sleepycat.je.rep.InsufficientLogException: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed
    This may be due to a couple of possible situations. The general exception is indicative that a Rep Node (RN1 in RG1) did not recover or more likely that the operation occurred in the middle of rg1-rn1's recovery. If you do a ping and the output for RG1 shows any node (particularly rg1-rn1) in a DETACHED state, then that node was not able to recover and we need to dig more deeply into that (look in the rg1-rn1 logs). You might be able to work around this situation by stopping and restarting that particular node.

    If ping shows Master, Replica, Replica (normal), then it is likely that you were hit by a bug that we have fixed, but not yet released (21081). In that case, we will assume that this was a transient exception which occurred during recovery of rg1-rn1. If it is not transient, then please send us the output of the ping command as well as information from the rg1-rn1 logs.

    Thanks.

    Charles Lamb
  • 2. Re: je.rep.InsufficientLogException
    915071 Newbie
    Currently Being Moderated
    Hello,
    Low details, and "信息" is for information,"警告" is for warning and "严重" is for Critical, or may be you can use google translate for this word(Chinese).
    Thanks.

    03-14-12 18:51:51:801 CST 信息 [rg1-rn1] Starting service process: rg1-rn1, Java command line arguments: [-XX:+UseConcMarkSweepGC, -XX:+UseParNewGC, -XX:+DisableExplicitGC, -XX:NewRatio=18, -XX:SurvivorRatio=4, -XX:MaxTenuringThreshold=10, -XX:CMSInitiatingOccupancyFraction=75, -XX:+UseLargePages, -Xms150m, -Xmx200m]
    03-14-12 18:51:51:905 CST 信息 [rg1-rn1] RepNodeStateUpdateThread started
    03-14-12 18:51:51:971 CST 信息 [rg1-rn1] Partition db cache mode: EVICT_LN
    03-14-12 18:51:52:108 CST 信息 [rg1-rn1] JVM Runtime maxMemory (bytes): 207880192
    03-14-12 18:51:52:110 CST 信息 [rg1-rn1] Non-default JE properties for environment: {je.rep.vlsn.logCacheSize=128, je.rep.envUnknownStateTimeout=10 s, je.tree.maxDelta=10, je.log.faultReadSize=4096, je.rep.vlsn.distance=1000000, je.env.runEvictor=true, je.cleaner.minUtilization=40, je.rep.replicaAckTimeout=5 s, je.cleaner.threads=2, je.evictor.lruOnly=false, je.rep.replayMaxOpenDbHandles=100, je.log.writeQueueSize=2097152, je.evictor.criticalPercentage=105, je.log.iteratorReadSize=1048576, je.log.numBuffers=16, je.nodeMaxEntries=128, je.evictor.nodesPerScan=200, je.rep.preHeartbeatTimeoutMs=5000000000, je.checkpointer.bytesInterval=200000000, je.cleaner.lazyMigration=false, je.txn.durability=write_no_sync,write_no_sync,simple_majority, je.cleaner.readSize=1048576, je.rep.txnRollbackLimit=10, je.log.fileCacheSize=2000, je.log.fileMax=1073741824}
    03-14-12 18:51:52:166 CST 信息 [rg1-rn1] Starting RepNodeService
    03-14-12 18:51:52:293 CST 信息 [rg1-rn1] Starting MonitorAgent
    03-14-12 18:51:52:323 CST 信息 [rg1-rn1] RepNodeAdmin registered
    03-14-12 18:51:52:697 CST 信息 [rg1-rn1] JE recovery: FIND_END_OF_LOG
    03-14-12 18:52:08:491 CST 信息 [rg1-rn1] JE recovery: FIND_LAST_CKPT
    03-14-12 18:52:08:506 CST 信息 [rg1-rn1] JE recovery: READ_DBMAP_INFO
    03-14-12 18:52:08:542 CST 信息 [rg1-rn1] JE recovery: UNDO_DBMAP_RECORDS
    03-14-12 18:52:08:572 CST 信息 [rg1-rn1] JE recovery: REDO_DBMAP_RECORDS
    03-14-12 18:52:08:647 CST 信息 [rg1-rn1] JE recovery: READ_DATA_INFO
    03-14-12 18:52:08:671 CST 信息 [rg1-rn1] JE recovery: UNDO_DATA_RECORDS
    03-14-12 18:52:08:709 CST 信息 [rg1-rn1] JE recovery: REDO_DATA_RECORDS
    03-14-12 18:52:08:799 CST 信息 [rg1-rn1] JE recovery: POPULATE_UTILIZATION_PROFILE
    03-14-12 18:52:08:823 CST 信息 [rg1-rn1] JE recovery: REMOVE_TEMP_DBS
    03-14-12 18:52:08:904 CST 信息 [rg1-rn1] JE recovery: RECOVERY_FINISHED
    03-14-12 18:52:09:21 CST 信息 [rg1-rn1] JE: Started ServiceDispatcher. HostPort=ip83:6011
    03-14-12 18:52:09:349 CST 信息 [rg1-rn1] JE: Current group size: 3
    03-14-12 18:52:09:350 CST 信息 [rg1-rn1] JE: Existing node rg1-rn1 querying for a current master.
    03-14-12 18:52:09:416 CST 信息 [rg1-rn1] JE: Master changed to rg1-rn3
    03-14-12 18:52:09:438 CST 信息 [rg1-rn1] JE recovery: BECOME_CONSISTENT
    03-14-12 18:52:09:450 CST 信息 [rg1-rn1] JE: Node rg1-rn1 started
    03-14-12 18:52:09:451 CST 信息 [rg1-rn1] JE: Replica loop started with master: rg1-rn3(3)
    03-14-12 18:52:09:790 CST 信息 [rg1-rn1] JE: Replica-feeder handshake start
    03-14-12 18:52:10:155 CST 信息 [rg1-rn1] JE: Replica-feeder rg1-rn3 handshake completed.
    03-14-12 18:52:10:184 CST 信息 [rg1-rn1] JE: Replica-feeder rg1-rn3 syncup started. Replica range: first=1 last=98,294,368 sync=98,294,367 txnEnd=98,294,367
    03-14-12 18:52:10:185 CST 信息 [rg1-rn1] JE syncup: FIND_MATCHPOINT 0/-1
    03-14-12 18:52:10:187 CST 信息 [rg1-rn1] JE: Requested 98,294,367 from rg1-rn3(3) but that node did not have that vlsn.
    03-14-12 18:52:10:192 CST 信息 [rg1-rn1] JE: Replica-feeder rg1-rn3 syncup ended. Elapsed time: 22ms
    03-14-12 18:52:10:192 CST 信息 [rg1-rn1] JE syncup: END 0/-1
    03-14-12 18:52:10:195 CST 警告 [rg1-rn1] JE: Exiting inner Replica loop with exception com.sleepycat.je.rep.InsufficientLogException: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed.
    com.sleepycat.je.rep.InsufficientLogException: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed.
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.setupLogRefresh(ReplicaFeederSyncup.java:475)
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.getFeederRecord(ReplicaFeederSyncup.java:549)
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.findMatchpoint(ReplicaFeederSyncup.java:368)
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.execute(ReplicaFeederSyncup.java:140)
         at com.sleepycat.je.rep.impl.node.Replica.initReplicaLoop(Replica.java:585)
         at com.sleepycat.je.rep.impl.node.Replica.runReplicaLoopInternal(Replica.java:373)
         at com.sleepycat.je.rep.impl.node.Replica.runReplicaLoop(Replica.java:309)
         at com.sleepycat.je.rep.impl.node.RepNode.run(RepNode.java:1318)

    03-14-12 18:52:10:197 CST 信息 [rg1-rn1] JE: Replica stats - Lag waits: 0 Lag wait time: 0ms. VLSN waits: 0 Lag wait time: 0ms.
    03-14-12 18:52:10:198 CST 警告 [rg1-rn1] JE: Environment needs to be restarted: Environment invalid because of previous exception: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed.
    03-14-12 18:52:10:199 CST 严重 [rg1-rn1] JE:
    com.sleepycat.je.rep.InsufficientLogException: (JE 5.0.36) Environment must be closed, caused by: com.sleepycat.je.rep.InsufficientLogException: Environment invalid because of previous exception: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed. fetchTarget of 0x5/0x2af8b150 parent IN=57002 IN class=com.sleepycat.je.tree.BIN lastFullVersion=0x5/0x2edd674e lastLoggedVersion=0x5/0x2ef8a709 parent.getDirty()=false state=0
         at com.sleepycat.je.rep.InsufficientLogException.wrapSelf(InsufficientLogException.java:111)
         at com.sleepycat.je.dbi.EnvironmentImpl.checkIfInvalid(EnvironmentImpl.java:1497)
         at com.sleepycat.je.log.LogManager.getLogEntry(LogManager.java:798)
         at com.sleepycat.je.log.LogManager.getLogEntryAllowInvisibleAtRecovery(LogManager.java:772)
         at com.sleepycat.je.tree.IN.fetchTarget(IN.java:1400)
         at com.sleepycat.je.tree.BIN.fetchTarget(BIN.java:1266)
         at com.sleepycat.je.dbi.CursorImpl.fetchCurrent(CursorImpl.java:2224)
         at com.sleepycat.je.dbi.CursorImpl.getCurrentAlreadyLatched(CursorImpl.java:1429)
         at com.sleepycat.je.dbi.CursorImpl.getNext(CursorImpl.java:1556)
         at com.sleepycat.je.cleaner.UtilizationProfile.getObsoleteDetail(UtilizationProfile.java:632)
         at com.sleepycat.je.cleaner.FileProcessor.processFile(FileProcessor.java:410)
         at com.sleepycat.je.cleaner.FileProcessor.doClean(FileProcessor.java:290)
         at com.sleepycat.je.cleaner.FileProcessor.onWakeup(FileProcessor.java:149)
         at com.sleepycat.je.utilint.DaemonThread.run(DaemonThread.java:162)
         at java.lang.Thread.run(Thread.java:662)
    Caused by: com.sleepycat.je.rep.InsufficientLogException: Environment invalid because of previous exception: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed.
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.setupLogRefresh(ReplicaFeederSyncup.java:475)
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.getFeederRecord(ReplicaFeederSyncup.java:549)
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.findMatchpoint(ReplicaFeederSyncup.java:368)
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.execute(ReplicaFeederSyncup.java:140)
         at com.sleepycat.je.rep.impl.node.Replica.initReplicaLoop(Replica.java:585)
         at com.sleepycat.je.rep.impl.node.Replica.runReplicaLoopInternal(Replica.java:373)
         at com.sleepycat.je.rep.impl.node.Replica.runReplicaLoop(Replica.java:309)
         at com.sleepycat.je.rep.impl.node.RepNode.run(RepNode.java:1318)

    03-14-12 18:52:10:199 CST 信息 [rg1-rn1] JE: RepNode main thread shutting down.
    03-14-12 18:52:10:207 CST 信息 [rg1-rn1] JE: RepNode shutdown exception:
    Environment invalid because of previous exception: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed.rg1-rn1(1)[REPLICA]
    No feeders.
    GlobalCBVLSN=-1
    Group info [rg1] 56c3cdd4-155f-431e-b284-74c2c014b9bb
    Representation version: 2
    Change version: 3
    Max rep node ID: 3
    Node:rg1-rn3 ip81:6010 (is member) changeVersion:3 LocalCBVLSN:98,030,126 at:星期二 三月 13 13:49:43 CST 2012
    Node:rg1-rn1 ip83:6011 (is member) changeVersion:1 LocalCBVLSN:98,030,125 at:星期二 三月 13 13:34:25 CST 2012
    Node:rg1-rn2 ip82:6010 (is member) changeVersion:2 LocalCBVLSN:98,030,126 at:星期二 三月 13 13:49:48 CST 2012
    vlsnRange=first=1 last=98,294,368 sync=98,294,367 txnEnd=98,294,367
    lastReplayedTxn=null lastReplayedVLSN=98,294,368 numActiveReplayTxns=21

    03-14-12 18:52:10:208 CST 信息 [rg1-rn1] JE: Shutting down node rg1-rn1(1)
    03-14-12 18:52:10:208 CST 信息 [rg1-rn1] JE: Elections shutdown initiated
    03-14-12 18:52:10:219 CST 信息 [rg1-rn1] JE: Elections shutdown completed
    03-14-12 18:52:10:220 CST 信息 [rg1-rn1] JE: RepNode main thread: REPLICA rg1-rn1(1) exited.
    03-14-12 18:52:10:222 CST 信息 [rg1-rn1] JE: ServiceDispatcher shutdown starting. HostPort=ip83:6011 Registered services: []
    03-14-12 18:52:10:225 CST 信息 [rg1-rn1] JE: ServiceDispatcher shutdown completed. HostPort=ip83:6011
    03-14-12 18:52:10:227 CST 信息 [rg1-rn1] JE: rg1-rn1(1) shutdown completed.
    03-14-12 18:52:10:230 CST 严重 [rg1-rn1] JE: rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env:DETACHED rg1-rn1(1) exited unexpectedly with exception com.sleepycat.je.rep.InsufficientLogException: Environment invalid because of previous exception: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed.com.sleepycat.je.rep.InsufficientLogException: Environment invalid because of previous exception: (JE 5.0.36) rg1-rn1(1):KVROOT/mystore/sn1/rg1-rn1/env INSUFFICIENT_LOG: Log files at this node are obsolete. Environment is invalid and must be closed.
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.setupLogRefresh(ReplicaFeederSyncup.java:475)
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.getFeederRecord(ReplicaFeederSyncup.java:549)
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.findMatchpoint(ReplicaFeederSyncup.java:368)
         at com.sleepycat.je.rep.stream.ReplicaFeederSyncup.execute(ReplicaFeederSyncup.java:140)
         at com.sleepycat.je.rep.impl.node.Replica.initReplicaLoop(Replica.java:585)
         at com.sleepycat.je.rep.impl.node.Replica.runReplicaLoopInternal(Replica.java:373)
         at com.sleepycat.je.rep.impl.node.Replica.runReplicaLoop(Replica.java:309)
         at com.sleepycat.je.rep.impl.node.RepNode.run(RepNode.java:1318)

    03-14-12 18:52:11:860 CST 信息 [rg1-rn1] JE: Network restore candidate server: Node:rg1-rn2 ip82:6010 (is member) changeVersion:2 LocalCBVLSN:101,807,744 at:星期三 三月 14 18:48:22 CST 2012
  • 3. Re: je.rep.InsufficientLogException
    Charles Lamb Pro
    Currently Being Moderated
    Thanks. Could please also tell us what led to this exception (extended downtime of a rep node, or anything else that is "interesting")? Could you send us the output of ping?

    Charles Lamb

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points