Re: [systemd-devel] what does --ephemeral really do on btrfs?

2015-07-03 Thread Elias Probst
Looks like I shouldn't have announced success that early.

Even on a fresh raw-backed machines btrfs volume, I'm running into problems.

What I did:
# re-create btrfs volume
machinectl set-limit 6G

# built a mininmal CentOS7.1 image (yum.conf below):
yum -c /tmp/yum.conf groupinstall Base

# yum.conf
[main]
reposdir=/dev/null
gpgcheck=0
logfile=/var/log/yum.log
installroot=/var/lib/machines/centos7.1-base
assumeyes=1

[base]
name=CentOS 7.1.1503 - x86_64
baseurl=http://mirror.centos.org/centos/7.1.1503/os/x86_64/
enabled=1

# tried to create a new machine using the centos7.1-base as template
systemd-nspawn --template=/var/lib/machines/centos7.1-base -bD
/var/lib/machines/storage-test

The result is the same again… hanging 'btrfs-transacti':
kernel: INFO: task btrfs-transacti:3603 blocked for more than 120 seconds.
kernel:   Not tainted 4.1.0-gentoo #4
kernel: echo 0  /proc/sys/kernel/hung_task_timeout_secs disables this
message.
kernel: btrfs-transacti D 88007ac6f8a8 0  3603  2 0x0080
kernel:  88007ac6f8a8 8802361e02d0 88007db44390 0246
kernel:  88007ac7 88020f11f1e0 88007db44390 88007ac6f8f8
kernel:  88007db44390 88007ac6f8c8 95963329 
kernel: Call Trace:
kernel:  [95963329] schedule+0x74/0x83
kernel:  [953e44eb] btrfs_tree_read_lock+0xc0/0xea
kernel:  [951346bd] ? wait_woken+0x74/0x74
kernel:  [95395c6d] btrfs_search_old_slot+0x509/0x7fc
kernel:  [9538fc41] ? __tree_mod_log_oldest_root.isra.20+0x46/0x67
kernel:  [9540587b] __resolve_indirect_refs+0x192/0x5d9
kernel:  [953d0c46] ? release_extent_buffer+0x34/0xb1
kernel:  [953d105f] ? free_extent_buffer+0x6e/0x7a
kernel:  [95406905] find_parent_nodes+0xb28/0xfaa
kernel:  [95406e19] __btrfs_find_all_roots+0x92/0xf0
kernel:  [95406ed3] btrfs_find_all_roots+0x45/0x65
kernel:  [95391387] ? btrfs_get_tree_mod_seq+0x72/0x86
kernel:  [9540ad70] btrfs_delayed_qgroup_accounting+0x32b/0x962
kernel:  [953a58e4] btrfs_run_delayed_refs+0x185/0x210
kernel:  [953b3e0a] btrfs_commit_transaction+0x47/0xaf0
kernel:  [953b4c5a] ? start_transaction+0x3a7/0x52a
kernel:  [953b0550] transaction_kthread+0xfa/0x1d0
kernel:  [953b0456] ? btrfs_cleanup_transaction+0x498/0x498
kernel:  [9511b44d] kthread+0xcd/0xd5
kernel:  [9512] ?
ftrace_raw_output_sched_migrate_task+0x7f/0x7f
kernel:  [9511b380] ? kthread_create_on_node+0x17a/0x17a
kernel:  [95967d62] ret_from_fork+0x42/0x70
kernel:  [9511b380] ? kthread_create_on_node+0x17a/0x17a
kernel: INFO: task kworker/u8:7:28547 blocked for more than 120 seconds.
kernel:   Not tainted 4.1.0-gentoo #4
kernel: echo 0  /proc/sys/kernel/hung_task_timeout_secs disables this
message.
kernel: kworker/u8:7D 88010051f9b8 0 28547  2 0x0080
kernel: Workqueue: btrfs-delayed-meta btrfs_delayed_meta_helper
kernel:  88010051f9b8 95e04460 880178028090 0246
kernel:  88010052 8801086ac308 88020f11f178 880108789010
kernel:  015b 88010051f9d8 95963329 
kernel: Call Trace:
kernel:  [95963329] schedule+0x74/0x83
kernel:  [953e478f] btrfs_tree_lock+0xa7/0x1b7
kernel:  [951346bd] ? wait_woken+0x74/0x74


On 07/03/2015 01:31 PM, Elias Probst wrote:
 On 07/02/2015 07:22 AM, Johannes Ernst wrote:
 Mine takes an awful long time — blocking IO on the device in the awful long 
 meantime — and I’m puzzled why. Does it perhaps copy (deep? references 
 only?) the entire drive? 

 
 I've seen a similar issue here which was caused by a obviously corrupted
 btrfs volume.
 'systemd-nspawn' and 'btrfs-transacti' consumed a full CPU core and
 never stopped doing so - they were just stuck there.
 
 After enabling CONFIG_HANGCHECK_TIMER=y in my Kernel I was able to get
 some more information out of it:
 
 kernel: INFO: task kworker/u8:2:213 blocked for more than 120 seconds.
 kernel:   Not tainted 4.1.0-gentoo #4
 kernel: echo 0  /proc/sys/kernel/hung_task_timeout_secs disables this
 message.
 kernel: kworker/u8:2D 8802344d3978 0   213  2 0x
 kernel: Workqueue: writeback bdi_writeback_workfn (flush-btrfs-1)
 kernel:  8802344d3978 8802361ee350 880234ad8390 0246
 kernel:  8802344d4000 8801f5296ae0 8802344d3a80 8802304ac000
 kernel:  880001447300 8802344d3998 94963329 
 kernel: Call Trace:
 kernel:  [94963329] schedule+0x74/0x83
 kernel:  [943e478f] btrfs_tree_lock+0xa7/0x1b7
 kernel:  [941346bd] ? wait_woken+0x74/0x74
 kernel:  [943d03eb] lock_extent_buffer_for_io+0x39/0x199
 kernel:  [943d1371] btree_write_cache_pages+0x306/0x35d
 kernel:  [943ad2db] btree_writepages+0x1e/0x5d
 kernel:  [941ad9b9] 

Re: [systemd-devel] what does --ephemeral really do on btrfs?

2015-07-03 Thread Lennart Poettering
On Fri, 03.07.15 13:31, Elias Probst (m...@eliasprobst.eu) wrote:

 On 07/02/2015 07:22 AM, Johannes Ernst wrote:
  Mine takes an awful long time — blocking IO on the device in the awful long 
  meantime — and I’m puzzled why. Does it perhaps copy (deep? references 
  only?) the entire drive? 
  
 
 I've seen a similar issue here which was caused by a obviously corrupted
 btrfs volume.
 'systemd-nspawn' and 'btrfs-transacti' consumed a full CPU core and
 never stopped doing so - they were just stuck there.

 Didn't get a reply in #btrfs regarding this yet and didn't get around
 yet to raise this on the btrfs ML.

Yeah, please report this on the kernel bugzilla and/or the btrfs ML!

Lennart

-- 
Lennart Poettering, Red Hat
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] what does --ephemeral really do on btrfs?

2015-07-03 Thread Lennart Poettering
On Wed, 01.07.15 22:22, Johannes Ernst (johannes.er...@gmail.com) wrote:

 If I run systemd-nspawn with —ephemeral, it creates a new temporary
 btrfs subvolume, the documentation says.

Correct.

 Mine takes an awful long time — blocking IO on the device in the
 awful long meantime — and I’m puzzled why. Does it perhaps copy
 (deep? references only?) the entire drive?

If the path you specifiy is not a btrfs subvolume itself then the code
falls back to doing a deep copy into into a new btrfs subvolume.

 Should I put the original directory on a separate subvolume, or how
 can I speed this up? If I just copied the image / directory, this
 might be faster.

Yes, if the source is a subvolume of its own the code can take a
snapshot efficiently. If it is just a normal subdir, then it has to
copy.

Lennart

-- 
Lennart Poettering, Red Hat
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] what does --ephemeral really do on btrfs?

2015-07-03 Thread Elias Probst
On 07/02/2015 07:22 AM, Johannes Ernst wrote:
 Mine takes an awful long time — blocking IO on the device in the awful long 
 meantime — and I’m puzzled why. Does it perhaps copy (deep? references only?) 
 the entire drive? 
 

I've seen a similar issue here which was caused by a obviously corrupted
btrfs volume.
'systemd-nspawn' and 'btrfs-transacti' consumed a full CPU core and
never stopped doing so - they were just stuck there.

After enabling CONFIG_HANGCHECK_TIMER=y in my Kernel I was able to get
some more information out of it:

kernel: INFO: task kworker/u8:2:213 blocked for more than 120 seconds.
kernel:   Not tainted 4.1.0-gentoo #4
kernel: echo 0  /proc/sys/kernel/hung_task_timeout_secs disables this
message.
kernel: kworker/u8:2D 8802344d3978 0   213  2 0x
kernel: Workqueue: writeback bdi_writeback_workfn (flush-btrfs-1)
kernel:  8802344d3978 8802361ee350 880234ad8390 0246
kernel:  8802344d4000 8801f5296ae0 8802344d3a80 8802304ac000
kernel:  880001447300 8802344d3998 94963329 
kernel: Call Trace:
kernel:  [94963329] schedule+0x74/0x83
kernel:  [943e478f] btrfs_tree_lock+0xa7/0x1b7
kernel:  [941346bd] ? wait_woken+0x74/0x74
kernel:  [943d03eb] lock_extent_buffer_for_io+0x39/0x199
kernel:  [943d1371] btree_write_cache_pages+0x306/0x35d
kernel:  [943ad2db] btree_writepages+0x1e/0x5d
kernel:  [941ad9b9] do_writepages+0x19/0x27
kernel:  [9420d42d] __writeback_single_inode+0x4e/0x258
kernel:  [9420d804] writeback_sb_inodes+0x1cd/0x35a
kernel:  [9420da0b] __writeback_inodes_wb+0x7a/0xb3
kernel:  [9420dbeb] wb_writeback+0x10d/0x256
kernel:  [941acb92] ? bdi_dirty_limit+0x2c/0x8c
kernel:  [9420e27f] bdi_writeback_workfn+0x1a1/0x352
kernel:  [94116b4b] process_one_work+0x1d5/0x364
kernel:  [9411756e] worker_thread+0x2d2/0x3f4
kernel:  [9411729c] ? cancel_delayed_work_sync+0x10/0x10
kernel:  [9411b44d] kthread+0xcd/0xd5
kernel:  [9412] ?
ftrace_raw_output_sched_migrate_task+0x7f/0x7f
kernel:  [9411b380] ? kthread_create_on_node+0x17a/0x17a
kernel:  [94967d62] ret_from_fork+0x42/0x70
kernel:  [9411b380] ? kthread_create_on_node+0x17a/0x17a
kernel: INFO: task btrfs-transacti:2020 blocked for more than 120 seconds.
kernel:   Not tainted 4.1.0-gentoo #4
kernel: echo 0  /proc/sys/kernel/hung_task_timeout_secs disables this
message.
kernel: btrfs-transacti D 8802347838a8 0  2020  2 0x0080
kernel:  8802347838a8 8802361e02d0 88023477a350 0246
kernel:  880234784000 8801f5296ae0 88023477a350 8802347838f8
kernel:  88023477a350 8802347838c8 94963329 
kernel: Call Trace:
kernel:  [94963329] schedule+0x74/0x83
kernel:  [943e44eb] btrfs_tree_read_lock+0xc0/0xea
kernel:  [941346bd] ? wait_woken+0x74/0x74
kernel:  [94395c6d] btrfs_search_old_slot+0x509/0x7fc
kernel:  [9440587b] __resolve_indirect_refs+0x192/0x5d9
kernel:  [943e43e5] ? btrfs_clear_lock_blocking_rw+0x78/0xbe
kernel:  [943d0c46] ? release_extent_buffer+0x34/0xb1
kernel:  [943d105f] ? free_extent_buffer+0x6e/0x7a
kernel:  [94406905] find_parent_nodes+0xb28/0xfaa
kernel:  [94406e19] __btrfs_find_all_roots+0x92/0xf0
kernel:  [94406ed3] btrfs_find_all_roots+0x45/0x65
kernel:  [94391387] ? btrfs_get_tree_mod_seq+0x72/0x86
kernel:  [9440ad70] btrfs_delayed_qgroup_accounting+0x32b/0x962
kernel:  [943a58e4] btrfs_run_delayed_refs+0x185/0x210
kernel:  [943b3e0a] btrfs_commit_transaction+0x47/0xaf0
kernel:  [943b4c5a] ? start_transaction+0x3a7/0x52a
kernel:  [943b0550] transaction_kthread+0xfa/0x1d0
kernel:  [943b0456] ? btrfs_cleanup_transaction+0x498/0x498
kernel:  [9411b44d] kthread+0xcd/0xd5
kernel:  [9412] ?
ftrace_raw_output_sched_migrate_task+0x7f/0x7f
kernel:  [9411b380] ? kthread_create_on_node+0x17a/0x17a
kernel:  [94967d62] ret_from_fork+0x42/0x70
kernel:  [9411b380] ? kthread_create_on_node+0x17a/0x17a


In this state, I was even unable to fully copy away my machines into a
tarball which just ended up in

tar: Unexpected EOF in archive
tar: Unexpected EOF in archive
tar: Error is not recoverable: exiting now

and

gzip: stdin: unexpected end of file


Didn't get a reply in #btrfs regarding this yet and didn't get around
yet to raise this on the btrfs ML.

I unmounted the machine volume (which was just backed by a raw image on
my ext4 root volume), moved the raw volume file away for possible later
analysis and recreated the volume from scratch (machinectl set-limit 6G).


- Elias



signature.asc
Description: OpenPGP digital signature
___
systemd-devel mailing list

[systemd-devel] what does --ephemeral really do on btrfs?

2015-07-01 Thread Johannes Ernst
If I run systemd-nspawn with —ephemeral, it creates a new temporary btrfs 
subvolume, the documentation says.

Mine takes an awful long time — blocking IO on the device in the awful long 
meantime — and I’m puzzled why. Does it perhaps copy (deep? references only?) 
the entire drive? 

Should I put the original directory on a separate subvolume, or how can I speed 
this up? If I just copied the image / directory, this might be faster.

Thanks,



Johannes.

___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel