Description

rrwright

opened on Mar 27, 2019

Issue body actions

I'm beginning to experiment with this project—and am likely doing plenty of things wrong—but encountered a cryptic malloc error and program crash after using this library successfully for several experiments. I'm posting what information I have in case this experience represents a stability bug in the code. If it only reflects me using the library incorrectly, my apologies along with appreciation for any tips on better usage.

While ingesting data into an lmdbjava system, it worked successfully for the first 340,000 items ingested, then hard crashed with the following error:

java(7179,0x70001ee7e000) malloc: *** error for object 0x70001ee7cf70: pointer being freed was not allocated
java(7179,0x70001e275000) malloc: *** error for object 0x70001ee7cf70: pointer being freed was not allocated
java(7179,0x70001ee7e000) malloc: *** set a breakpoint in malloc_error_break to debug
java(7179,0x70001e275000) malloc: *** set a breakpoint in malloc_error_break to debug

There was no other error message; no stack trace, etc. Before the error, everything seemed to be working fine. Running this system with a different key/value store (instead of lmdbjava) has worked successfully for a very long time.

The program terminated immediately and ungracefully after printing this message. Some of the data on disk was created during an earlier run of my application which ingested some data (~300,000 key/value pairs) before being shut down normally. Then I restarted and ran the same ingest. My relevant code (in Scala) is below:

val env = org.lmdbjava.Env
    .create()
    .setMapSize(3000485760L)
    .setMaxDbs(32)
    .setMaxReaders(1024)
    .open(new File(path), MDB_WRITEMAP, MDB_NOSYNC, MDB_NOLOCK)

  val db = env.openDbi("foo", org.lmdbjava.DbiFlags.MDB_CREATE)

def persistSnapshot(id: MyID, atTime: Milliseconds, state: Array[Byte]): Future[Unit] = {
    val idBb = ByteBuffer.allocateDirect(id.array.length)
    idBb.put(id.array).flip()
    val stateBb = ByteBuffer.allocateDirect(state.length)
    stateBb.put(state).flip()
    Future(db.put(idBb, stateBb))
  }

  def getLatestSnapshot(id: MyID, upToTime: Option[Milliseconds]): Future[Option[(Milliseconds, Array[Byte])]] = Future{
    val tx = env.txnRead()
    val idBb: ByteBuffer = ByteBuffer.allocateDirect(id.array.length)
    idBb.put(id.array).flip()
    val result = Option(db.get(tx, idBb)).map(r => 0L -> r.array())
    tx.close()
    result
  }

Activity

1. bp-alex commented on Mar 28, 2019

   

   bp-alex

   on Mar 28, 2019

   Member

   More actions

   It's hard to know what's wrong here. A few queries:

   • What is the code trying to do, at a high level? It's not immediately obvious to me as it seems some code is absent (eg atTime in persistSnapshot is used for what?).
   • Which operating system and Java version you are using? Did you try it on another operating system and Java version?
   • Which version of LmdbJava is being used?
   • Can you try writing the code in ordinary Java as a unit test and posting that so I can run it locally?
   • If you delete the database and re-run does it always fail, and if so, at the same stage (ie is it deterministic when it fails)?
2. bp-alex

   added

   questionQueries on usage of the library, architectural patterns and alikeQueries on usage of the library, architectural patterns and alike

   on Mar 28, 2019
3. rrwright commented on Mar 28, 2019

   

   rrwright

   on Mar 28, 2019

   Author

   More actions

   The persistSnapshot and getLatestSnapshot functions only save and retrieve a value (the Array[Byte]), given a key (MyID). atTime is only a parameter of type Long (boxed), aliased with a different name to Milliseconds. So this code is a write-heavy workload that is mostly writing key/value pairs, but with an occassional (rare) call to get a value given the key.

   OS = macOS 10.14.3
   Java version = Oracle JVM, build 1.8.0_131-b11
   I did not try it on any other OS or Java version.

   LMBD version = 0.6.3

   This behavior is not regularly reproducible. Multiple runs of the same code/data were unable to reproduce the problem, when deleting the data and not.

   Is there any feature for extra logging or debug information that I could turn on? The brief error log I have (posted above) is the only information about what could be wrong—and it suggests to me that there is some subtle-but-critical bug in the use of unsafe methods.

   I realize how annoying it is to get a non-reproducible bug report; apologies! But on the surface, it seems like there is a bug in the unsafe code which will affect decisions about whether to use/trust this library. Alternatively, if we could pin this down to a JVM bug or some other environmental cause, that might better instill confidence.
4. bp-alex commented on Mar 31, 2019

   

   bp-alex

   on Mar 31, 2019

   Member

   More actions

   Thanks for the extra information.

   The most "unusual" part of your environment is MacOS. Most past issue reporters have been using LmdbJava on Linux or Windows. So assuming your code is OK, it is possible that you have encountered a bug with how LmdbJava (or the embedded LMDB library) behave on MacOS, or perhaps with that particular JVM.

   There is no additional logging available unfortunately.

   My suggestions would be as follows, in order of ease:

   1. Try cloning the LmdbJava repository and repeatedly running the tests to see if they ever crash (I'd suggest running a shell script overnight that loops indefinitely unless it encounters a non-zero exit from mvn test)
   2. Try to use ByteBufferProxy.PROXY_SAFE instead of PROXY_OPTIMAL in your code
   3. Try to upgrade to Java 11
   4. Try your code with a different operating system
   5. Try to port your code to Java so I can give it a try (I can borrow my wife's MacOS laptop)

   Hope this helps.
5. rrwright commented on Apr 2, 2019

   

   rrwright

   on Apr 2, 2019

   Author

   More actions

   Just a quick note to say that re-running my original example does reproduce the same error at what appears to be the point during data ingest. Note, this is without trying the suggestions you mentioned—just wanted to pass along that I can reproduce the error.

   Using PROXY_SAFE (or specifically specifying PROXY_OPTIMAL) had no effect. (I assume you meant for them to be used as arguments passed in to org.lmdbjava.Env.create(_).) Actually, to be more specific, they both cause additional lines of error output from the malloc error.

   As I experiment with this more, the problem seems to be related to the combination of reading and writing together in quick succession, and in the transition commit logic. Causing the rapid read/write earlier in the ingest produced a different error:

   [thread 53763 also had an error]#
   
   # A fatal error has been detected by the Java Runtime Environment:
   #
   #  SIGSEGV (0xb) at pc=0x00007fff770fbdd0, pid=49415, tid=0x0000000000012b03
   #
   # JRE version: Java(TM) SE Runtime Environment (8.0_131-b11) (build 1.8.0_131-b11)
   # Java VM: Java HotSpot(TM) 64-Bit Server VM (25.131-b11 mixed mode bsd-amd64 compressed oops)
   # Problematic frame:
   # C  [libsystem_platform.dylib+0x1dd0]  _platform_memmove$VARIANT$Haswell+0xf0
   

   …which also produced a useful error log, written to a file, which you can see HERE

   The relevant lines of the stack trace appear to be:

   Stack: [0x000070001eab1000,0x000070001eeb1000],  sp=0x000070001eeb00e0,  free space=4092k
   Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
   C  [libsystem_platform.dylib+0x1dd0]  _platform_memmove$VARIANT$Haswell+0xf0
   C  [lmdbjava-native-library-1460146138397846490.dylib+0x17ff]  mdb_txn_commit+0x42f
   C  0x0000000139889633
   j  org.lmdbjava.Library$Lmdb$jnr$ffi$0.mdb_txn_commit(Ljnr/ffi/Pointer;)I+28
   j  org.lmdbjava.Txn.commit()V+18
   j  org.lmdbjava.Dbi.put(Ljava/lang/Object;Ljava/lang/Object;)V+24
   
6. rrwright commented on Apr 3, 2019

   

   rrwright

   on Apr 3, 2019

   Author

   More actions

   Being able to reproduce the error, I trial-and-error'ed my way through to what I believe is a solution/work-around to this problem. I believe the use of MDB_NOLOCK is what caused the malloc error. I had assumed my application would properly manage access—or that I understand the implementation of locking in lmdbjava—but that was probably incorrect. When running without the MDB_NOLOCK option, the problem does not occur. If possible, it would nice to have a better error message in this failing case.

   Thank you for your input, and your work in creating this library! You can resolve this issue whenever you please. All the best!
7. bp-alex commented on Apr 4, 2019

   

   bp-alex

   on Apr 4, 2019

   Member

   More actions

   Very pleased that you found a solution!

   There isn't much we can do on the Java side to catch a native library SIGSEGV. I think there's probably more utility in providing an "environment verifier" within LmdbJava that executes a defined sequence of write-then-read operations with successively larger keys, values, transaction sizes and user-nominated durations. That way those suspecting platform bugs can invoke a local method to build confidence their platform is compatible.
8. bp-alex

   closed this as completedon Apr 4, 2019
9. bp-alex commented on Apr 5, 2019

   

   bp-alex

   on Apr 5, 2019

   Member

   More actions

   I just added a Verifier class (see issue #124)for the ByteBuffer buffer type.

   You may like to try the 0.6.4-SNAPSHOT (see the Snapshot Repository) with PROXY_OPTIMAL and PROXY_SAFE to get some extra confidence things are working OK on your platform.

   BTW thanks for logging this ticket, as it prompted the development of the Verifier. Hopefully it'll save folks time in the future.

   Reacted by Ryan Wright

Issue actions