Why is LiveData onChanged called before data change is made?

Question

Context

Using MutableLiveData to hold a value. Button click should increment the value.

Problem

MutableLiveData's Observer.onChanged() appears to be called before MutableLiveData.setValue() is used to change the value.

For example, before Button click, onChanged log happens after initial value is set (onChanged nanoseconds is greater than new value nanoseconds) . However, after Button click, onChanged log happens before new value is set (onChanged nanoseconds is less than new value nanoseconds). Why does this happen?:

Before Button click (onChanged log expectedly happens after setting initial val):

09-06 20:30:47.877 com.example.android.test D/TAG: initial set val ns 102107899222617
    initial get val ns 102107899367096
09-06 20:30:47.882 com.example.android.test D/TAG: onChanged integer 0 ns 102107903996992

After Button click (onChanged log unexpectedly happens before setting new val):

09-06 20:30:55.372 com.example.android.test D/TAG: onChanged integer 1 ns 102115394178238
09-06 20:30:55.373 com.example.android.test D/TAG: onClick set new val 1 ns 102115394446415

Code

final MutableLiveData<Integer> val = new MutableLiveData<>();
val.setValue(0); // triggers onChanged
Log.d(TAG, "initial set val ns " + System.nanoTime());

tv.setText("" + val.getValue());
Log.d(TAG, "initial get val ns " + System.nanoTime());

val.observe(this, new Observer<Integer>() {
    @Override
    public void onChanged(@Nullable Integer integer) {
        // onChanged happens after initial setValue but before setValue with new value
        Log.d(TAG, "onChanged integer " + integer + " ns " + System.nanoTime());
        tv.setText("" + integer);
    }
});

btn.setOnClickListener(new View.OnClickListener() {
    @Override
    public void onClick(View v) {
        // setting new value (triggers onChanged but 
        // onChanged happens before setting new value via setValue)
        int newVal = val.getValue() + 1;
        val.setValue(newVal);
        Log.d(TAG, "onClick set new val " + newVal + " ns " + System.nanoTime());
    }
});

Answer 1

As @pskink pointed out, the problem was placement of the log for setting new value, logging before and after the MutableLiveValue.setValue() made it clear:

Add before and after logs:

final MutableLiveData<Integer> val = new MutableLiveData<Integer>() {
    @Override
    public void setValue(Integer value) {
        Log.d(TAG, "setValue before");
        super.setValue(value);
        Log.d(TAG, "setValue after");
    }
};

After Button click (onChanged log expectedly happens after setValue):

09-06 20:52:02.869 com.example.android.test D/TAG: onClick: before set new val
    setValue before
09-06 20:52:02.870 com.example.android.test D/TAG: onChanged integer 1 ns 103382891472200
    setValue after
    onClick after set new val 1 ns 103382891671576

Edit

The reason logging after setValue happened after onChanged is because onChanged is called at some point in setValue.