KISS πŸ‡ΊπŸ‡¦

Stop the war!

Stop the war in Ukraine! Fuck putin!

More information is at: https://war.ukraine.ua/.

There is a fund to support the Ukrainian Army: https://savelife.in.ua/en/donate/, and there is a special bank account that accepts funds in multiple currencies: https://bank.gov.ua/en/about/support-the-armed-forces. I donated to them. Please donate if you can!

Killer putin

Killer putin. Source: politico.eu.

Arrested putin

"It hasn't happened yet, but it will happen sooner or later. Beautiful photo, isn't it?" Source: twitter.

Threads synchronization by logging

| comments

Hi! Today I’d like to write a small note/reminder about a subtle and unintended threads synchronization “feature” by using a shared object, for instance logger. The example will be in Java, and you can check it out with your favorite language (not to say that Java is mine).

To get started, you can git clone https://github.com/pluton8/java_concurrency_examples.git to get the described classes. We’re interested in the e201_sequence_notsynchronizedlist and e202_sequence_notsynchronizedlist_logging classes. As the doc states, it is

A very contrived yet simple example of a Sequence class producing increasing natural numbers with each nextNumber() call. Two Worker threads get the numbers, sharing the same instance, and add them to a shared List. After they’ve added a certain number of numbers, the main object checks if all the numbers in the list are increasing uniformly.

When you run the first version you can get such an output:

1
2

Result: [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 45, 44, 46, null, null, 48, 50, 51, 52, 53, 54, 55, 56, 57, 58, 59, 60, 61, 62, 63, 64, 65, 66, 67, 68, 69, 70, 71, 72, 73, 74, 75, 76, 77, 78, 79, 80, 81, 82, 83, 84, 85, 86, 87, 88, 89, 90, 91, 92, 93, 94, 95, 96, 97]
First incorrect number @index 46: 45

or even more interesting one:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

Exception in thread "Worker0" java.lang.ArrayIndexOutOfBoundsException: 10
Result: [null, null, null, 0, 4, 5, 6, 6, 7, 8, null, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50]
    at java.util.ArrayList.add(ArrayList.java:441)
    at e201_sequence_notsynchronizedlist.addNumber(e201_sequence_notsynchronizedlist.java:47)
    at e201_sequence_notsynchronizedlist$Worker.run(e201_sequence_notsynchronizedlist.java:37)
    at java.lang.Thread.run(Thread.java:744)
Exception in thread "main" java.lang.NullPointerException
    at e201_sequence_notsynchronizedlist.firstIncorrectNumberIndex(e201_sequence_notsynchronizedlist.java:53)
    at e201_sequence_notsynchronizedlist.processResults(e201_sequence_notsynchronizedlist.java:65)
    at e201_sequence_notsynchronizedlist.main(e201_sequence_notsynchronizedlist.java:88)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:120)

In any case, you can notice a number of nulls in the numbers list. Where did they come from? Our Sequence’s nextNumber() method can only produce incrementing numbers. Let’s check the return values of the method in the console by adding the simple logging line here (line 36):

1
2
3

final Long number = sequence.nextNumber();
System.out.println(number);
addNumber(number);

The result is class e202_sequence_notsynchronizedlist_logging. No way! I run this version a few dozen of times and never got a null in the list:

1
2

Result: [0, 1, 2, 4, 5, 6, 7, 8, 9, 3, 10, 11, 12, 14, 15, 16, 13, 17, 19, 20, 21, 22, 23, 18, 24, 26, 27, 28, 25, 29, 31, 32, 33, 34, 30, 35, 37, 38, 39, 40, 41, 36, 42, 44, 45, 46, 47, 48, 49, 50, 43, 51, 53, 54, 55, 56, 57, 58, 59, 52, 60, 61, 62, 63, 64, 65, 66, 67, 68, 69, 70, 71, 72, 73, 74, 75, 76, 77, 78, 79, 80, 81, 82, 83, 84, 85, 86, 87, 88, 89, 90, 91, 92, 93, 94, 95, 96, 97, 98, 99]
First incorrect number @index 3: 4

What happened? It’s this phenomenon when using a shared object, the console output stream in this case, implicitly creates a lock and gets rid of the synchronization issue. However, you should never use such a technique, because it’s not obvious and logging could be on in debug (no runtime issues) and off in release (users will face issues).

Remember about it and don’t fall for it. Concurrency is not an easy topic, and the only way to master it is practice.

Comments