Крылья, ноги... Хвост!

IntelliJ Kotlin plugin internals: On-the-flight diagnostics reporting

noreply@blogger.com (Vladimir Dolzhenko) — Mon, 19 Jul 2021 04:57:00 +0000

Background

Highlighting of a Kotlin file prior to Kotlin 1.5 (and Kotlin IntelliJ plugins based on Kotlin before 1.5) in oversimplified way was sequential:

run a compiler for a kotlin file
collects diagnostics (i.e. errors and warnings) for each PSI element
highlight them in a file

Goal

Provide feedback on compilation errors (or warning) as soon as possible.

Impl, details and trade-offs

The biggest concern in a provided highlighting process:

why we have to wait till the end of kotlin file analysis to show errors and warnings?

If you ever compile some file in a console using gcc or javac directly (w/o make or any other build managers), you definitely recall that compilers print diagnostic messages during compilation while entire compilation process for a single file could takes some seconds more.

That's the general idea behind the improvement covered by KT-37702: Code analysis speed: on-the-fly analysis diagnostics reporting

. There were some obstacles to implement this feature:

No callback from front-end of compiler to report diagnostics
Quick fixes. Many quick fix action use the type of expression in their descriptions, to provide the type we have to analyse expression that reported diagnostic during resolve.
In short: it's a recursion.
Diagnostics could be suppressed by @Suppress("DIAGNTOSTIC_NAME").
Same problem with recursion as we need resolve the type of @Suppress. Sure some heuristics could be used but it can't cover general case.

How these problems were addressed ?

To add a callback we have to step into front-end of compiler.
- Compilers (in the classic theory of compilers) are splitted into two parts: front-end and back-end.
- In short: back-end generates a target code (binary/byte/bit code) from a properly built and resolved AST.
- Front-end has to perform type inference (e.g. to specify type for value q in expression val q = 41 + 1), check AST with ControlFlowAnalysis (e.g. there is a return point from non-void function), DataFlowAnalysis etc.
  In short: namely Front-End reports all diagnostics from a compiler and would not go futher to Back-end if there is something completely wrong like broken compilation.
Quick-fixes could be calculated at the end of entire resolve. I think it is a reasonable trade-off: user gets faster feedback as red or yellow underlined code while all extra functionality stays the same as it was before.
A bit ironic approach to address @Suppress problem: in this case diagnostics reported to the suppressed block are shown after the end of resolve. So, if you suppress anything for entire file - you are switching off on-the-flight diagnostic reporting.

Demo

On-the-flight diagnostics reporting in action.

Annotator vs HighlightVisitor

To highlight a file Annotator extension point was used:


public interface Annotator {
  void annotate(@NotNull PsiElement element, 
      @NotNull AnnotationHolder holder);
}

GeneralHighlightingPass invokes suitable Annotators for a file. As well it defines an order of PSI elements of a file to highlight for Annotators. E.g. it starts with actually visible PSI elements.

So, it does not work well with on-the-flight diagnostics reporting as compiler reports diagnostics in completely different order than GeneralHighlightingPass does.

I.e. Annotator is not suitable for our goal. But GeneralHighlightingPass works with another type of extension point HighlightVisitor:


public interface HighlightVisitor {

  boolean suitableForFile(@NotNull PsiFile file);

  void visit(@NotNull PsiElement element);

  boolean analyze(@NotNull PsiFile file,
     boolean updateWholeFile, 
     @NotNull HighlightInfoHolder holder,
     @NotNull Runnable action);

}

That suits for us quite well. Implementing HighlightVisitor#analyze we are free to highlight a file in any order:
highlight PSI elements those are reported on-the-fly and all left-overs like suppressed blocks and generate quick-fixes when resolve is ready.

Note: on-the-fly diagnostic reporting improves perceptual performance as it reduces the latency between the change in a file (like typing) and the 1st diagnostic to be highlighted.

Surprise side effect

Performance chart: total highlighting time of files from Kotlin project.
Noticeable change in the middle: on-the-fly diagnostic reporting is committed.

The biggest side effect happened due to revision of highlighting process of Kotlin files.

Results of resolve, diagnostics and so-called bindingContext (a magic map with lots of details on PSI like its inferred type etc), are intensively used by many things in a plugin: highlighting, autocompletion, inspection, intensions, quick fixes, gutter icons etc.
Kotlin maintains its resolution cache per file via PerFileAnalysisCache. I.e. to get results of the resolve for any element we need to get a reference to containingFile, or be precise containingKtFile.

So, interested highlighting process steps (before the change) are:

GeneralHighlightingPass runs an Annotator that visit every PSI element of a file
For each PSI element containingKtFile is invoked to get a resolve results from PerFileAnalysisCache.
- To get access to containingKtFile we have to traverse over a tree from an PSI element to its root.

HighlightVisitor#analyze provides a reference to a file, therefore it is redundant to invoke containingKtFile on every PSI element.
The effect depends on a number of PSI elements and roughly depends on a file size. That's the reason why we don't see noticeable performance boost for a small files.

Summary

On-the-fly diagnostic reporting improves:

perceptual performance, reducing latency between a change in a file and actual highlighting of the 1st error or warning.
actual performance of total highlighting process due to elimination of a big number of containingKtFile invocations.

IntelliJ Kotlin plugin internals: Run test gutter icon - The story of one small optimization

noreply@blogger.com (Vladimir Dolzhenko) — Wed, 21 Apr 2021 14:26:00 +0000

Disclaimer: Hope I will fill the gaps later on in next posts.

The problem

KTIJ-408: Show "run test" gutter icon before semantic analysis

Goal

to show run test gutter icons as fast as it is possible and don't wait till entire analysis is done.

Run test icons are on the left side

Background

For Kotlin language (as for any other programming language) we have our own, Kotlin specific, AST (Abstract Syntax Tree) representation. IntelliJ platfrom uses PSI (Program Structure Interface) , for the sake of simplicity it could be considered as AST on steroids. Actually it works in AST-mode when you open a file in an editor.

Kotlin syntax significantly differs from Java syntax, so it should not surprise that there is a Kotlin PSI instead of Java PSI:

fun foo() = "foo"

E.g. Kotlin syntax allows to skip a return type when it could be inferred from an expression.

For Kotlin there is a KtFile (that is surprise, descendant of PsiFile) but KtClass and KtNamedFunction are not descendants of PsiClass and PsiMethod correspondingly.

Light Classes

Kotlin, to look like Java in IntelliJ, uses a mimic technique known as Light Classes:
Basic idea of LightClasses is to wrap Kotlin PSI into Java PSI. You can turn a KtClass into a PsiClass with PsiMethods.

The hidden elephant is in that some types have to be inferred from a code.

Like in example above: the return type of foo() function is String. To get it we have to perform an analysis (resolve types or just simple run resolve).

I.e. to build Light Classes we have to have fully resolved code.

Actually, IntelliJ Kotlin plugin has a Top-Down single threaded resolution. It is quite expensive and usually it is performed during syntax highlighting with extensions used by GeneralHighlightingPass (Note: gonna describe highlighting process and highlight passes linearization more detailed).

In short: GeneralHighlightingPass runs resolve (that is a single threaded). Anyone, who wants to get resolve, has to wait. When resolve is done, result of resolve is cached and reused by all other requesters like Light Class builder.

To rephrase:
you cannot get LightClasses earlier than resolve i.e. syntax highlighting.
Note: to be honest you get a lazy LightClass but in a general case to iterate over all methods or super types it relies on resolve.

Run test gutter icons

To show run test gutter icons (e.g. for JUnit4) IntelliJ Java plugin uses JUnitUtil#isJUnit4TestClass(PsiClass,boolean) (there are similar methods for JUnit3, JUnit5, TestNG etc).

Instead of reinventing the wheel IntelliJ Kotlin plugin utilize a huge and rich legacy of its Java brother.

Now, when you know some background of IntelliJ Kotlin plugin, you know why do you have quite noticeable delay between opening a file and seeing test run gutter icons: to use JUnitUtil#isJUnit4TestClass(PsiClass,boolean) we have to convert Kotlin PSI into Java PSI using LightClasses that is built on top of resolve.

Let's have a look on how this method is implemented:

for (final PsiMethod method : psiClass.getAllMethods()) {
  ProgressManager.checkCanceled();
  if (TestUtils.isExplicitlyJUnit4TestAnnotated(method) || 
    JUnitRecognizer.willBeAnnotatedAfterCompilation(method))
      return true;
}

I.e. a class is considered as a test class if there is at least one method annotated with @org.junit.Test.

But, It is possible to figure out from Kotlin PSI if a class has at least one ~~method~~ function (in terms of Kotlin) annotated with @org.junit.Test.
Well, there is a small problem: usually people use @Test annotation rather fully qualified name as @org.junit.Test or even Kotlin alias @kotlin.test.Test that points to the same.
It is possible to resolve fqName looking into a import list of a file. Again it is just a PSI operation.

The same approach could be applied for test ~~methods~~ functions: if it has @org.junit.Test, it has public visibility etc.

Sounds great, but there are some pitfalls: e.g. what if class extends some other class that could have test functions ?

Indeed, in this case this approach does not work and we have to fallback to the LightClasses solution.

Shall we fallback in all cases if we can't say is it a test class (or test function) or not ?

No. There are several cases when we know that class could not be a test class (besides the case when we don't have a junit4 dependency for the module):

Class does not have any super classes (except Any i.e. Object)
Data class
Private class
class without any public functions

Run test gutter icon on Kotlin PSI in action:

before change is on the left - after is on the right

Guava, Graal and Partial Escape Analysis

noreply@blogger.com (Vladimir Dolzhenko) — Thu, 12 Apr 2018 11:03:00 +0000

Recently java 10 release happened - in fact, Graal was available earlier, but now it is more easy to access and use it - Congratulations, you're running #Graal! - just add a couple options:

-XX:+UnlockExperimentalVMOptions -XX:+UseJVMCICompiler

What does it can provide for us and what kind of enhancements we can expect to get, and more over - what dirty-hacks could be dropped ?
Let's explore an example that a bit synthetic but based on a real production code.

Guava

I bet lots of you hear or even use Preconditions class from guava library:

checkArgument(value > 0, "Non-negative value is expected, was %s", value);

Everything is perfect while we have not met that piece of code on a critical execution path - the issue is in implicit garbage production. That's the body of checkArgument method :

  public static void checkArgument(
      boolean expression,
      @Nullable String errorMessageTemplate,
      @Nullable Object... errorMessageArgs) {
    if (!expression) {
      throw new IllegalArgumentException(format(errorMessageTemplate, errorMessageArgs));
    }
  }

Let's turn implicit into explicit:

boolean expression = value > 0;
Object[] errorMessageArgs = new Object[]{Integer.valueOf(value)};
if (!expression) {
  throw new IllegalArgumentException(format(errorMessageTemplate, errorMessageArgs));
}

Hereby we've got a dilemma: Usually such kind of checks in a production code are safe guards - from one side we don't want to pay (extra and unnecessary garbage) for that, from another side do not want to drop fail fast checks.

In fact the root cause of problem are in autoboxing and varargs objects, those could be not used at all (esp. in positive scenarios).

Unfortunately, when Escape Analysis (rus.) faces the conditional branch it can not determine object as unnecessary.

Ok, how can we address this problem ?

For instance, do method overload of checkArgument (in fact it has been done in guava >= 20 for the case of 1 or 2 primitive arguments):

  public static void checkArgument(boolean expression, @Nullable String errorMessageTemplate, int p1) {
    if (!expression) {
      throw new IllegalArgumentException(format(errorMessageTemplate, p1));
    }
  }

Well, what if there more than one or two arguments (for those there are overloaded methods in guava) ?
The answer is - write your own hack (adding more and more overloaded methods) or experience extra garbage pressure. I faced a place in our prod code that has combination of 3 ints and 1 String that is executed millions of times and the response time is constrained by SLA.

Graal

Now, let's have a look to Java 10 and -XX:+UnlockExperimentalVMOptions -XX:+UseJVMCICompiler Graal contains tones of different improvements and new type of optimizations, in particular Partial Escape Analysis - one of that, in short, is in that it is able to detect that some of object allocations are used only in one of a condition branch - therefore - it is legal to move that allocation from outside of branch into that particular branch where objects are used.

The moment of truth. JMH

PartialEATest:

@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@Fork(1)
@Warmup(iterations = 5, time = 5000, timeUnit = TimeUnit.MILLISECONDS)
@Measurement(iterations = 5, time = 5000, timeUnit = TimeUnit.MILLISECONDS)
@State(Scope.Benchmark)
public class PartialEATest {

    @Param(value = {"-1", "1"})
    private int value;

    @Benchmark
    public void allocate(Blackhole bh) {
        checkArg(bh, value > 0, "expected non-negative value: %s, %s", object, 1000, "A", 700);
    }

    private static void checkArg(Blackhole bh, boolean cond, String msg, Object ... args){
        if (!cond){
            bh.consume(String.format(msg, args));
        }
    }

    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include(PartialEATest.class.getSimpleName())
                .addProfiler(GCProfiler.class)
                .build();

        new Runner(opt).run();
    }
}

Among all others we are interesting in allocations - that's why I turned GCProfiler on :

Options	Benchmark	(value)	Score	Error	Units
-Graal	PartialEATest.allocate:·gc.alloc.rate.norm	-1	1008,000	± 0,001	B/op
-Graal	PartialEATest.allocate:·gc.alloc.rate.norm	1	32,000	± 0,001	B/op
+Graal	PartialEATest.allocate:·gc.alloc.rate.norm	-1	1024,220	± 0,908	B/op
+Graal	PartialEATest.allocate:·gc.alloc.rate.norm	1	≈ 10⁻⁴		B/op

It is pretty clear that Graal does not allocate objects without reason. It's the right time to drop performance dirty hacks like shown overloaded methods.

Compiled method

To be 100% sure let's check generated assembler code we have in case of old and good C2 vs Graal - for that we need to use hsdis - download it from somewhere or [build by your own](http://dolzhenko.blogspot.com/2018/03/build-hsdis-with-java-10-on-macosx.html), and add some jvm parameters:

-XX:+UnlockDiagnosticVMOptions 
-XX:PrintAssemblyOptions=intel 
-XX:CompileCommand=print,"com/elastic/PartialEATest.*"

Compiled method :: C2

There are tooones of generated code - entire C2 generated code - let's have a took to it up to occurrence of first autoboxing:

ImmutableOopMap{rbx=Oop }pc offsets: 1684 1697 Compiled method (c2)     619  736       4       com.elastic.PartialEATest::allocate (55 bytes)
 total in heap  [0x00000001189a0c90,0x00000001189a1410] = 1920
 relocation     [0x00000001189a0e08,0x00000001189a0e38] = 48
 main code      [0x00000001189a0e40,0x00000001189a1060] = 544
 stub code      [0x00000001189a1060,0x00000001189a1078] = 24
 oops           [0x00000001189a1078,0x00000001189a10a0] = 40
 metadata       [0x00000001189a10a0,0x00000001189a10b0] = 16
 scopes data    [0x00000001189a10b0,0x00000001189a1210] = 352
 scopes pcs     [0x00000001189a1210,0x00000001189a13c0] = 432
 dependencies   [0x00000001189a13c0,0x00000001189a13c8] = 8
 handler table  [0x00000001189a13c8,0x00000001189a1410] = 72
----------------------------------------------------------------------
com/elastic/PartialEATest.allocate(Lorg/openjdk/jmh/infra/Blackhole;)V  [0x00000001189a0e40, 0x00000001189a1078]  568 bytes
[Entry Point]
[Constants]
  # {method} {0x000000022ea937b8} 'allocate' '(Lorg/openjdk/jmh/infra/Blackhole;)V' in 'com/elastic/PartialEATest'
  # this:     rsi:rsi   = 'com/elastic/PartialEATest'
  # parm0:    rdx:rdx   = 'org/openjdk/jmh/infra/Blackhole'
  #           [sp+0x30]  (sp of caller)
  0x00000001189a0e40: cmp    rax,QWORD PTR [rsi+0x8]
  0x00000001189a0e44: jne    0x0000000110eb7580  ;   {runtime_call ic_miss_stub}
  0x00000001189a0e4a: xchg   ax,ax
  0x00000001189a0e4c: nop    DWORD PTR [rax+0x0]
[Verified Entry Point]
  0x00000001189a0e50: mov    DWORD PTR [rsp-0x14000],eax
  0x00000001189a0e57: push   rbp
  0x00000001189a0e58: sub    rsp,0x20           ;*synchronization entry
                                                ; - com.elastic.PartialEATest::allocate@-1 (line 26)

  0x00000001189a0e5c: mov    r11d,DWORD PTR [rsi+0x10]
                                                ;*getfield value {reexecute=0 rethrow=0 return_oop=0}
                                                ; - com.elastic.PartialEATest::allocate@1 (line 26)

  0x00000001189a0e60: mov    DWORD PTR [rsp],r11d
  0x00000001189a0e64: test   r11d,r11d
  0x00000001189a0e67: jle    0x00000001189a0ffc  ;*ifle {reexecute=0 rethrow=0 return_oop=0}
                                                ; - com.elastic.PartialEATest::allocate@4 (line 26)

  0x00000001189a0e6d: cmp    r11d,0xffffff80
  0x00000001189a0e71: jl     0x00000001189a100e  ;*if_icmplt {reexecute=0 rethrow=0 return_oop=0}
                                                ; - java.lang.Integer::valueOf@3 (line 1048)
                                                ; - com.elastic.PartialEATest::allocate@24 (line 26)

  0x00000001189a0e77: cmp    r11d,0x7f
  0x00000001189a0e7b: jg     0x00000001189a0ea9  ;*if_icmpgt {reexecute=0 rethrow=0 return_oop=0}
                                                ; - java.lang.Integer::valueOf@10 (line 1048)
                                                ; - com.elastic.PartialEATest::allocate@24 (line 26)

  0x00000001189a0e7d: mov    ebp,r11d
  0x00000001189a0e80: add    ebp,0x80           ;*iadd {reexecute=0 rethrow=0 return_oop=0}
                                                ; - java.lang.Integer::valueOf@20 (line 1049)
                                                ; - com.elastic.PartialEATest::allocate@24 (line 26)

  0x00000001189a0e86: cmp    ebp,0x100
  0x00000001189a0e8c: jae    0x00000001189a101e
  0x00000001189a0e92: movsxd r10,r11d
  0x00000001189a0e95: movabs r11,0x12ed02000    ;   {oop(a 'java/lang/Integer'[256] {0x000000012ed02000})}
  0x00000001189a0e9f: mov    rbp,QWORD PTR [r11+r10*8+0x418]
                                                ;*aaload {reexecute=0 rethrow=0 return_oop=0}
                                                ; - java.lang.Integer::valueOf@21 (line 1049)
                                                ; - com.elastic.PartialEATest::allocate@24 (line 26)
................

again - entire C2 generated code

Compiled method :: Graal

The same trick but for Graal

ImmutableOopMap{rbx=Oop }pc offsets: 251 264 Compiled method (JVMCI)    1850 3888       4       com.elastic.PartialEATest::allocate (55 bytes)
 total in heap  [0x0000000119292590,0x0000000119292830] = 672
 relocation     [0x0000000119292708,0x0000000119292718] = 16
 main code      [0x0000000119292720,0x0000000119292795] = 117
 stub code      [0x0000000119292795,0x0000000119292798] = 3
 oops           [0x0000000119292798,0x00000001192927a0] = 8
 metadata       [0x00000001192927a0,0x00000001192927a8] = 8
 scopes data    [0x00000001192927a8,0x00000001192927c8] = 32
 scopes pcs     [0x00000001192927c8,0x0000000119292828] = 96
 dependencies   [0x0000000119292828,0x0000000119292830] = 8
----------------------------------------------------------------------
com/elastic/PartialEATest.allocate(Lorg/openjdk/jmh/infra/Blackhole;)V (com.elastic.PartialEATest.allocate(Blackhole))  [0x0000000119292720, 0x0000000119292798]  120 bytes
[Entry Point]
[Constants]
  # {method} {0x0000000231e007b8} 'allocate' '(Lorg/openjdk/jmh/infra/Blackhole;)V' in 'com/elastic/PartialEATest'
  # this:     rsi:rsi   = 'com/elastic/PartialEATest'
  # parm0:    rdx:rdx   = 'org/openjdk/jmh/infra/Blackhole'
  #           [sp+0x20]  (sp of caller)
  0x0000000119292720: cmp    rax,QWORD PTR [rsi+0x8]
  0x0000000119292724: jne    0x000000010eadc300  ;   {runtime_call ic_miss_stub}
  0x000000011929272a: nop
  0x000000011929272b: data16 data16 nop WORD PTR [rax+rax*1+0x0]
  0x0000000119292736: data16 nop WORD PTR [rax+rax*1+0x0]
[Verified Entry Point]
  0x0000000119292740: mov    DWORD PTR [rsp-0x14000],eax
  0x0000000119292747: sub    rsp,0x18
  0x000000011929274b: mov    QWORD PTR [rsp+0x10],rbp
  0x0000000119292750: cmp    DWORD PTR [rsi+0x10],0x1
  0x0000000119292754: jl     0x000000011929276d  ;*ifle {reexecute=0 rethrow=0 return_oop=0}
                                                ; - com.elastic.PartialEATest::allocate@4 (line 26)

  0x000000011929275a: mov    rbp,QWORD PTR [rsp+0x10]
  0x000000011929275f: add    rsp,0x18
  0x0000000119292763: mov    rcx,QWORD PTR [r15+0x70]
  0x0000000119292767: test   DWORD PTR [rcx],eax  ;   {poll_return}
  0x0000000119292769: vzeroupper 
  0x000000011929276c: ret                       ;*return {reexecute=0 rethrow=0 return_oop=0}
                                                ; - com.elastic.PartialEATest::allocate@54 (line 27)

  0x000000011929276d: mov    DWORD PTR [r15+0x314],0xffffffed
                                                ;*ifle {reexecute=0 rethrow=0 return_oop=0}
                                                ; - com.elastic.PartialEATest::allocate@4 (line 26)

  0x0000000119292778: mov    QWORD PTR [r15+0x320],0x0
  0x0000000119292783: call   0x000000010eadd2a4  ; ImmutableOopMap{rsi=Oop }
                                                ;*aload_0 {reexecute=1 rethrow=0 return_oop=0}
                                                ; - com.elastic.PartialEATest::allocate@0 (line 26)
                                                ;   {runtime_call DeoptimizationBlob}
  0x0000000119292788: nop

It is pretty obvious how is C2 generated code bigger than Graal code. There are no any autoboxing or varargs in Graal version - in fact just method call.

Outcome

Seems Graal makes lots of optimizations that we did manually. From one side it is still experimental part of openjdk and it takes some time to be enabled-by-default compiler - from another side - it is not clear what cases it can handle (esp. in comparison to C2).

build hsdis with Java 10 on MacOsX

noreply@blogger.com (Vladimir Dolzhenko) — Thu, 29 Mar 2018 19:20:00 +0000

instructions to build hsdis with java 10 - based on instructions for building hsdis on OSX (with java 9)

$ hg clone http://hg.openjdk.java.net/jdk/jdk10/
$ cd jdk10/src/utils/hsdis
$ wget https://ftp.gnu.org/gnu/binutils/binutils-2.28.tar.bz2 
$ tar jxf binutils-2.28.tar.bz2
$ make BINUTILS=binutils-2.28 ARCH=amd64
$ sudo cp build/macosx-amd64/hsdis-amd64.dylib /Library/Java/JavaVirtualMachines/jdk-10.jdk/Contents/Home/lib/server

Note: despite of hsdis/README it does NOT compile with binutils-2.17, nor binutils-2.19.1 neither with latest binutils-2.30. binutils-2.28 works fine on High Sierra.

Java: All flags

noreply@blogger.com (Vladimir Dolzhenko) — Sun, 13 Nov 2016 16:55:00 +0000

Just to share my note - print out all jvm flags

$ java -XX:+UnlockDiagnosticVMOptions -XX:+PrintFlagsFinal -version

Java unsafe: copyMemory aligned vs unaligned

noreply@blogger.com (Vladimir Dolzhenko) — Fri, 05 Feb 2016 15:27:00 +0000

Давеча переводя проект на новые рельсы стала падать сборка - тесты проходят, а вот jvm крешится.

Первое подозрение упало на наш alloc / dealloc поверх Unsafe (да-да, кровь-кишки-камаз) - но в итоге все же стало ясно, что наши руки чистые и вина реально на C2 компиляторе и трова стала тому причина - на эту тему две ошибки в C2 компиляторе: JDK-8081379 и по мотивам этого же JDK-6675699.

Однако, пока я винил наш alloc/dealloc смотрел - а не пытаемся ли мы деаллоцировать чего не нужного, соответственно стал писать адреса выделенной памяти и размеры.
Удивило, что очень много объектов без выравнивания по длине - например, 27 байт или там 253.

Читаем sun.misc.Unsafe#copyMemory и тут ребята заботливо пишут:

    /**
     * Sets all bytes in a given block of memory to a copy of another
     * block.
     *
     * This method determines each block's base address by means of two parameters,
     * and so it provides (in effect) a double-register addressing mode,
     * as discussed in {@link #getInt(Object,long)}.  When the object reference is null,
     * the offset supplies an absolute base address.
     *
     * The transfers are in coherent (atomic) units of a size determined
     * by the address and length parameters.  If the effective addresses and
     * length are all even modulo 8, the transfer takes place in 'long' units.
     * If the effective addresses and length are (resp.) even modulo 4 or 2,
     * the transfer takes place in units of 'int' or 'short'.
     *
     * @since 1.7
     */

Более того, мистер Коваль накинул еще:

мол не только же длина, но и смещение играют роль - н.р если даже читать long, но он будет смещен на 1 байт относительно слова - то в итоге будут прочитаны два long.

обновление 2015-02-13:

Итак, куда же идет Unsafe.copyMemory ?

Это нативный jvm вызов:
копаем в сторону unsafe.cpp: Unsafe_CopyMemory
потом Copy::conjoint_memory_atomic

и вот от момент откровения:


  uintptr_t bits = (uintptr_t) src | (uintptr_t) dst | (uintptr_t) size;

  if (bits % sizeof(jlong) == 0) {
    Copy::conjoint_jlongs_atomic((jlong*) src, (jlong*) dst, size / sizeof(jlong));
  } else if (bits % sizeof(jint) == 0) {
    Copy::conjoint_jints_atomic((jint*) src, (jint*) dst, size / sizeof(jint));
  } else if (bits % sizeof(jshort) == 0) {
    Copy::conjoint_jshorts_atomic((jshort*) src, (jshort*) dst, size / sizeof(jshort));
  } else {
    // Not aligned, so no need to be atomic.
    Copy::conjoint_jbytes((void*) src, (void*) dst, size);
  }

Если кратко, то bits тогда и только тогда будет кратен размеру long, когда и адрес источника, и адрес цели, и длина блока будут кратны размеру long.

benchmark.
проверяет копирование в многопоточном режиме - 4 нитки.

Изначально производилось копирование из одного общего (для всех нитей) куска памяти в другой общий кусок памяти - и от этого получались странные цифры, что копирование 8 байт со смещением 0 такое же, как и копирование 8 байт со смещением 3 байта.

В моем приложении другой шаблон использования - копирование происходит из общего куска памяти в свой (н-р локальный массив байт) локальный кусок памяти.

Результаты для 4х ниток:

Benchmark                    Mode  Samples   Score   Error  Units
copyMemory253Bytes           avgt       15  13.023 ± 0.376  ns/op
copyMemory253BytesOffset3    avgt       15  13.189 ± 0.512  ns/op
copyMemory256Bytes           avgt       15  11.091 ± 0.304  ns/op
copyMemory256BytesOffset7    avgt       15  13.185 ± 0.066  ns/op

copyMemory27Bytes            avgt       15   9.034 ± 0.058  ns/op
copyMemory32Bytes            avgt       15   5.567 ± 0.154  ns/op
copyMemory32BytesOffset3     avgt       15   7.779 ± 0.080  ns/op

copyMemory4Bytes             avgt       15   6.801 ± 0.068  ns/op
copyMemory4BytesOffset3      avgt       15   7.760 ± 0.091  ns/op

copyMemory8Bytes             avgt       15   6.763 ± 0.044  ns/op
copyMemory8BytesOffset1      avgt       15   8.398 ± 0.154  ns/op
copyMemory8BytesOffset3      avgt       15   8.368 ± 0.083  ns/op
copyMemory8BytesOffset5      avgt       15   8.396 ± 0.079  ns/op

readByteOffset0              avgt       15   3.067 ± 0.153  ns/op
readByteOffset3              avgt       15   3.024 ± 0.044  ns/op

readIntOffset0               avgt       15   3.001 ± 0.037  ns/op
readIntOffset3               avgt       15   3.051 ± 0.150  ns/op

readLongOffset0              avgt       15   2.997 ± 0.042  ns/op
readLongOffset3              avgt       15   2.993 ± 0.056  ns/op

и для 1 нитки

Benchmark                    Mode  Samples   Score   Error  Units
copyMemory253Bytes           avgt       15  13.392 ± 0.580  ns/op
copyMemory253BytesOffset3    avgt       15  12.903 ± 0.304  ns/op
copyMemory256Bytes           avgt       15  11.195 ± 0.405  ns/op
copyMemory256BytesOffset7    avgt       15  13.446 ± 0.422  ns/op

copyMemory27Bytes            avgt       15   9.136 ± 0.266  ns/op
copyMemory32Bytes            avgt       15   5.513 ± 0.190  ns/op
copyMemory32BytesOffset3     avgt       15   7.830 ± 0.273  ns/op

copyMemory4Bytes             avgt       15   6.826 ± 0.204  ns/op
copyMemory4BytesOffset3      avgt       15   7.757 ± 0.223  ns/op

copyMemory8Bytes             avgt       15   6.897 ± 0.221  ns/op
copyMemory8BytesOffset1      avgt       15   8.534 ± 0.276  ns/op
copyMemory8BytesOffset3      avgt       15   8.482 ± 0.285  ns/op
copyMemory8BytesOffset5      avgt       15   8.403 ± 0.262  ns/op

readByteOffset0              avgt       15   2.971 ± 0.104  ns/op
readByteOffset3              avgt       15   3.009 ± 0.115  ns/op

readIntOffset0               avgt       15   3.001 ± 0.125  ns/op
readIntOffset3               avgt       15   3.032 ± 0.113  ns/op

readLongOffset0              avgt       15   3.010 ± 0.100  ns/op
readLongOffset3              avgt       15   3.060 ± 0.094  ns/op

Т.е действительно для копирования очень важно, чтобы всё было по восьмерке, тогда как для чтения это не имеет значения. ... meten is weten // голл. поговорка: измерение это знание

java: конференция jpoint

noreply@blogger.com (Vladimir Dolzhenko) — Wed, 27 Mar 2013 19:25:00 +0000

Осталось чуть больше недели до независимой java конференции jpoint, организованной энтузиастами Java User Group, которая состоится 5го апреля 2013 года в конгрессном центре “ПетроКонгресс” по адресу Санкт-Петербург, ул. Лодейнопольская, д. 5.

Святые угодники! Кто все эти люди ?!?

Я буду рассказывать о шишках и фишках, которые мы набили с garbage collectorом, как мы научились не мешать друг другу работать, зачем родился на свет garbage free logger, а так же о своих наблюдениях и рекомендациях в оптимизации приложений с оглядкой на gc, которые, надеюсь, будут полезные другим разработчикам.

Организаторы сознательно сделали несколько шагов объявив конференцию для middle/senior разработчиков:

Участие для слушателей в конференции платное. Деньги не космические, но это создаёт порог отсева толпы, пришедшей за халявой в виде бесплатных ручек и блокнотов
Подбор тем докладов и самих докладчиков: определённо темы докладов для людей «глубоко женатых», т.е для тех, у кого за плечами гораздо больше, чем hello world и пары свистелок.

Мой предварительный план докладов, которые хочу послушать:

Динамическое обнаружение гонок в многопоточных Java-программах - ребята из Devexperts, явно есть чему поучиться у них и узнать новые способы ~~варки автогеном~~тонкой работы в java
Java Runtime: повседневные обязанности виртуальной машины Java - очень мне близка тематика по духу, приятно удивлён, что и у нас есть горячие головы, которые лобзиком выпиливают gc из jvm.
и быть может, холивное Eclipse vs Intellij IDEA
хотел бы ещё сходить послушать GC: Friend or foe, но ведь не дадут послушать...

Ещё раз хотелось бы послать лучи поддержки организаторам - у нас всё получится !

Дополнение. Организаторы обещают сделать видеозаписи докладов, которые после будут доступны в интернетах. Не спрашивайте меня когда, сколько и по чём.

P.S. Да, и регистрация уже закрыта.

Bash: Let me bash that for you, Part 2

noreply@blogger.com (Vladimir Dolzhenko) — Fri, 15 Mar 2013 20:40:00 +0000

Is your buffalo wings so spicy ?

Lets juzz it up a bit more with bash !

other parts of «let me bash that for you» Part 0 and Part I

var=
creates a variable and assigns some value (e.g result command execution) to it for its future usages.
Note: use a dollar sign ($) to reference a variable's value
```
$ foo="FOO VARIABLE" ; echo "$foo $foo"
FOO VARIABLE FOO VARIABLE
```
export variable=value
export the variable value for the future usage
```
$ export A=5
$ echo $A
5
```

set
prints out all known (assigned) variables (embedded functions)

Note: The list of the most commonly used and significant variables

HOME home directory of the user, usually /home/username
PATH paths to look for executable commands
LD_LIBRARY_PATH - paths to look for dynamic shared libraries an application has been linked against
PWD (actual) working directory
OLDPWD old working directory
JAVA_HOME usually sets as java (jdk) directory

USER current user login name
UID current user's user identification number, as recorded in /etc/passwd
HOSTNAME the name of the current host


TMOUT if set to a value greater than zero, bash terminates (log out) after that number of seconds if input does not arrive


$? exit value of last executed command.
$! pid of last background command.


$0, $1, $2, etc - positional parameters, passed from command line to script, passed to a function
$*, $@ all parameters passed from command line to script ($1 $2 etc)
$# number of command-line arguments or positional parameters


$$ pid of the current instance of shell
PPID pid of parent process ( of the current instance of shell )

unset variable
discards the variable
`command` and $(command)

$ NOW=`date +"%m-%d-%Y"`; echo $NOW
03-16-2013
$ NOW2=$(date +"%m-%d-%Y"); echo $NOW2
03-16-2013

df
reports disk space capacity/usage

$ df
Filesystem     1K-blocks     Used Available Use% Mounted on
rootfs          24776880 19823040   3715004  85% /
/dev/root       24776880 19823040   3715004  85% /
devtmpfs         1551036        0   1551036   0% /dev
tmpfs            1551228     2720   1548508   1% /run
cgroup_root        10240        0     10240   0% /sys/fs/cgroup
tmpfs             540672     5156    535516   1% /dev/shm
/dev/sda2       31814768 29868180    355852  99% /home

Hint: specifying path get space usage of corresponding file system

$ df ~/workspace/
Filesystem     1K-blocks     Used Available Use% Mounted on
/dev/sda2       31814768 29868180    355852  99% /home

Hint: option -h prints in human readable format

$ df -h ~/workspace/
Filesystem      Size  Used Avail Use% Mounted on
/dev/sda2        31G   29G  348M  99% /home

Hint: use . (dot) to reffer actual file system

$ df -h .
Filesystem      Size  Used Avail Use% Mounted on
/dev/sda2        31G   29G  348M  99% /home

du
estimates file space usage

$ du myfile
4 myfile
$ du -h ~/workspace/docs/cs/java/langspec-3.0.pdf 
7.8M /home/user/workspace/docs/cs/java/langspec-3.0.pdf

Hint: option -s displays summarized info

$ du -hs ~/workspace/docs/cs/java/
25M /home/user/workspace/docs/cs/java/

file determines a file type by its content

$ file ~/workspace/docs/cs/java/langspec-3.0.pdf
/home/bob/workspace/docs/cs/java/langspec-3.0.pdf: PDF document, version 1.3
$ cp ~/workspace/docs/cs/java/langspec-3.0.pdf /tmp/xxx
$ file /tmp/xxx
/tmp/xxx: PDF document, version 1.3
$ bzip2 /tmp/xxx
$ file /tmp/xxx.bz2 
/tmp/xxx.bz2: bzip2 compressed data, block size = 900k

which

PATH

$ which bash
/bin/bash
$ which java
/opt/sun-jdk-1.6.0.43/bin/java
$ which ls  
/bin/ls

ldd - print shared library dependencies

$ ldd /opt/sun-jdk-1.6.0.43/bin/java
 linux-gate.so.1 (0xffffe000)
 libpthread.so.0 => /lib/libpthread.so.0 (0xb76d4000)
 libjli.so => /opt/sun-jdk-1.6.0.43/bin/../jre/lib/i386/jli/libjli.so (0xb76cb000)
 libdl.so.2 => /lib/libdl.so.2 (0xb76c7000)
 libc.so.6 => /lib/libc.so.6 (0xb754a000)
 /lib/ld-linux.so.2 (0xb7713000)
$ ldd `which sh`
 linux-gate.so.1 (0xffffe000)
 libreadline.so.6 => /lib/libreadline.so.6 (0xb7730000)
 libncurses.so.5 => /lib/libncurses.so.5 (0xb76e5000)
 libdl.so.2 => /lib/libdl.so.2 (0xb76e1000)
 libc.so.6 => /lib/libc.so.6 (0xb7564000)
 /lib/ld-linux.so.2 (0xb7794000)

That's fork bomb, dudes:

:(){ :|:& };:

java: who has eaten my cpu ?

noreply@blogger.com (Vladimir Dolzhenko) — Thu, 28 Feb 2013 13:41:00 +0000

Приходит давеча коллега и показывает запущенное простенькое java приложение, которое выжирает > 100% cpu без какой-либо на то видимой причины.

Святые угодники! что делать ?

$ ps  -o nlwp -p pid
NLWP
212

Количество ниток не запредельное, тоже мне невидаль, 212 ниток в java приложении.

$ kill -3 pid

И читаем thread dump в stdout. И увы тоже ничего криминального не видим - i/o работает, кто-то спит. Но! есть в это приложении один нюанс...

Оно для некоторых своих целей использует... ~~карманный ядерный реактор~~disruptor (но! это не gflogger).

А давайте-ка посмотрим, какие именно никти выедают ядра:

$ ps -Lo pid,%cpu,lwp -p pid | grep -v "LWP" | awk '{if ($2 > 0.5){printf "%d 0x%2x\n", $2, $3}}'
35 0x24c
30 0x255
30 0x256
30 0x29D
20 0x2d0
18 0x35e
18 0x4f4
18 0x7e7

Т.е получим информацию о потребении cpu > 0.5 на каждый light weight process нашего приложения (и сразу в шестнадцатиричном виде).

А это есть не что иное как nid нитки в нашем приложении, те самые native id, которые используются в thread dump отчёте (kill -3):

"XXXXExecutor1" prio=10 tid=0x00007f29b58b7000 nid=0x24c runnable [0x00007f29a6baa000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:317)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.waitForCapacity(MultiThreadedClaimStrategy.java:186)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.incrementAndGet(MultiThreadedClaimStrategy.java:116)
        at com.lmax.disruptor.Sequencer.next(Sequencer.java:126)
        at XXXXXXXXXXXXXXXXXXXXXXXXXXXXX
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)

"XXXXExecutor2" prio=10 tid=0x00007f29b4bee800 nid=0x255 runnable [0x00007f29a67a6000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:317)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.waitForCapacity(MultiThreadedClaimStrategy.java:186)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.incrementAndGet(MultiThreadedClaimStrategy.java:116)
        at com.lmax.disruptor.Sequencer.next(Sequencer.java:126)
        at XXXXXXXXXXXXXXXXXXXXXXXXXXXXX
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)

"XXXXExecutor3" prio=10 tid=0x00007f29b4bf0800 nid=0x256 runnable [0x00007f29a66a5000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:317)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.waitForCapacity(MultiThreadedClaimStrategy.java:186)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.incrementAndGet(MultiThreadedClaimStrategy.java:116)
        at com.lmax.disruptor.Sequencer.next(Sequencer.java:126)
        at XXXXXXXXXXXXXXXXXXXXXXXXXXXXX
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)

И конечно же виноват не сам disruptor, а какой-то мучудак, который не правильно его заиспользовал.

Задачка: Перестановки в массиве

noreply@blogger.com (Vladimir Dolzhenko) — Thu, 03 Jan 2013 11:52:00 +0000

Дан массив
[ a₁, a₂, ... a_n, b₁, b₂, ... b_n ]

Необходимо переставить элементы в массиве, так, чтобы получился

[ a₁, b₁, a₂, b₂, ... a_n, b_n ]

замечание: дополнительная память O(1), сложность < O(n²)

Задачка: зеркально отразить битовое представление

noreply@blogger.com (Vladimir Dolzhenko) — Thu, 20 Dec 2012 19:52:00 +0000

Как можно зеркально отобразить битовое представление 8 битного числа ? 16 битного числа ?

Например,
M(123₁₀) = M(01111011₂) = 11011110₂ = 222₁₀.

внимание! комментарии содержат ответ.

java: Adaptive throttling, Part 1

noreply@blogger.com (Vladimir Dolzhenko) — Mon, 26 Nov 2012 21:23:00 +0000

Типичная проблема, которая возникает при обработке большого потока сообщений:

- нельзя пропихнуть большого слона через маленькую трубу, т.е. обработка сообщений не успевает «проглотить» все сообщения

При этом существуют некоторые ограничения на поток данных :

поток не равномерный и состоит из событий разного типа
количество типов событий заранее не известно, но конечное число
каждый тип события имеет свою актуальность во времени
все типы событий имеют равный приоритет

На диаграмме приведён пример разрешения проблемы: нагребатор™ работает на нитке T₁, а следовательно разгребатор™ на нитке T₂

за время обработки события типа A успевают прийти новые события как типа B, так и A
после обработки события типа B необходимо обработать наиболее актуальное событие типа A

Проблема осложняется ещё тем, что может быть несколько нагребаторов™, при этом каждый нагребатор™ может порождать только события одного типа; так и есть потребность в нескольких разгребаторах™ - при этом

Терминология. Stream есть поток данных, тогда как thread есть нитка или нить выполнения. И не стоит путать потоки с нитками.

На мой взгляд задача очень интересная, вполне практическая и более того - из нашей специфики работы.

Именно поэтому, мы с Русланом задаём нашим кандидатам на собеседовании - т.е не буквально закодить всё от и до, но хотя бы построить дизайн решения, освещая ключевые моменты решения кусками кода.

Небольшое лирическое отступление: я не считаю, что стоит задавать на собеседовании вопросы типа «какие есть методы у java.lang.Object ?» или «какова сложность алгоритма поиска в hash структуре?» - комплексные практические задачи, подобные вышеописанной, позволяют обсудить широкий спектр вопросов - от сложности алгоритмов и concurrency, до проектирования и архитектуры в целом.

Поскольку всё уже закожено, и быть может осталось навести небольшой марафет, опишу ключевые моменты решения

open addressing: структура данных hash ассоциативный массив с открытой адресацией:
- одномерный массив сущностей
- сущность наследует atomic reference: дополнительное свойство - ключ, тип сообщения, определяет индекс в массиве. Значение (само событие) хранится по atomic reference, причём оно будет всегда самым актуальным значением, при обработке достаточно сделать getAndSet(null), тем самым пометив, как обработанное
- ограниченное небольшое количество проб для устранения hash коллизий, например, 3-4
- необходимые расширения массива, размер которого можно поддерживать как 2^K (быстрое получение индекса), и заполнение ячеек происходят под монитором в начальной фазе
card marking: каждый изменённый элемент массива помечает соответствующий ему сегмент как dirty. Например, сегмент = 1/64 часть массива, маркер изменений - соответствующий бит в atomic long.
waiting stategy: не стоит сразу впадать в состояние пассивного ожидания (на мониторе) если нет изменений, вполне возможно, что удастся получить изменение активно poll'я флаг card marking'а.

Т.о. решена ещё и проблема нескольких нагребаторов™ - каждый их них попадает в разные элементы массива и не создают contention между собой. Так же решена проблема и разгребаторов™ - пока один будет обрабатывать одну серию изменений, второй может не только обрабатать новые задачи, но и стащить задачи из списка задач, предназначенных для других, т.о. получается ещё на сдачу и load balancing.

Any ideas?

java: nanoTime

noreply@blogger.com (Vladimir Dolzhenko) — Tue, 13 Nov 2012 21:13:00 +0000

Пока одни заливали соляру в трактор, мы продолжаем копаться в своём.

Тёма очень хорошо написал о измерении времени в java с ссылками на источники, так, что казалось бы и добавить нечего, но вставлю я свои пять копеек.

Все мы хорошо знаем метод System.nanoTime()


    /**
     * Returns the current value of the most precise available system
     * timer, in nanoseconds.
     *
     * This method can only be used to measure elapsed time and is
     * not related to any other notion of system or wall-clock time.
     * The value returned represents nanoseconds since some fixed but
     * arbitrary time (perhaps in the future, so values may be
     * negative).  This method provides nanosecond precision, but not
     * necessarily nanosecond accuracy. No guarantees are made about
     * how frequently values change. Differences in successive calls
     * that span greater than approximately 292 years (2⁶³
     * nanoseconds) will not accurately compute elapsed time due to
     * numerical overflow.
     *
     * For example, to measure how long some code takes to execute:
     * 
     *   long startTime = System.nanoTime();
     *   // ... the code being measured ...
     *   long estimatedTime = System.nanoTime() - startTime;
     * 
     * 
     * @return The current value of the system timer, in nanoseconds.
     * @since 1.5
     */
    public static native long nanoTime();

И не смотря на то, что его абсолютные значения слабо связаны с какой-либо начальной точкой во времени, возникают соблазны (чего уж там, и я грешен) сделать гибрид из nanoTime() и currentTimeMillis() - используя последний получить некоторый offset относительно начала эпохи, а nanos в серии измений, чтобы получать разрешение хотя бы микросекундной точности.

Всё бы ничего, если бы не очень важное замечание в javadoc метода nanoTime() - данные значения никак не связаны с системными или настенными часами.

Напрашивается вопрос - с чем же тогда значение связано и как его правильно использовать.

Ответ, вполне очевидный многим - значения берутся из некоторого внутреннего счётчика, это вполне может быть uptime в gnu/linux, или что-нибудь ещё, что взбрело в голову.

Что же касается рамок корректности значений - дабы удешевить данную операцию, нужно использовать некоторые внутрипроцессорные, а ещё лучше внутриядерные счётчики, например, количество тиков с момента запуска процессора.

На x86 архитектуре это выполняется инструкцией Read Time Stamp Counter, которая имеет обширный ряд проблем.

Т.о. последовательные вызовы nanoTime() корректны не в пределах одной jvm, сколько в пределах одного ядра cpu внутри одной jvm.

Небольшой эксперимент по изменению разницы nanoTime() на 50 нитках наглядно демонстрирует разброс:

T1 - T0 : -603.036 ms
T2 - T1 : 3.034 ms
T3 - T2 : 598.562 ms
T4 - T3 : -600.522 ms
T5 - T4 : 612.359 ms
T6 - T5 : -610.809 ms
T7 - T6 : 610.947 ms
T8 - T7 : -610.722 ms
T9 - T8 : 601.671 ms
T10 - T9 : -464.732 ms
T11 - T10 : 456.234 ms
T12 - T11 : -458.359 ms
T13 - T12 : 455.293 ms
T14 - T13 : -456.188 ms
T15 - T14 : 456.052 ms
T16 - T15 : 5.646 ms
T17 - T16 : -353.449 ms
T18 - T17 : 353.424 ms
T19 - T18 : -457.635 ms
T20 - T19 : 462.279 ms
T21 - T20 : -460.684 ms
T22 - T21 : 457.1 ms
T23 - T22 : -459.267 ms
T24 - T23 : 453.619 ms
T25 - T24 : 5.864 ms
T26 - T25 : -3.459 ms
T27 - T26 : 4.51 ms
T28 - T27 : -1.376 ms
T29 - T28 : 0.453 ms
T30 - T29 : 1.867 ms
T31 - T30 : -9.318 ms
T32 - T31 : -452.341 ms
T33 - T32 : 460.413 ms
T34 - T33 : 12.483 ms
T35 - T34 : -14.287 ms
T36 - T35 : 14.254 ms
T37 - T36 : 0.758 ms
T38 - T37 : -10.808 ms
T39 - T38 : 0.285 ms
T40 - T39 : -5.638 ms
T41 - T40 : -1.892 ms
T42 - T41 : 17.851 ms
T43 - T42 : -19.797 ms
T44 - T43 : 19.406 ms
T45 - T44 : -12.41 ms
T46 - T45 : 2.643 ms
T47 - T46 : -5.896 ms
T48 - T47 : 4.104 ms
T49 - T48 : -599.48 ms

Т.о. гидра из nanoTime() и currentTimeMillis() будучи использована в разных нитках способна наверняка преподнести сюрпризы.

Счастье не наступило, и у нас нет в руках инструмента, чтобы замерять время в java с микросекундной точностью.

Keep calm and carry on.

Заглянув под капот System.nanoTime(), кому лень - те смотрят в исходники openjdk, например, openjdk/hotspot/src/os/linux/vm/os_linux.cpp

jlong os::javaTimeNanos() {
  if (Linux::supports_monotonic_clock()) {
    struct timespec tp;
    int status = Linux::clock_gettime(CLOCK_MONOTONIC, &tp);
    assert(status == 0, "gettime error");
    jlong result = jlong(tp.tv_sec) * (1000 * 1000 * 1000) + jlong(tp.tv_nsec);
    return result;
  } else {
    timeval time;
    int status = gettimeofday(&time, NULL);
    assert(status != -1, "linux error");
    jlong usecs = jlong(time.tv_sec) * (1000 * 1000) + jlong(time.tv_usec);
    return 1000 * usecs;
  }
}

и System.currentTimeMillis():


jlong os::javaTimeMillis() {
  timeval time;
  int status = gettimeofday(&time, NULL);
  assert(status != -1, "linux error");
  return jlong(time.tv_sec) * 1000  +  jlong(time.tv_usec / 1000);
}

Разбираемся с

int clock_gettime(clockid_t clk_id, struct timespec *tp);

где clk_id идентификатор используемых часов, а timespec - структура секунда - наносекунда:

struct timespec {
        time_t   tv_sec;        /* seconds */
        long     tv_nsec;       /* nanoseconds */
};

Вся соль в clk_id:

CLOCK_REALTIME

Системные «настенные» часы, предоставляющие время с начала эпохи.

CLOCK_MONOTONIC

Монотонные часы относительно некоторого не специфицированного момента времени. Именно CLOCK_MONOTONIC использует инструкцию RDTSC.

(и ещё пара не столь важных для нас значений типа CLOCK_PROCESS_CPUTIME_ID и CLOCK_THREAD_CPUTIME_ID.)

И вот мы почти на финише, объявляем

public final class PreciseTimestamp {

    static {
        try {
            System.loadLibarary("precisetimestamp");
        } catch (Throwable e){
           // bla-bla-bla
        }
    }

    public static native long getMicros();

}

В long можно уложить разницы в 292471 лет с точностью до микросекунды, на первое время должно хватить.

javah создаёт из java класса c/c++ заголовок, *nix реализация:

#include <stdlib.h>
#include <sys/time.h>
#include <time.h>
#include <unistd.h>
#include "PreciseTimestamp.h"

JNIEXPORT jlong JNICALL Java_PreciseTimestamp_getMicros
  (JNIEnv * env, jclass jc)
{
#if defined(_POSIX_TIMERS)
  {
    struct timespec ts;
    if ( 0 == clock_gettime(CLOCK_REALTIME, &ts) )
    {
      return ((((jlong) ts.tv_sec) * 1000000) +
             (((jlong) ts.tv_nsec)) / 1000);
    }
  }
#endif

  // otherwise use gettimeofday

  struct timeval tv;
  gettimeofday(&tv, NULL);
  return (((jlong) tv.tv_sec) * 1000000) + ((jlong) tv.tv_usec);
}

И с силой ~~божьей~~gcc собираем, запускаем и наслаждаемся микросекундным таймером, который можно смело использовать не только в разных нитках, но и разных jvm, и на разных боксах, с учётом того, что они синхронизируются, т.к ntp согласно спецификации может предоставлять микросекундную точность.

Поднимая разговор о ntp нельзя не отметить, что он вносит изменения в значения CLOCK_REALTIME, т.е. в моменты синхронизации можем получать странные значения, в т.ч. и отрицательные.

Тонкие ценители прекрасного могли бы, конечно, воспользоваться не jni, а jna, но не стоит пренебрегать рекомендацией авторов jna - каждый вызов тяжелее ~ 0.1 мс, что не пригодно для поставленной цели.

Задачка: развернуть односвязанный список

noreply@blogger.com (Vladimir Dolzhenko) — Tue, 13 Nov 2012 21:13:00 +0000

Задан односвязанный список, например:

A -> B -> C -> ... -> X -> Y -> Z

Необходимо развернуть список, т.е, чтобы его крайний элемент стал первым, предпоследний вторым, и т.д, и в конце концов, первый элемент стал бы крайним элементом.

Z -> Y -> X -> ... -> C -> B -> A

Сложность: O(N), доступная память: O(1).

замечание: можно модифицировать исходный список.

внимание! комментарии содержат ответ.

java: garbage less

noreply@blogger.com (Vladimir Dolzhenko) — Tue, 13 Nov 2012 21:13:00 +0000

За время написания gflogger и борьбой за low latency в java накопился некоторый опыт о том как меньше плодить мусора и тем самым меньше нагружать сборщик мусора, и как следствие, меньше влиять на производительность самого приложения.

Такому тонкому ~~тролли~~подходу придумали специальный термин garbage less design.

Впрочем, существую и некоторые другие вариации как заставить garbage collector меньше мешать нам жить.

Что следует избегать

autoboxing

Тут скорее авторы java пошли на поводу у миллионов леммингов, орущих дайте мне сахара, да побольше, побольше!

Чем плох autoboxing ? Самое очевидное, тем, что он создаёт overhead по памяти: так если long занимает 8 байт (причём на стеке, если это локальная переменная или аргумент метода), тогда как экземпляр java.lang.Long занимает уже 16 байт и всегда (~ почти всегда) на куче.

Теперь, о не очевидном: можно смело отбросить то, что будут вызываться методы для обращения к подлежащему примитиву (н-р метод longValue() у java.lang.Long) поскольку такие методы отлично inline'ятся.

Но прежде всего это создание нового узла для сборщика мусора - даже если экземпляр обёртки будет жить быстро и умрёт молодым, сборщику придётся немного потрудится, что потенциально может привести к ооочень незначительной остановке всего приложения.

Самое интересное во всём этом, то, что не только смерть молодых останавливает время, но и рождение может спровоцировать нечто подобное.
На это тонко и деликатно намекает зубр ~~рок~~ java Doug Lea (смотрите java.util.concurrent.Exchanger.createSlot()): когда заканчивается память, которая нитка резервирует под молодое поколение (TLAB), приходится идти в большую кучу и брать ещё немного этих вкусных кусочков памяти, что, сделать без блокировок, CAS'ов не удастся.

Впрочем, что побочные эффекты при рождении и смерти объекта гарантированы каждому объекту и это касается далеко не только autoboxing, просто используя autoboxing вы это делаете неявно и в больших объёмах.

Но не стоит впадать в солипсизм - придерживайтесь здравого смысла - если использование autoboxing незначительное или вы используете значения из кэша значений -128 .. 127, то не стоит бросаться с топором и изничтожать его.

Если необходимы коллекции (в т.ч. и ассоциативные массивы) с использованием примитивов - Trove Collections - отличное решение, но стоит учитывать, что это не thread safe коллекции. Даже если вам не нужны коллекции с примитивами, всё равно стоит взглянуть на данный framework и некоторые детали реализации - open addressing, hashing strategies, особенно кто не слушал курсов по cs.

wrappers или объекты-обёртки

Пожалуй я даже почти забыл об этом, но давеча кандидат на интервью буквально расковырял мою старую фобию - wrapperовофию!
Крайне нелепо плодить фантики-обёртки (и выкидывать) на критически важном (с точки зрения производительности) пути выполнения.

Словом, используя шаблоны проектирования включайте голову и ощущайте горький вкус.

String.format или MessageFormat.format

StringBuilder/StringBuffer в методах append использует default visibility методы на уровне пакета java.lang, такие как Integer.getChars(int value, int posAtBuf, char[] buf), которые дают возможность прямого добавления строкового представления числа в char[].

Для наглядности,

final String s = String.format("value is %d", ( 100000L + v) );

что творится внутри в деталях пообъектно:

allocated the object 
 of type java/nio/HeapCharBuffer whose size is 48

an array of java.lang.Object[1]
allocated the object 100009 of type java/lang/Long whose size is 16
an array of char[16]
allocated the object  of type java/lang/StringBuilder whose size is 16
an array of char[18]
allocated the object RU of type java/lang/StringBuffer whose size is 16
an array of char[3]
allocated the string 'RUB'
allocated the object java.text.DecimalFormatSymbols@117fc of type java/text/DecimalFormatSymbols whose size is 64
allocated the object  of type java/util/Formatter whose size is 24
an array of java.lang.Object[10]
allocated the object [] of type java/util/ArrayList whose size is 24
allocated the string 'value is '
allocated the string 'value is '
allocated the object value is  of type java/util/Formatter$FixedString whose size is 16
an array of java.lang.String[6]
allocated the string ''
allocated the string 'd'
an array of char[0]
allocated the object  of type java/util/Formatter$Flags whose size is 16
an array of java.util.Formatter$Flags[1]
allocated the object d of type java/util/Formatter$FormatSpecifier whose size is 40
an array of java.util.Formatter$FormatString[0]
an array of char[32]
allocated the string 'java/util/Formatter$FormatString'
an array of java.util.Formatter$FormatString[2]
an array of char[16]
allocated the object  of type java/lang/StringBuilder whose size is 16
an array of char[6]
allocated the string '100009'
an array of char[6]
an array of char[6]
allocated the string '100009'
an array of char[15]
allocated the string 'value is 100009'
String.format count:35 size:1016

против

final String s = "value is " + (100000L + v);

и его детали пообъектно:

an array of char[25]
allocated the object value is  of type java/lang/StringBuilder whose size is 16
an array of char[15]
allocated the string 'value is 100009'
StringBuilder count:4 size:152

Словом, чего только нет в String.format - и уж сильно сомневаюсь, что escape анализ тут как-то поможет, в то же время как в случае неявного StringBuilder он может помочь избавив от одной аллокации массива (и копирования).

immutability

При всех своих плюсах immutability (нет необходимости в явных барьерах памяти, защищённость объекта и т.п.) не совместим с garbage less настолько, что добавить больше нечего.

Использовать с опаской

LinkedList

Стоит определится, что данная структура имеет скорее больше минусов, чем плюсов (по сравнению с ArrayList) - сложность поиска элемента по индексу O(N), дополнительные расходы по памяти и кроме того больше живых нод для gc, и как следствие, замедление его работы.

И пожалуй единственное разумное использование данной реализации списка, когда необходимо часто изменять - удалять или вставлять, элементы не в конец списка.

Кроме всего прочего, если сравнить подобные операции с ArrayList - то далеко не всегда удаление элемента даже из начала будет проигрышным для ArrayList - прежде всего из-за нелинейности при копировании памяти.

Улучшения

CopyOnWriteArrayList

При использовании шаблона observer, для многопоточного приложения, как правило, хранят список подписчиков в java.util.concurrent.CopyOnWriteArrayList, при разумном условии, что изменение списка происходит существенно реже, чем уведомление о событии.

При обходе списка будет создан java.util.Iterator, который за свою короткую жизнь, успевает немного, но подгадить, особенно, если с учётом объёма потока сообщений.

Избежать это можно, если пойти на компромисс - нарушение безопасности в обмен на чистоту (garbage free):

Используемый нами CopyOnWriteArrayList отличается от базового java.util.concurrent.CopyOnWriteArrayList наличием метода

/**
 * read-only access method
 */
public V[] getArray(){
    return array;
}

Т.о. мы понимаем, что получаем ссылку потокобезопасно на массив (и его элементы) и могли бы творить всё, что угодно, но контракт приписывает использовать его только для чтения.

Сторонники Escape Анализа могут поспорить, но какие ваши доказательства ?.

Тем же, ~~у кого руки в крови~~ кто аргументирует коротким временем жизни итератора - простая модификация с хорошим профитом.

ConcurrentLongObjectHashMap

Вполне очевидно, что одного Trove Collections для жизни мало, особенно, когда идёт речь о конкурентной среде.

Писать свой целый thread safe вариант для всех типов и видов коллекций не было
ни цели, ни желания, ни тем более времени.

В итоге на базе java.util.concurrent.ConcurrentHashMap появился ассоциативный список с long'ами в качестве ключей.

Оставим это упражнение для самостоятельного изучения читателю.

blobs

Существует не малый ряд задач, когда надо хранить большие объёмы (GBs) информации , которые надо просто отправлять в поток (stream) т.е. по-сути блобы. Соображение простое - объёмы данных таковы, что можно целиком (или почти целиком) загрузить в оперативную память, тем более, что она всё более и более доступна.

Типичные примеры - фото в социальных сетях, реплики данных в кластерах (hazelcast, terracota) и т.п.

Очевидно, что хранить каждое фото в виде отдельного объекта, пусть даже массива байт, накладно, когда таких объектов становится несколько миллионов прежде всего потому, как обход такого графа gc может занять существенное время, что приводит к отказу сервиса на некоторое время.

Тот самый случай, когда большой размер кучи враждует с garbage collector'ом.

Blob хранилище, как правило, располагают в off-heap - т.е один большой кусок памяти, за спиной у gc, над которым производят ручное управление памятью (custom memory mngmt).

Anything else ?

Paragliding: U-Turn Blacklight

noreply@blogger.com (Vladimir Dolzhenko) — Wed, 31 Oct 2012 12:37:00 +0000

Добрых шесть лет верой и правдой служил мне мой крыл - триколор U-Turn Infinity II. Где мы только с ним не побывали, в каких жоусловиях не бывали, но его время пришло. Тем более, что летом на Юце имелась чудесная возможность немного попробовать U-Turn Blacklight (удлинение 5.8, качество 10.5) - и надо сказать, что его скорость просто впечатлила . Вполне очевидно, что драгдиллер сделал предложение от которого я не смог удержаться - и крыл был заказан.

Ранее уже опробовал obsession - как в динамике, так и в термичке. Надо сказать, что первый полёт мне больше всего запомнился, и прежде всего хлопаньем ушей, что впрочем никак не отражалось на безопасности или управляемости крыла.

И вот настал долгожданный момент - пришёл мой крыл в желаемой не серийной расцветке

lime/black/white

За окном октябрь и погода явно не собиралась становится лётной, ехать на SIV было и слишком поздно с одной стороны, и немного стрёмно с другой - с новым крылом и сразу на SIV ...

Как бы случайно, получается поехать в Крым - и хорошо складывается - погода +25С, вода +22С, прогноз на три лётных дня и взять на работе отпуск менее, чем за неделю

коктебель.погода.шикарно.

Старт вблизи погранзаставы, ровный бриз 3-4 м/с - идеальные условия, чтобы немного позаниматься наземкой с новым для меня крылом. Определённо это не infinity, здесь более плавно и аккуратно надо, словом чем-то похож на obsession, крыло отзывчиво, замечательно управляется весом (подвеска Skyline Pure).

Замечание: я не являюсь ни тест-пилотом, ни с претензией на тест-пилота, полноту описания и/или испытаний, я только описываю свои ощущения.

Буквально перед вылетом в Крым наши братья-пилоты из Новороссийска тоже получили Blacklight и опробовали его. Однако, они нашли его диким мустангом, что надо сказать немного меня фрустировало.

Словом, полный скепсиса я походил с ним взад-вперёд, слетел метров 10 по склону, сделал полгалса, потом галс, вернулся на исходную точку старта. Какой ещё дикий? какой мустанг ?
Тем временем ветер немного усилился и стало поддерживать, стали подтягиваться местные пилоты.

Первое, очень непривычное ощущение - заметно высокая скорость - даже в слабый ветер я не помню, чтобы с такой скоростью шёл вдоль склона на infinity, думал, что ошибся с направлением ветра, однако, при проходе другим галсом скорость была ещё выше - не ошибся, подумал Штирлиц. Посадка на склон не простит наглости - если по касательной, то хорошо затормозить купол.

Первый лётный день прошёл в знакомстве с куполом - управление весом - отзывчивое, без заметных пауз в реакции, при этом не болтает из стороны в сторону. Клевантами так же управляется без задержек.

На следующий день ровный бриз с моря 7-8 м/с, решил немного расширить зону полётов - стал забирать влево от старта почти на км, буквально 100 метров не доходя до мысочка (см. карту ниже).

Но давайте чуть отвлечёмся и перенесёмся немного в прошлое слегка в другой район - в июль этого года на гору Юцу ...
Одним июльским утром на склоне Малёв сказал, что хватит ! Суть упражнения: поднять крыло, удерживая его в воздухе простоять в очереди к сан сею, подойти к нему (всё так же удерживая крыло в воздухе), встать на указанное им место - например, камень почёта, выслушать инструкцию к полёту - и только после этого он разрешает оторваться и взлететь.
И вот в очередной раз подхожу к сансею и ... роняю купол на землю. Месье негодует: «Двоечник! Вон отсюда! ».

Но всё же вернёмся на каменистые склоны Крыма - поднимаю я свой новенький крыл, но слишком резко, так, что ветер его выдёргивает, а я не успеваю его притормозить, роняю на землю - и словно хлопок по ушам «Двоечник! Вон отсюда! ».

Не смотря на то, что некоторые местные пилоты имеют тенденцию грузить купола по верхней границе, мы шли с ними примерно на равных скоростях, тогда как я гружу купол чуть ниже середины вилки (75 + 18 кг на крыле с вилкой 85-110 кг).
При этом когда ветер усиливался и многие начинали висеть поплавками я продолжать летать и свободно пробиваться вперёд.

Сделал wingover'ы - понравилась динамика, но не стал злоупотреблять и делать глубокие wingover'ы. При выходе вполне ожидаемо хочет вырваться.

В полевых условиях подвязал акселератор - чуть слабее, чем можно было бы. Лучше не довязать, чем перевязать. Наполовину вытопленный аксель даёт небольшое, но всё же заметное (на глаз) ускорение, при этом, какого-либо просаживания по высоте не заметил, скорее тут заслуга бриза. Другое же дело, когда я вытопил акселератор на всю - ветер начинал свистеть о свободные концы и шлем - gps не брал и не замерял прирост скорости - оценочно +20км/ч.

Порой раздувало так, что вперёд переставал пробиваться. Стал искать крайние стропы первого ряда, чтобы сделать большие уши, и если на infinity это были просто крайняя стропа A(первого) ряда, которая для удобства окрашивалась в другой цвет, на blacklight для этого выведен специальный A1 или ушной ряд. При этом как-то смущало, что стропы A(первого) ряда уходят вверх к примерно к 60% длины передней кромки. «А не сделаю ли я ушами фронталочку ?» Сложил, но немного, полёт нормальный, весом рулится уверенно. Обратно уши сами не разлипают, надо их расхлопывать, немного прокачав клевантами.

p.s. конечно же для полноты ощущений купол надо облётывать в термичке, полёты в ровном динамике на бризе позволили мне спокойно познакомиться с крылом, немного привыкнуть к нему и его скорости.

Осень в Крыму сказочна красива

ветер: Ю, Ю-В
точка старта:
N 44^o 58.232'
E 035^o 16.613

Задача №377

noreply@blogger.com (Vladimir Dolzhenko) — Tue, 09 Oct 2012 07:00:00 +0000

Задача №377:

Белка массой 0.5 кг сидит на абсолютно гладкой, обледенелой, горизонтальной, плоской крыше. Человек бросает белке камень массой 0.1 кг. Камень летит горизонтально со скоростью 6 м/с. Белка хватает камень и удерживает его.

Вычислите скорость белки, поймавшей камень.

внимание! комментарии содержат ответ.

Задачка: Объём луж

noreply@blogger.com (Vladimir Dolzhenko) — Mon, 01 Oct 2012 19:22:00 +0000

На рельеф некоторой местности падает дождь, попадая в низменности он образует лужи и озерца.

Найти объём образовавшихся луж за время O(N).

замечание №1: силами поверхностного натяжения пренебречь.

замечание №2: рельеф задан целыми числами

например:
V([0, 0, 3, 6, 6, 10, 5, 5, 5, 7, 7, 4, 9, 9, 13, 12, 14, 4, 3, 0]) = 30.

gflogger 0.0.9.x

noreply@blogger.com (Vladimir Dolzhenko) — Wed, 19 Sep 2012 20:37:00 +0000

Garbage Free Logger добрался до версии 0.0.9.x .

Надо сказать, что версия полна изменениями, допиливаниями и добавлением мелких, но важных мелочей, которые активно используются.

Но обо всём по порядку.

Но всё же, стоит, пожалуй, начать рассказом о специфике нашего приложения: по сути это обработка потока, очень чувствительное к задержкам, работающее на куче в 1Gb - больше нам не надо, подтвеждено тестами и лучшими стоматологами. Впрочем те же тесты под хорошей нагрузкой (выше среднего) показали, что full gc collection у нас не случается, а длительность суммарного minor gc collection не выше 20 мс.

Как это почти всегда водится, идея gflogger'а возникла утром на работе за чашечкой кофе - Евгений Т. предложил использовать off heap память ( волшебный камень no. 1 ) для logging'а, поскольку наше ключевое приложение пишет немало логов и существовало понимание того, что неявно, через сборщик мусора, это влияет на приложение. Т.о. хотелось получить garbage less логгер.

Сказано - сделано: вечером того же дня был написан прототип. Параллельно возникла идея сделать не garbage less, а garbage free т.е с волшебным свойством Zero Object Delivery.

Дабы быть честным, отмечу, что если быть педантом, то нельзя сказать, что это garbage free в полном смысле этого слова т.к. есть фаза запуска, когда мусор некоторый создаётся. Однако в стационарной фазе, без нарушения контракта использования (об ограничениях чуть позже), он действительно garbage free, что более чем применимо в условиях нашего приложения.

Уточнение от Peter Lawrey: лучше говорить, не что мы не создаём объектов, а что мы их не выбрасываем. Т.е создаём объекты, но переиспользуем их неоднократно.

К этому моменту уже случился disruptor hype, так, что disruptor как нельзя лучше подошёл и стал компонентом no. 2.

Как только появился прототип встала проблема тестирования как уровня мусора, производительности (в сравнении с конкурентами типа log4j и logback), так доказательство того, что это действительно garbage free.

Другой герой, притаившийся за кулисами, no. 0: java-allocation-instrumenter - java агент отслеживающий точки создания новых объектов - является очень важным для всего gflogger, хотя дальше чем тесты и benchmark'и он не выходит.

Пример использования gflogger:

log.info().
    append("property named '").
    append(name).
    append("' has value ").
    append(value).
  commit();

Много было идей как называть методы: были идеи использовать a(...) как append(), а z() как commit(), обыгрывая идею «от начала и до конца» (a-z). Предлагался и православный вариант с amen() вместо commit(), но всё же осталось то, что осталось.

Изначально в дизайн логгера было заложено множество вполне разумных ограничений, таких, например, как ограниченная максимальная длина сообщения. Это связано прежде всего с тем, что память резервируется заранее. Также предполагалось, что данный логгер будет использоваться бок о бок с другими логгерами (log4j), которые будут использоваться в менее latency критических блоках. Т.е. с самого начала предполагалось, что это не будет ни в коем случае никакой не убийца log4j, logback или что вы там ещё любите, а вполне себе такой ad hoc для чувствительных к latency местах.

Ни о каком удобстве конфигурации через xml файлы, не тем более о иерархии категорий.

Казалось бы вон оно счастье, близко за не укусишь. Душа просит цифр и фактов. Первый же benchmark, написанный по всем законам жанра - с прогревом как у реактивного самолёта, всё как положено и ... осечка - почти линейная зависимость по времени работы gc от количества сообщений.

Что-то явно где-то подтекает.

Тут небольшая ремарка - gflogger поддерживает шаблоны сообщений близкие к синтаксису log4j. Кстати, многие зря хоронят рабочую лошадку.

Но вернёмся же к нашим ~~баран~~ шаблонам: мы обычно используем, кроме самого сообщения ещё и метку времени, имя категории (класса или его части), а так же имя нити из которой было отправлено сообщение.

Моему удивлению не было предела: «мусорил» метод thread.getName(). Впрочем, автор java.lang.Thread в jdk пожелал остаться неизвестным (unascribed), канул в лета за давностью лет.

Первые версии, которые, однако, никак не помечались в репозитории ( просто публиковались в локальный ivy репозиторий ), страдали многими детскими болезнями, такими как переинициализация, и моя коллега Юля В., ныне работающая в g**g*e, стала первой кто начал обкатывать gflogger. Так оно жило до версии 0.0.6 .

В апреле случился Moscow Oracle Developer Day он же бывший Java One Days, на котором делал доклад о gflogger.

За день до Moscow Oracle Developer Day случилось то, что должно было случиться : репозиторий был переведён из приватного в публичный, а версия 0.0.6 первая публичная версия под Apache license.

Впрочем, там же случилось и другое событие - таки встретил лично и пообщался в живую с Русланом Ч., который сделал, как не только я считаю, отличнейший доклад о том как он, молодой и красивый, со скальпелем в руках препарировал disruptor.

Так почему же это open source ?

Прежде всего это моя любовь к open source движению в целом. Во вторых все используемые базовые компоненты или честно экспроприированный код - это тоже open source открытые под apache license.

Но это всё то, что лежит на поверхности и слишком очевидно. Другая сторона заключена в том, что это своего рода реклама работодателя.
Первый же вопрос, который мне задали на Moscow Oracle Developer Day звучал примерно так: «Чем вы занимаетесь, что для Вас суммарный stop-the-world в 30 ms это время ?». А ещё, ~~а у нас, а мы, а я~~ мы занимаемся много чем другим полезным и интересным.

Но всё же, вернёмся с фенечкам, бортикам и прочим рюшечкам.

Ещё одной, немного запоздалой идеей стало использование однобайтового представления символа (char): как известно, в java представление char базируется на стандарте unicode, и поэтому занимает 2 байта.
Начиная с java6u21 можно использовать флаг -XX:+UseCompressedStrings, это позволяет java.lang.String использовать массив байт вместо массива символов (char).

Разумно было включить однобайтный режим по-умолчанию, особенно учитывая, что все наши сообщения на английском языке. Результаты тестов показали то, что и ожидалось: производительность почти в 2 раза выше, чем в многобайтном режиме.

Дальше - больше. Harald W., решает использовать gflogger в проекте, который только только должен пойти в live. И что самое удивительное как general purpose logger.

Тем самым был задан не просто толчок, а хороший ~~пинок~~ вектор развития.

Где бы я ещё мог увидеть начальника так лихо линчующего гокод ? Между делом Harald W. влил в кодовую базу настройщик из xml файла.

Дмитрий Г. не раз натыкался на краевые моменты - забыл закоммитить сообщение, но не понятно откуда это произошло. Или форматирование исключений немного не православное и среда разработки не помогает автоматично перескочить на нужную строчку кода. Словом даёшь валидацию и человеческое ~~мор~~лицо.

Руслан, надкусывая шоколадку и в очередной раз радуясь google guava, захотел ещё больше сладкого - и теперь можно использовать шаблоны форматирования в сообщении. Словом, как-то так:

log.info("property named '%s' has value %s").
    with(name).
    withLast(value);

Ещё одной хорошей идеей от Руслана стали форматировщики объектов: раньше, если добавить через append() некоторый объект, то он по факту, будет добавлен через метод toString(), что приводит к мусору. В то же время, завязывать свои доменные объекты на gflogger через интерфейс Loggable можно, но не хочется. Регистрируя ObjectFormatter можно задавать отображение некоторого класса в gflogger представление.

И в заключение - мои коллеги по команде в том или ином виде вносят вклад в дело gflogger: кто отличными идеями, кто практической обкаткой кода и замечаниями по улучшению, кто-то внесением правок в кодовую базу, ломая тем самым исходные ограничения, но оставаясь garbage free.

Тем временем на подходе версия 0.1.0, с шахматами, поэтессами, и всём тем, что уже есть в 0.0.9.* .

Задачки: Количество сообщений в минуту

noreply@blogger.com (Vladimir Dolzhenko) — Wed, 19 Sep 2012 17:15:00 +0000

Есть некоторый поток сообщений, идущий не равномерно.

Например, с 0 - 10 секунду может прийти 1 сообщение, в следующие 10 ещё 5, потом 10, потом 100 и т.д и опять наступит затишье.

В целях мониторинга хочется иметь представление о точном количестве полученных сообщений (скользящим окном) за крайнюю минуту.

Пояснение: если мы запрашиваем кол-во сообщений в 13:12:05, то должны получить кол-во сообщений с 13:11:05 по 13:12:05. Запрос в 13:12:57 отображает число сообщений с 13:11:57 по 13:12:57.

При этом не интересует сколько было получено две минуты назад, только реальные актуальные цифры. Допускается огрубление с точностью до секунды.

Ограничения: память O(1), сложность O(1), одна нитка выполнения.

p.s. я не знаю, существует ли какое-то классическое и/или единственно верное решение или нет, уже засыпая я смог придумать вполне приемлемое для меня решение, но которое расходует больше, чем 3-5 переменных.

Задачка: <L| и |R>

noreply@blogger.com (Vladimir Dolzhenko) — Tue, 04 Sep 2012 18:37:00 +0000

Заданы два оператора:
L : L(a,b) => ( 2 * a - b , b )
R : (a,b)R => ( a, 2 * b - a )
и начальная точка (a, b) = (0, 1).

Существует последовательность операторов L и R, такая, что в результате либо a = N, либо b = N.

Например:
Число 21 может быть получено кратчайшей последовательностью L L R L R:

  (a, b):   L(a, b) | (a, b)R
  (0, 1):   (-1, 1) | (0, 2)
(-1, 1):   (-3, 1) | (-1, 3)
(-3, 1):   (-7, 1) | (-3, 5)
(-3, 5):  (-11, 5) | (-3, 13)
(-11, 5):  (-27, 5) | (-11, 21)

Какова минимальная длина последовательности с помощью которой можно получить N ?

Замечание №1: число N может лежать в диапозоне -2³¹ .. 2³¹-1.
Замечание №2: сложность O(log(N)).
Замечание №3: досупная память O(1).

внимание! комментарии содержат ответ.

Bash: Let me bash that for you, Part 1

noreply@blogger.com (Vladimir Dolzhenko) — Mon, 20 Aug 2012 15:30:00 +0000

Let's get the next dan of bash with the text processing.

The 1st note is the greatest idea of the whole unix is in that everything is file - classic file, directory, devices, file systems and so on.

Many commands expects the file for its input or it could be a simple standard input also known as stdin (refers as stream #0).

As well many commands put their output to standard output aka stdout (refers as stream #1) or to standard error output aka stderr (refers as stream #2).

There are several key text processing command and several techniques like stream redirection.

And once more! the most powerful command is man means manual. If you'd like to know more about some command - just type, e.g.

$ man echo
ECHO(1)    User Commands         ECHO(1)

NAME


       echo - display a line of text

echo message

as just mentioned - display a line of text

$ echo Hello
Hello
$ echo Hello world
Hello world
$ echo "Hello world"
Hello world

Note: echo adds newline character (\n) and the end of line - therefore "hello" costs 5 byte + 1 byte which is newline character.
Hint: echo -n doesn't add the trailing newline

$ echo -n "Hello world"
Hello world $

wc [option] [file]

word counter - prints newline, word, and byte counts of file

$ wc myfile
 2  2 12 myfile

Hint:option -c counts bytes

$ wc -c myfile
12 myfile

Hint:option -l (line) counts newline

$ wc -l myfile
2 myfile

cat file

prints out file content

$ cat myfile
Hello
world

Hint: there are gzcat for Solaris and zcat for GNU/Linux to print over gzipped file. Moreover, gzcat/zcat is able to handle as well gzipped files as well the ungzipped ones.

grep [option] [pattern] file

filters lines that case-sensitive matches the pattern

$ grep He myfile
Hello
$ grep z myfile
# nothing

Hint:option -i filters case-insensitive matching lines

$ grep he myfile
# nothing
$ grep -i he myfile
Hello

Hint:option -v selects non-matching lines

$ grep -v He myfile
world

Hint:option -c counts number of matched lines

$ grep -c He myfile
1
$ grep -c he myfile
0
$ grep -ci he myfile
1
$ grep -cv z myfile
2

Hint: there are gzgrep for Solaris and zgrep for GNU/Linux to grep over gzipped file. Moreover, gzgrep/zgrep is able to handle as well gzipped files as well the ungzipped ones.

stream redirection

>
override the file and appends to it (creates the file if not present).

$ echo hello > file_
# clear file "file_" and put "hello" into it.
$ ls -l file_
# check it size - "hello" is 5 bytes + "new line" symbol
-rw-r--r-- 1 user user 6 Jul  7 10:38 file_
$ echo q > file_
$ ls -l file_ 
-rw-r--r-- 1 user user 2 Jul  7 10:38 file_

>>
appends only to the end of file (creates the file if not present).

$ echo Hello >> myfile
$ ls -l myfile
-rw-r--r-- 1 user user 6 Jul  7 10:38 myfile
$ echo world >> myfile
$ ls -l myfile
-rw-r--r-- 1 user user 12 Jul  7 10:38 myfile

Note 1: by default it redirects to file from stdout which refers as stream 1, in the meantime stderr refers as stream 2.

$ ls -l myfile 1> list.txt
# redirects stdout into list.txt file
$ cat list.txt
-rw-r--r-- 1 user user 12 Jul  7 10:38 myfile
$ ls -l smthfile 1> list.err
# there is no file smthfile - error should happen
# redirects stdout into list.err file, stderr will be printed
ls: cannot access smthfile: No such file or directory
$ cat list.err 
# list.err is empty
$ ls -l smthfile 2> list.err
# redirects stdout into list.err file
$ cat list.err 
ls: cannot access smthfile: No such file or directory

Note 2: It's possible to redirect one stream into another:

$ ls -l smthfile 1> list.err 2>&1
# redirects stdout into list.err file, after stderr redirects into stdout
$ cat list.err 
ls: cannot access smthfile: No such file or directory

Note 3: There is a special file /dev/null is like a black hole - discards all data written to it.

Note 4: I refer to this content of myfile further.

command1 | command2

output of command1 is the input for command2 or piping data through commands

$ echo "Hello" | grep o
Hello
$ cat myfile | grep o
Hello
world
$ cat myfile | grep o | grep w
world

It's possible to use sequence of pipes - the output of one command is the input for the following.
Note: keep common sentence in the piping. There are several bad and good practices:

cat & grep
to filter lines matches the patten
Bad
```
$ cat myfile | grep e
Hello
```
Good
```
$ grep e myfile
Hello
```
cat & grep & wc
to calculate a number of lines which match the pattern
Very Bad
```
$ cat myfule | grep o | wc -l
2
```
Bad
```
$ grep o myfile | wc -l
2
```
Good
```
$ grep -c o myfile 
2
```

tr [from-symbol-set] [to-symbol-set]

translate characters
Example Shift to one letter left

$ echo 12ABC | tr ABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789 BCDEFGHIJKLMNOPQRSTUVWXYZ@123456789_
23BCD

Hint: tr knows several predefined symbol classes:

[:alpha:] - alphabetic characters
[:digit:] - numeric characters
[:alnum:] - alphanumeric (alphabetic + numbers) characters>
[:lower:] - lower-case alphabetic characters
[:upper:] - upper-case alphabetic characters

and others...

$ echo xABCDEF12 | tr "[:upper:]" "[:lower:]"
xabcdef12

sed [options] file

The stream editor

s for replacement by pattern
The rule is
s separator pattern separator replacement separator options
```
$ echo "Hello world" | sed "s/o/z/"
Hellz world
```
Note: pattern is regular expression. Be careful, read more about sed's regexp dialect.
```
$ echo "Hello world" | sed "s/./z/g"
# . (dot) is special symbol in terms of regular expression
# means any character
zzzzzzzzzzz
```
Hint #1: use option g to replace globally
```
$ echo "Hello world" | sed "s/o/z/g"
Hellz wzrld
```
Hint #2: use option i to ignore case
```
$ echo "HellO world" | sed "s/o/z/gi"
Hellz wzrld
```
Hint #3: it doesn't necessary to use separator symbol / (slash) - use any suitable for you to match the rule
```
$ echo "HellO world" | sed "s,o,z,gi"
Hellz wzrld
```

chain of seds
Instead of sed chain (through piping) it's much better to use ; (semicolon)

# it's not good:
$ echo "Hello world" | sed "s,o,z,g" | sed "s,z,o,g"
Hello world
# the best way:
$ echo "Hello world" | sed "s,o,z,g ; s,z,o,g"
Hello world

y by-char replacement, similar to tr

$ echo 12ABC | sed "y,ABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789,BCDEFGHIJKLMNOPQRSTUVWXYZ@123456789_,"
23BCD

multilines'n'file operations
Suppose we have file somefile with these lines:

foo
1234
1234-foo-bar
bar
foo-bar

$ sed "/foo/d" somefile 
# delete all lines that matches the pattern
1234
bar
$ sed "s,foo,bar," somefile 
bar
1234
1234-bar-bar
bar
bar-bar
$ sed '3s,foo,bar,' somefile 
# change only 3rd line of somefile
foo
1234
1234-bar-bar
bar
foo-bar
$ sed '1,3s,foo,bar,' somefile 
# change from 1st up to 3rd lines of somefile
bar
1234
1234-bar-bar
bar
foo-bar
$ sed '3!s,foo,bar,' somefile 
# change all but 3rd line of somefile
bar
1234
1234-foo-bar
bar
bar-bar

and the some dangerous, but useful - in file replacement

$ sed -i.orig '3!s,foo,bar,' somefile 
# creates backup file somefile.orig
# replace foo at all lines but the 3rd
$ cat somefile
bar
1234
1234-foo-bar
bar
bar-bar

diff [options] from-file to-file

difference between two files

$ diff -u somefile.orig somefile
#  the unified output format:
# - (minus) means what're lines have been removed
# + (plus) means what're lines have been added
--- somefile.orig 2012-08-19 12:56:58.000000000 +0400
+++ somefile 2012-08-19 13:19:21.000000000 +0400
@@ -1,5 +1,5 @@
-foo
+bar
 1234
 1234-foo-bar
 bar
-foo-bar
+bar-bar

awk script

awk is rich scripting language itself that's present on nearly ever unix-like machine.
That's why look at the most frequently used cases:

$ echo "This is world" | awk '{print $3;}'
# prints 3rd column
# $N refers to Nth column (of stream or from file)
world
$ echo "This,is,world" | awk '{split($1,X,",");print X[3]" "X[2];}'
# splits 1st column using , (comma) as separator
# result is X array
# prints 3rd and 2nd items of X array
world is
$ awk '{c++}END{print c;}' somefile
# increase counter c on each line by one
# at the end prints out its value = number of lines in file
5

bc

An arbitrary precision calculator language.

The powerful tool with amazing set of math functionality: power calculation, exponent, sine, cosine, arctangent, natural logarithm, squared root, transform from one numeral system into another (e.g from decimal into binary, hexadecimal and vice-verse).

It's too rich, that's why i'd like to describe it briefly:

$ echo "2*3/7" | bc -l
.85714285714285714285
$ echo "10^6/4" | bc -l
# quarter of one million
250000.00000000000000000000
$ echo "l(10)" | bc -l
# natural logarithm of 10
2.30258509299404568401
# keep in mind relation  
# calculate 
$ echo "l(10)/l(2)" | bc -l
3.32192809488736234789

# converting to/from different numerical systems

$ echo "obase=16;254" | bc -l
# convert 254 to hexadecimal (output base is 16)
FE
$ echo "ibase=2;101" | bc -l
# convert from binary (input base is 2) to decimal (default)
5

Bash: Let me bash that for you, Part 0

noreply@blogger.com (Vladimir Dolzhenko) — Tue, 14 Aug 2012 18:40:00 +0000

I was going to write about some Unix-like shell hints which I usually use like grep, sed, for loop, variables and so on. I noticed that I do usually use lots of bash kung-fu beyond the shadow of a doubt.

I'm not going to start a holly war what shell is the best one - sh, ksh or whatever. I know how to cook bash tasty - it has lots in common with sh but some nuances happen.

That isn't a bash tutorial or so - it's more like commonly used hints and tips.

man anycommand

Each man has to know unix command man. That's manual, dude.

pwd

prints path of working directory

$ pwd 
/home/user

ls path

list of directory

$ ls /tmp
myfile

Hint: . (dot) in unix-like systems is current directory

$ ls .
myfile

Hint: when path isn't specified ls uses current directory

$ ls 
myfile

Hint: option -l prints a long file format with ownership info, file size and so on

$ ls -l 
-rw-r--r-- 1 user user 12 Jul  7 11:00 myfile

Hint: option -h prints file size in human readable format - Kilobytes, Megabytes etc

$ ls -lh Java\ Concurrency\ In\ Practice.pdf 
-rw-r--r-- 1 user user 3.9M May 22  2009 Java Concurrency In Practice.pdf

cd path

change directory

$ cd /tmp

cd path/of/my/destination/
Hint: I prefer use cd target/destitaton/path instead of several cd. It's much better, believe me. That's the benefit :
- cd -
  return back to previous directory in the change directory history
```
$ pwd 
/tmp
$ mkdir -p a/b/c/d/e
$ cd a/b/c/d
$ pwd
/tmp/a/b/c/d
$ cd -
$ pwd
/tmp
```
- revert search over bash command history
  It's possible to search in already executed commands using bash.
  Ctrl + r typing
  For instance
```
// Ctrl + r cd a
$ cd a/b/c/d
```
cd ~
move to home directory
```
$ cd ~
$ pwd
/home/user
```

cd
shortcut for cd ~
```
$ cd
$ pwd
/home/user
```

chown options owner:group filename(s)

changes ownership of file(s). Every file in Unix has user ownership, group and other permissions.

$ ls -la myfile
-rw-r----- 1 user user 12 Jul  7 11:00 myfile
$ chown user2 myfile
$ ls -la myfile
-rw-r----- 1 user2 user 12 Jul  7 11:00 myfile

chmod options filename(s)

changes mode file(s). Every file (in general directory is file too) in Unix has three permissions:

user (owner)
group
others

There are three types of permissions:

read = 4
write = 2
execute = 1

Two ways how to change mode:

numeric:
1st digit corresponds to user permissions.
2nd digit corresponds to group permissions.
3rd digit corresponds to other permissions.

Every digit is sum of permission type, e.g.
read + write = 4 + 2 = 6
read + write + execute = 4 + 2 + 1 = 7

Note: When change mode it doesn't keep previous permissions - permission type = 6 means that it has read + write but no executable.

Example:
```
$ chmod 640 myfile
$ ls -la myfile
-rw-r----- 1 user user 12 Jul  7 11:00 myfile
$ chmod 754 myfile
$ ls -la myfile
-rwxr-xr-- 1 user user 12 Jul  7 11:00 myfile
```
symbolic
Change permission in human readable way:
u+r grants readable permission to user
g-w removes writable permission from group

Note: In this case chmod keeps previous permissions.

$ ls -la myfile
-rwxr-xr-- 1 user user 12 Jul  7 11:00 myfile
$ chmod o-r myfile
$ ls -la myfile
-rwxr-x--- 1 user user 12 Jul  7 11:00 myfile
$ chmod g+w myfile
$ ls -la myfile
-rwxrwx--- 1 user user 12 Jul  7 11:00 myfile

Background and foreground processes

Hotkey Ctrl + z stops/resumes command execution
```
$ gzip application.log 
^Z
[1]+  Stopped                gzip application.log
```
It means that we've got job #1 which is gzip application.log has state Stopped.

jobs
get the current bash session job list

$ jobs
[1]+  Stopped                gzip application.log

fg job#
move job job# to foreground
```
$ fg 1
gzip application.log
```

bg job#
move job job# to background

$ bg 1
[1]+ gzip application.log &
$
[1]+  Done                    gzip application.log

command &
move command execution to background

$ gzip application.log &
[1] 364
$ jobs
[1]+ Running                 gzip application.log
$
[1]+  Done                   gzip application.log

wait pid
wait while background processes with pid will be finished

$ gzip application.log &
[1] 415
$ wait 415
[1]+  Done                   gzip application.log

Hint:

wait

history number-of-items

prints last number-of-items (if specified or all otherwise) executed commands.

$ history 3
  558  ls
  559  cd ~/
  560  history

Hint: to run n-th command in history use exclamation mark

$ !558
ls
file                              myfile

Hint: to run last command use double exclamation mark

$ !!
ls
file                              myfile

sleep seconds

sleep for a specified number of seconds

$ date ; sleep 5; date
Sat Jul  7 22:47:36 MSK 2012
Sat Jul  7 22:47:41 MSK 2012

Hot keys

Ctrl + a - move cursor to the beginning of the line
Ctrl + e - move cursor to the end of the line

Ctrl + u - delete from cursor position to the beginning of the line 
Ctrl + k - delete from cursor position to the end of the line 
Ctrl + w - delete from cursor position to the beginning of the word 


Ctrl + r - search in the history of executed commands

Ctrl + l - clear screen
Ctrl + d - shortcut for exit

Ctrl + z - stop/resume command background execution
Ctrl + c - cancel foreground command execution

Esc . (dot) - add last argument of last executed command

Now, let's go and conquer the world.

Принцип Дирихле

noreply@blogger.com (Vladimir Dolzhenko) — Sat, 16 Jun 2012 20:15:00 +0000

Кажется, это было ещё в седьмом классе, когда упоминался принцип Дирихле:

Если есть M предметов, которые надо разложить по N ящиков, причём M > N, тогда хотя бы в одном ящике будет более одного предмета.

К этому прилагалась задача типа: население Москвы 10 млн человек, среднее кол-во волос у человека 1.5млн, у скольких людей в мск одинаковое кол-во волос.

Сейчас я работаю в очень высоком здании, в котором много этажей и компаний - например, едет в лифте 6 человек и лифт будет останавливаться на 3 этажах. Казалось бы всё очевидно - где-то выйдет более, чем один человек.

Можно ли сказать что-то больше ? Например, что на каждом этаже выйдет по 2 человека ?

Используя метод пристального взгляда часто можно определить, что незнакомые люди работают в одной компании - как правило это либо, соблюдение ими дресс кода, либо просто то, что они друг с другом общаются.

т.о. зная что-то о специфике данных можно дать более точный и лучший ответ.

Один из наглядных примеров - упаковка доменных объектов в пачки (batches).

Так записывая каждый объект в поток напрямую мы получаем объём данных
V ~ O(N),
в то время как зная о специфике данных, о том, что это пачка, можно достигать
V >> O(N).

задачка: синие и красные в мешках

noreply@blogger.com (Vladimir Dolzhenko) — Sun, 06 May 2012 16:28:00 +0000

Есть 50 синих бумажек и 50 таких же, но красных.

Как их надо разложить по двум мешкам, чтобы человек, вытащив одну бумажку один раз из любого мешка с максимальной вероятностью вытащил синию бумажку.

внимание! комментарии содержат ответ.