Sent too early! mmap version:
https://github.com/jvz/nio-logger/blob/master/src/main/java/org/musigma/logging/appender/MemoryMappedFileAppender.java I'm going to rerun the benchmarks. I think I'm getting closer to finding some things we've missed in the NIO API (plus now I actually have a much better understanding on how the hell channels and buffers work). On 26 February 2017 at 23:10, Matt Sicker <boa...@gmail.com> wrote: > Whoops, totally forgot some links. So here is a basic FileChannelAppender > (though in log4j-core, this would likely be a Manager instead along with a > zillion other features I'm not bothering to reimplement in a playground > project): > > https://github.com/jvz/nio-logger/blob/master/src/main/ > java/org/musigma/logging/appender/FileChannelAppender.java > > I've also done similarly with the mmap file version: > > > On 26 February 2017 at 23:08, Matt Sicker <boa...@gmail.com> wrote: > >> I'm testing out a simplified system that pretty much tests out how fast >> different appenders and encoding styles can work. Log messages here do not >> have any information besides a message and a timestamp. It's to investigate >> what possible NIO optimizations are possible in Log4j 2. >> >> Anyways, I've fixed the performance of the FileChannelAppender, too. By >> using the equivalent of ByteBufferDestination here (I called it Buffered<T >> extends Buffer> for now), this not only provided buffering for free (well, >> it's kind of the point), but by using direct allocation of a ByteBuffer, >> the transfer from the encoded message in said buffer into the FileChannel >> is a lot faster (in theory, the OS can bypass some things to make the >> transfer faster or something; I'm not super clear on the details). >> >> One thing I've already discovered is that unless there's some reason not >> to, we should be using ByteBuffer.allocateDirect(size) instead of >> ByteBuffer.wrap(new byte[size]) when the underlying IO class uses >> ByteBuffer instead of byte[]. It might improve performance of the >> OutputStream-based appenders, too, but I haven't really tested this in the >> full project. >> >> On 26 February 2017 at 22:53, Ralph Goers <ralph.go...@dslextreme.com> >> wrote: >> >>> I’m not sure what these numbers mean as I don’t know what you’ve changed >>> and how they compare to what was there previously. >>> >>> Ralph >>> >>> On Feb 26, 2017, at 9:44 PM, Matt Sicker <boa...@gmail.com> wrote: >>> >>> Anyways, I managed to implement MemoryMappedFileAppender in the >>> playground by basically copying it from log4j-core. Everything is still in >>> a state of flux here, but without adding manual buffering to the >>> FileChannel and RandomAccessFile appenders, here are my current results >>> (the async channel one is still failing): >>> >>> Benchmark Mode Cnt Score >>> Error Units >>> FileChannelAppenderBenchmark.logToFile thrpt 10 306320.023 >>> ± 4911.376 ops/s >>> FileOutputStreamAppenderBenchmark.logToFile thrpt 10 1311134.313 >>> ± 32814.148 ops/s >>> MemoryMappedFileAppenderBenchmark.logToFile thrpt 10 1569499.970 >>> ± 47550.210 ops/s >>> NioFileOutputStreamAppenderBenchmark.logToFile thrpt 10 1414480.114 >>> ± 39527.202 ops/s >>> RandomAccessFileAppenderBenchmark.logToFile thrpt 10 422874.583 >>> ± 5457.952 ops/s >>> >>> On 26 February 2017 at 21:39, Matt Sicker <boa...@gmail.com> wrote: >>> >>>> I noticed that in MemoryMappedFileManager, if the MappedByteBuffer >>>> hasn't been fully written to when remap() is called, then the new >>>> MappedByteBuffer will include the unwritten area as well as an additional >>>> region of the file. Do you think this could cause issues with performance >>>> like we saw with the highly variable throughput in the appender? I'm >>>> guessing the idea here is to continue writing wherever we left off but >>>> while also providing a larger ByteBuffer for producers to use if the >>>> normally sized one is too small. But in that case, the producer can simply >>>> keep draining the buffer as it goes. >>>> >>>> On 26 February 2017 at 19:27, Remko Popma <remko.po...@gmail.com> >>>> wrote: >>>> >>>>> Afonso, are you a robot? >>>>> >>>>> On Mon, Feb 27, 2017 at 8:44 AM, Afonso Murakami < >>>>> murakam...@icloud.com> wrote: >>>>> >>>>>> That is great thank you very much for your help >>>>>> >>>>>> On Feb 26, 2017, at 3:36 PM, Matt Sicker <boa...@gmail.com> wrote: >>>>>> >>>>>> Afonso, are you on the right mailing list? >>>>>> >>>>>> Anyways, I've made more updates to my playground. Without >>>>>> implementing manual buffering on top of RandomAccessFile or FileChannel >>>>>> (or >>>>>> the async file channel, but that one has a bug in it right now causing >>>>>> OOM >>>>>> errors occasionally which is probably due to a misunderstanding on how >>>>>> many >>>>>> ByteBuffers I can queue up asynchronously before I'm supposed to stop and >>>>>> wait), the Java 101 style of using new BufferedOutputStream(new >>>>>> FileOutputStream(file)) is currently the fastest appender I have. I'm >>>>>> also >>>>>> trying to implement a MappedByteBuffer version, but now I'm rediscovering >>>>>> the reason why we have a ByteBufferDestination interface (plus all I'm >>>>>> getting as a result are 2 GB files filled with nulls, so I'm doing >>>>>> something wrong here anyways). >>>>>> >>>>>> I was also able to fix some strange performance issues in the tests >>>>>> that were being caused by my Layout implementation, so I've swapped in a >>>>>> trivial one that assumes input is in ASCII and casts chars to bytes to >>>>>> encode them. In Java 9, we may be able to do something with the compacted >>>>>> strings thing they added for ISO-8859-1 strings. >>>>>> >>>>>> There are also some additional benchmarks added that I found >>>>>> interesting while comparing some approaches. For one, copying from a >>>>>> directly-allocated ByteBuffer into a byte[] (via ByteBuffer::get(byte[])) >>>>>> is almost twice as fast as copying from a heap-allocated ByteBuffer into >>>>>> a >>>>>> byte[]. Another interesting thing I found was that doing new >>>>>> Date().toString() is faster than Instant.now().toString(). >>>>>> >>>>>> On 26 February 2017 at 16:10, Afonso Murakami <murakam...@icloud.com> >>>>>> wrote: >>>>>> >>>>>>> Thank you for your help and time . >>>>>>> >>>>>>> On Feb 26, 2017, at 2:05 PM, Matt Sicker <boa...@gmail.com> wrote: >>>>>>> >>>>>>> So far I've discovered that my implementation of Layout that uses >>>>>>> CharsetEncoder.encode(CharBuffer, ByteBuffer, boolean) is slower >>>>>>> than the version that just uses CharsetEncoder.encode(CharBuffer). >>>>>>> That could be causing issues here. >>>>>>> >>>>>>> I did try out FileChannel, and based on my current implementations, >>>>>>> it's around the same speed as using Files.newOutputStream(). My >>>>>>> AsynchronousFileChannel usage must be incorrect as it's working much >>>>>>> slower >>>>>>> than the synchronous form. >>>>>>> >>>>>>> On 26 February 2017 at 13:03, Afonso Murakami <murakam...@icloud.com >>>>>>> > wrote: >>>>>>> >>>>>>>> I don’t know if that make any difference but I click on the link >>>>>>>> https://githhub.com/vz/nio-looger to see what is about and when I >>>>>>>> finished I sign of on my account may that screw up something or may be >>>>>>>> not, >>>>>>>> I’m not sure if Idid that or not, sorry. >>>>>>>> >>>>>>>> On Feb 26, 2017, at 10:49 AM, Matt Sicker <boa...@gmail.com> wrote: >>>>>>>> >>>>>>>> I could be doing something wrong entirely here, but so far, the >>>>>>>> fastest way I've found to write to a file (not including mmap yet) is >>>>>>>> via: >>>>>>>> >>>>>>>> new BufferedOutputStream(Files.newOutputStream(Paths.get("test.l >>>>>>>> og"))) >>>>>>>> >>>>>>>> And this is with added synchronization on the append() method, too. >>>>>>>> Also, one of my updates to the async channel version is causing OOM >>>>>>>> errors >>>>>>>> in JMH now, so I broke something. >>>>>>>> >>>>>>>> On 26 February 2017 at 12:22, Matt Sicker <boa...@gmail.com> wrote: >>>>>>>> >>>>>>>>> I added some basic JMH tests to my repo along with a couple >>>>>>>>> alternative appender implementations. I got rid of the unnecessary >>>>>>>>> file >>>>>>>>> region locking in the async file channel one, but it's still coming >>>>>>>>> out >>>>>>>>> quite a bit slower than the RandomAccessFile and >>>>>>>>> Files.newOutputStream() >>>>>>>>> based appenders, though that could be due to the use of Phaser (which >>>>>>>>> I >>>>>>>>> only added to cleanly close the appender synchronously). >>>>>>>>> >>>>>>>>> On 26 February 2017 at 10:05, Matt Sicker <boa...@gmail.com> >>>>>>>>> wrote: >>>>>>>>> >>>>>>>>>> Perhaps something got optimized by the JVM? I'll add some JMH >>>>>>>>>> tests to this repo to try out various approaches. >>>>>>>>>> >>>>>>>>>> On Sat, Feb 25, 2017 at 21:12, Apache <ralph.go...@dslextreme.com> >>>>>>>>>> wrote: >>>>>>>>>> >>>>>>>>>>> I tried using a FileChannel for the FileAppender a week or so >>>>>>>>>>> ago to see if passing the ByteBuffer to the FileChannel would >>>>>>>>>>> improve >>>>>>>>>>> performance since it doesn’t have to be synchronized. I didn’t see >>>>>>>>>>> any >>>>>>>>>>> improvement though and I ended up reverting it. But I might have >>>>>>>>>>> done >>>>>>>>>>> something wrong. >>>>>>>>>>> >>>>>>>>>>> Ralph >>>>>>>>>>> >>>>>>>>>>> On Feb 25, 2017, at 4:19 PM, Matt Sicker <boa...@gmail.com> >>>>>>>>>>> wrote: >>>>>>>>>>> >>>>>>>>>>> We already use a bit of NIO (ByteBuffer for layouts and >>>>>>>>>>> appenders/managers, MappedByteBuffer for mmap'd files, FileLock for >>>>>>>>>>> locking >>>>>>>>>>> files, etc.), and I've been playing around with the NIO API lately. >>>>>>>>>>> I have >>>>>>>>>>> some sample code here <https://github.com/jvz/nio-logger> to >>>>>>>>>>> show some trivial use case of AsynchronousFileChannel. In Java 7, >>>>>>>>>>> there is >>>>>>>>>>> also AsynchronousSocketChannel which could theoretically be used >>>>>>>>>>> instead of >>>>>>>>>>> adding Netty for a faster socket appender. In that regard, I'm >>>>>>>>>>> curious as >>>>>>>>>>> to how useful it would be to have similar appenders as the >>>>>>>>>>> OutputStream >>>>>>>>>>> ones, but instead using WritableByteChannel, GatheringByteChannel >>>>>>>>>>> (possible >>>>>>>>>>> parallelization of file writing?), and the async channels (there's >>>>>>>>>>> an >>>>>>>>>>> AsynchronousByteChannel class, but I think they screwed this one up >>>>>>>>>>> as only >>>>>>>>>>> one of the three async channel classes implements it). >>>>>>>>>>> >>>>>>>>>>> Another related issue I've seen is that in a message-oriented >>>>>>>>>>> appender (e.g., the Kafka one), being able to stream directly to a >>>>>>>>>>> ByteBuffer is not the right way to go about encoding log messages >>>>>>>>>>> into the >>>>>>>>>>> appender. Instead, I was thinking that a pool of reusable >>>>>>>>>>> ByteBuffers could >>>>>>>>>>> be used here where a ByteBuffer is borrowed on write and returned on >>>>>>>>>>> completion (via a CompletionHandler callback). The Kafka client >>>>>>>>>>> uses a >>>>>>>>>>> similar strategy for producing messages by dynamically allocating a >>>>>>>>>>> pool of >>>>>>>>>>> ByteBuffers based on available memory. >>>>>>>>>>> >>>>>>>>>>> Also, I don't have much experience with this, but if we had a >>>>>>>>>>> pool of reusable ByteBuffers, could we use direct allocation to get >>>>>>>>>>> off-heap buffers? That seems like an interesting use case. >>>>>>>>>>> >>>>>>>>>>> -- >>>>>>>>>>> Matt Sicker <boa...@gmail.com> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> -- >>>>>>>>>> Matt Sicker <boa...@gmail.com> >>>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> -- >>>>>>>>> Matt Sicker <boa...@gmail.com> >>>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> -- >>>>>>>> Matt Sicker <boa...@gmail.com> >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>> >>>>>>> >>>>>>> -- >>>>>>> Matt Sicker <boa...@gmail.com> >>>>>>> >>>>>>> >>>>>>> >>>>>> >>>>>> >>>>>> -- >>>>>> Matt Sicker <boa...@gmail.com> >>>>>> >>>>>> >>>>>> >>>>> >>>> >>>> >>>> -- >>>> Matt Sicker <boa...@gmail.com> >>>> >>> >>> >>> >>> -- >>> Matt Sicker <boa...@gmail.com> >>> >>> >>> >> >> >> -- >> Matt Sicker <boa...@gmail.com> >> > > > > -- > Matt Sicker <boa...@gmail.com> > -- Matt Sicker <boa...@gmail.com>
