echo "file fs/ubifs/io.c +fp" > /sys/kernel/debug/dynamic_debug/control
echo "file fs/ubifs/file.c +fp" > /sys/kernel/debug/dynamic_debug/control
echo "file fs/ubifs/journal.c +fp" > /sys/kernel/debug/dynamic_debug/control
root@OpenWrt:/# tmptest /overlay/upper/foo.txt
[  207.915955] write_head: UBIFS DBG jnl (pid 1242): jhead 1 (base), LEB 17:8192, len 384
[  207.931831] ubifs_wbuf_write_nolock: UBIFS DBG io (pid 1242): 384 bytes (direntry node) to jhead 1 (base) wbuf at LEB 17:8192
[  207.954457] new_wbuf_timer_nolock: UBIFS DBG io (pid 1242): set timer for jhead 1 (base), 5000-5500 millisecs
[  207.974476] do_readpage: UBIFS DBG gen (pid 1242): ino 157, pg 0, i_size 0, flags 0x1
[  207.990152] ubifs_write_end: UBIFS DBG gen (pid 1242): ino 157, pos 0, pg 0, len 5, copied 5, i_size 0
[  208.008777] ubifs_fsync: UBIFS DBG gen (pid 1242): syncing inode 157
[  208.021498] ubifs_writepage: UBIFS DBG gen (pid 1242): ino 157, pg 0, pg flags 0x1609
[  208.037157] ubifs_jnl_write_data: UBIFS DBG jnl (pid 1242): ino 157, blk 0, len 5, key (157, data, 0)
[  208.055553] write_node: UBIFS DBG jnl (pid 1242): jhead 2 (data), LEB 16:43008, len 53
[  208.071359] ubifs_wbuf_write_nolock: UBIFS DBG io (pid 1242): 53 bytes (data node) to jhead 2 (data) wbuf at LEB 16:43008
[  208.093228] new_wbuf_timer_nolock: UBIFS DBG io (pid 1242): set timer for jhead 2 (data), 5000-5500 millisecs
[  208.113116] ubifs_wbuf_sync_nolock: UBIFS DBG io (pid 1242): LEB 17:8192, 384 bytes, jhead 1 (base)
[  208.132108] ubifs_wbuf_sync_nolock: UBIFS DBG io (pid 1242): LEB 16:43008, 56 bytes, jhead 2 (data)
root@OpenWrt:/# tmptest /overlay/upper/bar.txt user.baz qux
[   73.582733] write_head: UBIFS DBG jnl (pid 1094): jhead 1 (base), LEB 17:14336, len 384
[   73.598727] ubifs_wbuf_write_nolock: UBIFS DBG io (pid 1094): 384 bytes (direntry node) to jhead 1 (base) wbuf at LEB 17:14336
[   73.621452] new_wbuf_timer_nolock: UBIFS DBG io (pid 1094): set timer for jhead 1 (base), 5000-5500 millisecs
[   73.641324] do_readpage: UBIFS DBG gen (pid 1094): ino 160, pg 0, i_size 0, flags 0x1
[   73.656947] ubifs_write_end: UBIFS DBG gen (pid 1094): ino 160, pos 0, pg 0, len 5, copied 5, i_size 0
[   73.675511] ubifs_fsync: UBIFS DBG gen (pid 1094): syncing inode 160
[   73.688191] ubifs_writepage: UBIFS DBG gen (pid 1094): ino 160, pg 0, pg flags 0x1609
[   73.703809] ubifs_jnl_write_data: UBIFS DBG jnl (pid 1094): ino 160, blk 0, len 5, key (160, data, 0)
[   73.722185] write_node: UBIFS DBG jnl (pid 1094): jhead 2 (data), LEB 16:45056, len 53
[   73.737962] ubifs_wbuf_write_nolock: UBIFS DBG io (pid 1094): 53 bytes (data node) to jhead 2 (data) wbuf at LEB 16:45056
[   73.759791] new_wbuf_timer_nolock: UBIFS DBG io (pid 1094): set timer for jhead 2 (data), 5000-5500 millisecs
[   73.779600] ubifs_wbuf_sync_nolock: UBIFS DBG io (pid 1094): LEB 17:14336, 384 bytes, jhead 1 (base)
[   73.798774] ubifs_wbuf_sync_nolock: UBIFS DBG io (pid 1094): LEB 16:45056, 56 bytes, jhead 2 (data)
[   73.817817] write_head: UBIFS DBG jnl (pid 1094): jhead 1 (base), LEB 17:16384, len 400
[   73.833756] ubifs_wbuf_write_nolock: UBIFS DBG io (pid 1094): 400 bytes (xentry node) to jhead 1 (base) wbuf at LEB 17:16384
[   73.856109] new_wbuf_timer_nolock: UBIFS DBG io (pid 1094): set timer for jhead 1 (base), 5000-5500 millisecs
[   73.875863] ubifs_wbuf_sync_nolock: UBIFS DBG io (pid 1094): LEB 17:16384, 400 bytes, jhead 1 (base)
Wrote xattr "user.baz" value "qux"
[  208.151291] write_head: UBIFS DBG jnl (pid 1242): jhead 1 (base), LEB 17:10240, len 384
[  208.167279] ubifs_wbuf_write_nolock: UBIFS DBG io (pid 1242): 384 bytes (direntry node) to jhead 1 (base) wbuf at LEB 17:10240
[  208.189993] new_wbuf_timer_nolock: UBIFS DBG io (pid 1242): set timer for jhead 1 (base), 5000-5500 millisecs
Success!
[   73.895368] write_head: UBIFS DBG jnl (pid 1094): jhead 1 (base), LEB 17:18432, len 384
[   73.913872] ubifs_wbuf_write_nolock: UBIFS DBG io (pid 1094): 384 bytes (direntry node) to jhead 1 (base) wbuf at LEB 17:18432
[   73.939282] new_wbuf_timer_nolock: UBIFS DBG io (pid 1094): set timer for jhead 1 (base), 5000-5500 millisecs
Success!
[  213.306479] wbuf_timer_callback_nolock: UBIFS DBG io (pid 0): jhead 1 (base)
[  213.320550] ubifs_bg_wbufs_sync: UBIFS DBG io (pid 388): synchronize
[  213.333467] ubifs_wbuf_sync_nolock: UBIFS DBG io (pid 388): LEB 17:10240, 384 bytes, jhead 1 (base)
[   79.317440] wbuf_timer_callback_nolock: UBIFS DBG io (pid 0): jhead 1 (base)
[   79.331506] ubifs_bg_wbufs_sync: UBIFS DBG io (pid 387): synchronize
[   79.344190] ubifs_wbuf_sync_nolock: UBIFS DBG io (pid 387): LEB 17:18432, 384 bytes, jhead 1 (base)
Power cut
root@OpenWrt:~# hexdump -v -C /overlay/upper/foo.txt 
00000000  66 6f 6f 0a 00                                    |foo..|
root@OpenWrt:~# hexdump -v -C /overlay/upper/bar.txt 
00000000  00 00 00 00 00                                    |.....|