Re: 'rbd map' asynchronous behavior
Hi, Newer kernel rbd driver throws a quite strange messages on map|unmap, comparing to 3.2 branch: rbd map 'path' # device appears as /dev/rbd1 instead of rbd0, then rbd unmap /dev/rbd1 # causes following trace, w/ vanilla 3.4.0 from kernel.org: [ 99.700802] BUG: scheduling while atomic: rbd/3846/0x0002 [ 99.700857] Modules linked in: btrfs ip6table_filter ip6_tables iptable_filter ip_tables ebtable_nat ebtables x_tables iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi fuse nfsd nfs nfs_acl auth_rpcgss lockd sunrpc kvm_intel kvm bridge stp llc ipv6 rbd libceph loop 8250_pnp pcspkr firewire_ohci coretemp firewire_core hwmon 8250 serial_core [ 99.700899] Pid: 3846, comm: rbd Not tainted 3.4.0 #3 [ 99.700902] Call Trace: [ 99.700910] [81464d68] ? __schedule+0x96/0x625 [ 99.700916] [8105f98a] ? __queue_work+0x254/0x27c [ 99.700921] [81465d39] ? _raw_spin_lock_irqsave+0x2a/0x32 [ 99.700926] [81069b6d] ? complete+0x31/0x40 [ 99.700931] [8105f10a] ? flush_workqueue_prep_cwqs+0x16e/0x180 [ 99.700947] [81463bd8] ? schedule_timeout+0x21/0x1af [ 99.700951] [8107165d] ? enqueue_entity+0x67/0x13d [ 99.700955] [81464ad9] ? wait_for_common+0xc5/0x143 [ 99.700959] [8106d5fc] ? try_to_wake_up+0x217/0x217 [ 99.700963] [81063952] ? kthread_stop+0x30/0x50 [ 99.700967] [81060979] ? destroy_workqueue+0x148/0x16b [ 99.700977] [a004ce07] ? ceph_osdc_stop+0x1f/0xaa [libceph] [ 99.700984] [a00463b4] ? ceph_destroy_client+0x10/0x44 [libceph] [ 99.700989] [a00652ae] ? rbd_client_release+0x38/0x4b [rbd] [ 99.700993] [a0065719] ? rbd_put_client.isra.10+0x28/0x3d [rbd] [ 99.700998] [a006609d] ? rbd_dev_release+0xc3/0x157 [rbd] [ 99.701003] [81287387] ? device_release+0x41/0x72 [ 99.701007] [81202b95] ? kobject_release+0x4e/0x6a [ 99.701025] [a0065156] ? rbd_remove+0x102/0x11e [rbd] [ 99.701035] [8114b058] ? sysfs_write_file+0xd3/0x10f [ 99.701044] [810f8796] ? vfs_write+0xaa/0x136 [ 99.701052] [810f8a07] ? sys_write+0x45/0x6e [ 99.701062] [8146a839] ? system_call_fastpath+0x16/0x1b [ 99.701170] BUG: scheduling while atomic: rbd/3846/0x0002 [ 99.701220] Modules linked in: btrfs ip6table_filter ip6_tables iptable_filter ip_tables ebtable_nat ebtables x_tables iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi fuse nfsd nfs nfs_acl auth_rpcgss lockd sunrpc kvm_intel kvm bridge stp llc ipv6 rbd libceph loop 8250_pnp pcspkr firewire_ohci coretemp firewire_core hwmon 8250 serial_core [ 99.701251] Pid: 3846, comm: rbd Not tainted 3.4.0 #3 [ 99.701253] Call Trace: [ 99.701257] [81464d68] ? __schedule+0x96/0x625 [ 99.701261] [81465ef9] ? _raw_spin_unlock_irq+0x5/0x2e [ 99.701265] [81069f92] ? finish_task_switch+0x4c/0xc1 [ 99.701268] [8146525b] ? __schedule+0x589/0x625 [ 99.701272] [812084b2] ? ip4_string+0x5a/0xc8 [ 99.701276] [81208cbd] ? string.isra.3+0x39/0x9f [ 99.701281] [81208e33] ? ip4_addr_string.isra.5+0x5a/0x76 [ 99.701285] [81208b7a] ? number.isra.1+0x10e/0x218 [ 99.701290] [81463bd8] ? schedule_timeout+0x21/0x1af [ 99.701294] [81464ad9] ? wait_for_common+0xc5/0x143 [ 99.701298] [8106d5fc] ? try_to_wake_up+0x217/0x217 [ 99.701303] [8105f24c] ? flush_workqueue+0x130/0x2a5 [ 99.701309] [a00463b9] ? ceph_destroy_client+0x15/0x44 [libceph] [ 99.701314] [a00652ae] ? rbd_client_release+0x38/0x4b [rbd] [ 99.701319] [a0065719] ? rbd_put_client.isra.10+0x28/0x3d [rbd] [ 99.701324] [a006609d] ? rbd_dev_release+0xc3/0x157 [rbd] [ 99.701328] [81287387] ? device_release+0x41/0x72 [ 99.701334] [81202b95] ? kobject_release+0x4e/0x6a [ 99.701343] [a0065156] ? rbd_remove+0x102/0x11e [rbd] [ 99.701352] [8114b058] ? sysfs_write_file+0xd3/0x10f [ 99.701361] [810f8796] ? vfs_write+0xaa/0x136 [ 99.701369] [810f8a07] ? sys_write+0x45/0x6e [ 99.701377] [8146a839] ? system_call_fastpath+0x16/0x1b On Wed, May 16, 2012 at 12:24 PM, Andrey Korolyov and...@xdel.ru wrote: This is most likely due to a recently-fixed problem. The fix is found in this commit, although there were other changes that led up to it: 32eec68d2f rbd: don't drop the rbd_id too early It is present starting in Linux kernel 3.3; it appears you are running 2.6? Nope, it`s just Debian kernel naming - they continue to name 3.x with 2.6 and I`m following them at own build naming. I have tried that on 3.2 first time, and just a couple of minutes ago on my notebook with 3.3.4 over relatively slow vpn connection - rbd failed with almost same backtrace(I have removed sleep from cycle and bug has been reproduce immediately after first map-unmap) and kernel
Re: 'rbd map' asynchronous behavior
That looks like a bug that isn't familiar to Josh or I. Can you create a report in the tracker and provide as much debug info as you can come up with? :) On Friday, May 25, 2012 at 3:15 AM, Andrey Korolyov wrote: Hi, Newer kernel rbd driver throws a quite strange messages on map|unmap, comparing to 3.2 branch: rbd map 'path' # device appears as /dev/rbd1 instead of rbd0, then rbd unmap /dev/rbd1 # causes following trace, w/ vanilla 3.4.0 from kernel.org (http://kernel.org): [ 99.700802] BUG: scheduling while atomic: rbd/3846/0x0002 [ 99.700857] Modules linked in: btrfs ip6table_filter ip6_tables iptable_filter ip_tables ebtable_nat ebtables x_tables iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi fuse nfsd nfs nfs_acl auth_rpcgss lockd sunrpc kvm_intel kvm bridge stp llc ipv6 rbd libceph loop 8250_pnp pcspkr firewire_ohci coretemp firewire_core hwmon 8250 serial_core [ 99.700899] Pid: 3846, comm: rbd Not tainted 3.4.0 #3 [ 99.700902] Call Trace: [ 99.700910] [81464d68] ? __schedule+0x96/0x625 [ 99.700916] [8105f98a] ? __queue_work+0x254/0x27c [ 99.700921] [81465d39] ? _raw_spin_lock_irqsave+0x2a/0x32 [ 99.700926] [81069b6d] ? complete+0x31/0x40 [ 99.700931] [8105f10a] ? flush_workqueue_prep_cwqs+0x16e/0x180 [ 99.700947] [81463bd8] ? schedule_timeout+0x21/0x1af [ 99.700951] [8107165d] ? enqueue_entity+0x67/0x13d [ 99.700955] [81464ad9] ? wait_for_common+0xc5/0x143 [ 99.700959] [8106d5fc] ? try_to_wake_up+0x217/0x217 [ 99.700963] [81063952] ? kthread_stop+0x30/0x50 [ 99.700967] [81060979] ? destroy_workqueue+0x148/0x16b [ 99.700977] [a004ce07] ? ceph_osdc_stop+0x1f/0xaa [libceph] [ 99.700984] [a00463b4] ? ceph_destroy_client+0x10/0x44 [libceph] [ 99.700989] [a00652ae] ? rbd_client_release+0x38/0x4b [rbd] [ 99.700993] [a0065719] ? rbd_put_client.isra.10+0x28/0x3d [rbd] [ 99.700998] [a006609d] ? rbd_dev_release+0xc3/0x157 [rbd] [ 99.701003] [81287387] ? device_release+0x41/0x72 [ 99.701007] [81202b95] ? kobject_release+0x4e/0x6a [ 99.701025] [a0065156] ? rbd_remove+0x102/0x11e [rbd] [ 99.701035] [8114b058] ? sysfs_write_file+0xd3/0x10f [ 99.701044] [810f8796] ? vfs_write+0xaa/0x136 [ 99.701052] [810f8a07] ? sys_write+0x45/0x6e [ 99.701062] [8146a839] ? system_call_fastpath+0x16/0x1b [ 99.701170] BUG: scheduling while atomic: rbd/3846/0x0002 [ 99.701220] Modules linked in: btrfs ip6table_filter ip6_tables iptable_filter ip_tables ebtable_nat ebtables x_tables iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi fuse nfsd nfs nfs_acl auth_rpcgss lockd sunrpc kvm_intel kvm bridge stp llc ipv6 rbd libceph loop 8250_pnp pcspkr firewire_ohci coretemp firewire_core hwmon 8250 serial_core [ 99.701251] Pid: 3846, comm: rbd Not tainted 3.4.0 #3 [ 99.701253] Call Trace: [ 99.701257] [81464d68] ? __schedule+0x96/0x625 [ 99.701261] [81465ef9] ? _raw_spin_unlock_irq+0x5/0x2e [ 99.701265] [81069f92] ? finish_task_switch+0x4c/0xc1 [ 99.701268] [8146525b] ? __schedule+0x589/0x625 [ 99.701272] [812084b2] ? ip4_string+0x5a/0xc8 [ 99.701276] [81208cbd] ? string.isra.3+0x39/0x9f [ 99.701281] [81208e33] ? ip4_addr_string.isra.5+0x5a/0x76 [ 99.701285] [81208b7a] ? number.isra.1+0x10e/0x218 [ 99.701290] [81463bd8] ? schedule_timeout+0x21/0x1af [ 99.701294] [81464ad9] ? wait_for_common+0xc5/0x143 [ 99.701298] [8106d5fc] ? try_to_wake_up+0x217/0x217 [ 99.701303] [8105f24c] ? flush_workqueue+0x130/0x2a5 [ 99.701309] [a00463b9] ? ceph_destroy_client+0x15/0x44 [libceph] [ 99.701314] [a00652ae] ? rbd_client_release+0x38/0x4b [rbd] [ 99.701319] [a0065719] ? rbd_put_client.isra.10+0x28/0x3d [rbd] [ 99.701324] [a006609d] ? rbd_dev_release+0xc3/0x157 [rbd] [ 99.701328] [81287387] ? device_release+0x41/0x72 [ 99.701334] [81202b95] ? kobject_release+0x4e/0x6a [ 99.701343] [a0065156] ? rbd_remove+0x102/0x11e [rbd] [ 99.701352] [8114b058] ? sysfs_write_file+0xd3/0x10f [ 99.701361] [810f8796] ? vfs_write+0xaa/0x136 [ 99.701369] [810f8a07] ? sys_write+0x45/0x6e [ 99.701377] [8146a839] ? system_call_fastpath+0x16/0x1b On Wed, May 16, 2012 at 12:24 PM, Andrey Korolyov and...@xdel.ru (mailto:and...@xdel.ru) wrote: This is most likely due to a recently-fixed problem. The fix is found in this commit, although there were other changes that led up to it: 32eec68d2f rbd: don't drop the rbd_id too early It is present starting in Linux kernel 3.3; it appears you are running 2.6? Nope, it`s just Debian kernel naming - they continue to name 3.x with 2.6 and I`m following them at own build naming. I have tried that on 3.2 first time, and just a couple of minutes ago on
Re: 'rbd map' asynchronous behavior
This is most likely due to a recently-fixed problem. The fix is found in this commit, although there were other changes that led up to it: 32eec68d2f rbd: don't drop the rbd_id too early It is present starting in Linux kernel 3.3; it appears you are running 2.6? Nope, it`s just Debian kernel naming - they continue to name 3.x with 2.6 and I`m following them at own build naming. I have tried that on 3.2 first time, and just a couple of minutes ago on my notebook with 3.3.4 over relatively slow vpn connection - rbd failed with almost same backtrace(I have removed sleep from cycle and bug has been reproduce immediately after first map-unmap) and kernel has panicked after approx. four minutes when I stopped 'for...' execution, unfortunately no bt of panic because of X and lack of configured netconsole :) The symptoms are the same - 'rbd showmapped' shows latest volume, but unmap failed with 'xxx is not a block device remove failed: (22) Invalid argument' and a couple of 'null pointer dereference' messages in dmesg. I have used /dev/rbd0 instead of symlinks to reduce probability of involving udev-related timeout on symlinks creation. On Tue, May 15, 2012 at 7:40 PM, Josh Durgin josh.dur...@inktank.com wrote: On 05/15/2012 04:49 AM, Andrey Korolyov wrote: Hi, There are strange bug when I tried to map excessive amounts of block devices inside the pool, like following for vol in $(rbd ls); do rbd map $vol; [some-microsleep]; [some operation or nothing, I have stubbed guestfs mount here] ; [some-microsleep]; unmap /dev/rbd/rbd/$vol ; [some-microsleep]; done, udev or rbd seems to be somehow late and mapping fails. There is no real-world harm at all, and such case can be easily avoided, but on busy cluster timeout increases and I was able to catch same thing on two-osd config in recovering state. For 0.1 second on healthy cluster, all works okay, for 0.05 it may fail with following trace(just for me, because I am testing on relatively old and crappy hardware, so others may catch that on smaller intervals): udev is asynchronous by nature. The rbd tool itself doesn't wait for /dev to be populated because you may not be using the default udev rule (or not using udev at all). Our test framework polls for the device to make sure 'rbd map' and udev completed: https://github.com/ceph/teuthology/blob/d6b9bd8b63c8c6c1181ece1f6941829d8d1d5152/teuthology/task/rbd.py#L190 Josh -- To unsubscribe from this list: send the line unsubscribe ceph-devel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
'rbd map' asynchronous behavior
Hi, There are strange bug when I tried to map excessive amounts of block devices inside the pool, like following for vol in $(rbd ls); do rbd map $vol; [some-microsleep]; [some operation or nothing, I have stubbed guestfs mount here] ; [some-microsleep]; unmap /dev/rbd/rbd/$vol ; [some-microsleep]; done, udev or rbd seems to be somehow late and mapping fails. There is no real-world harm at all, and such case can be easily avoided, but on busy cluster timeout increases and I was able to catch same thing on two-osd config in recovering state. For 0.1 second on healthy cluster, all works okay, for 0.05 it may fail with following trace(just for me, because I am testing on relatively old and crappy hardware, so others may catch that on smaller intervals): [ 2130.450044] libceph: client0 fsid 70204128-4328-47e7-9df7-c7253c833fc1 [ 2130.450643] libceph: mon0 192.168.10.129:6789 session established [ 2130.454542] rbd0: p1 p2 [ 2130.454772] rbd: rbd0: added with size 0x8000 [ 2137.783484] libceph: client0 fsid 70204128-4328-47e7-9df7-c7253c833fc1 [ 2137.784095] libceph: mon0 192.168.10.129:6789 session established [ 2137.787801] rbd0: p1 p2 [ 2137.788028] rbd: rbd0: added with size 0x7d00 [ 2138.044490] [ cut here ] [ 2138.044499] WARNING: at /build/kernel/linux-2.6-3.2.15/debian/build/source_amd64_none/fs/sysfs/dir.c:481 sysfs_add_one+0x83/0x96() [ 2138.044503] Hardware name: System Product Name [ 2138.044505] sysfs: cannot create duplicate filename '/devices/virtual/block/rbd0' [ 2138.044508] Modules linked in: ip6table_filter ip6_tables iptable_filter acpi_cpufreq mperf ip_tables cpufreq_powersave ebtable_nat cpufreq_userspace ebtables x_tables cpufreq_conservative cpufreq_stats cn microcode ib_iser rdma_cm ib_addr iw_cm ib_cm ib_sa ib_mad ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi fuse nfsd nfs nfs_acl auth_rpcgss fscache lockd sunrpc kvm_intel kvm bridge stp ext2 rbd libceph coretemp tcp_yeah tcp_vegas loop dm_crypt snd_hda_codec_realtek nvidia(P) snd_hda_intel snd_hda_codec snd_hwdep nv_tco snd_pcm psmouse i2c_nforce2 i2c_core snd_page_alloc evdev serio_raw snd_timer snd pcspkr soundcore processor button asus_atk0110 ext4 crc16 jbd2 mbcache btrfs crc32c libcrc32c zlib_deflate dm_mod sd_mod sr_mod cdrom crc_t10dif ohci_hcd ata_generic pata_amd sata_nv ehci_hcd libata fan forcedeth thermal thermal_sys scsi_mod usbcore usb_common [last unloaded: scsi_wait_scan] [ 2138.044607] Pid: 16891, comm: rbd Tainted: P O 3.2.0-2-amd64 #1 [ 2138.044610] Call Trace: [ 2138.044616] [81046811] ? warn_slowpath_common+0x78/0x8c [ 2138.044620] [810468bd] ? warn_slowpath_fmt+0x45/0x4a [ 2138.044624] [8114e918] ? sysfs_add_one+0x83/0x96 [ 2138.044628] [8114e991] ? create_dir+0x66/0xa0 [ 2138.044631] [8114ea66] ? sysfs_create_dir+0x85/0x9b [ 2138.044636] [811afb6b] ? vsnprintf+0x7c/0x427 [ 2138.044640] [811a9aa2] ? kobject_add_internal+0xc8/0x181 [ 2138.044643] [811a9e77] ? kobject_add+0x95/0xa4 [ 2138.044647] [810363c7] ? should_resched+0x5/0x23 [ 2138.044651] [811a99d5] ? kobject_get+0x12/0x17 [ 2138.044655] [8119ccb4] ? get_disk+0x8d/0x8d [ 2138.044659] [8124bd13] ? device_add+0xd6/0x587 [ 2138.044663] [8124ad4e] ? dev_set_name+0x42/0x47 [ 2138.044667] [8119d8db] ? register_disk+0x37/0x147 [ 2138.044670] [8119ce48] ? blk_register_region+0x22/0x27 [ 2138.044674] [8119db6b] ? add_disk+0x180/0x26c [ 2138.044681] [a0e994d0] ? rbd_add+0x7b2/0xa32 [rbd] [ 2138.044685] [810363c7] ? should_resched+0x5/0x23 [ 2138.044689] [8114d477] ? sysfs_write_file+0xe0/0x11c [ 2138.044693] [810f92a7] ? vfs_write+0xa2/0xe9 [ 2138.044697] [810f9484] ? sys_write+0x45/0x6b [ 2138.044701] [8134e492] ? system_call_fastpath+0x16/0x1b [ 2138.044704] ---[ end trace b7a29490cafc363d ]--- [ 2138.044708] kobject_add_internal failed for rbd0 with -EEXIST, don't try to register things with the same name in the same directory. [ 2138.044723] Pid: 16891, comm: rbd Tainted: PW O 3.2.0-2-amd64 #1 [ 2138.044725] Call Trace: [ 2138.044729] [811a9b31] ? kobject_add_internal+0x157/0x181 [ 2138.044733] [811a9e77] ? kobject_add+0x95/0xa4 [ 2138.044736] [810363c7] ? should_resched+0x5/0x23 [ 2138.044740] [811a99d5] ? kobject_get+0x12/0x17 [ 2138.044743] [8119ccb4] ? get_disk+0x8d/0x8d [ 2138.044746] [8124bd13] ? device_add+0xd6/0x587 [ 2138.044750] [8124ad4e] ? dev_set_name+0x42/0x47 [ 2138.044757] [8119d8db] ? register_disk+0x37/0x147 [ 2138.044760] [8119ce48] ? blk_register_region+0x22/0x27 [ 2138.044763] [8119db6b] ? add_disk+0x180/0x26c [ 2138.044769] [a0e994d0] ? rbd_add+0x7b2/0xa32 [rbd] [ 2138.044772] [810363c7] ? should_resched+0x5/0x23 [ 2138.044776] [8114d477] ?
Re: 'rbd map' asynchronous behavior
On 05/15/2012 06:49 AM, Andrey Korolyov wrote: Hi, There are strange bug when I tried to map excessive amounts of block devices inside the pool, like following for vol in $(rbd ls); do rbd map $vol; [some-microsleep]; [some operation or nothing, I have stubbed guestfs mount here] ; [some-microsleep]; unmap /dev/rbd/rbd/$vol ; [some-microsleep]; done, This is most likely due to a recently-fixed problem. The fix is found in this commit, although there were other changes that led up to it: 32eec68d2f rbd: don't drop the rbd_id too early It is present starting in Linux kernel 3.3; it appears you are running 2.6? -Alex udev or rbd seems to be somehow late and mapping fails. There is no real-world harm at all, and such case can be easily avoided, but on busy cluster timeout increases and I was able to catch same thing on two-osd config in recovering state. For 0.1 second on healthy cluster, all works okay, for 0.05 it may fail with following trace(just for me, because I am testing on relatively old and crappy hardware, so others may catch that on smaller intervals): [ 2130.450044] libceph: client0 fsid 70204128-4328-47e7-9df7-c7253c833fc1 [ 2130.450643] libceph: mon0 192.168.10.129:6789 session established [ 2130.454542] rbd0: p1 p2 [ 2130.454772] rbd: rbd0: added with size 0x8000 [ 2137.783484] libceph: client0 fsid 70204128-4328-47e7-9df7-c7253c833fc1 [ 2137.784095] libceph: mon0 192.168.10.129:6789 session established [ 2137.787801] rbd0: p1 p2 [ 2137.788028] rbd: rbd0: added with size 0x7d00 [ 2138.044490] [ cut here ] [ 2138.044499] WARNING: at /build/kernel/linux-2.6-3.2.15/debian/build/source_amd64_none/fs/sysfs/dir.c:481 sysfs_add_one+0x83/0x96() [ 2138.044503] Hardware name: System Product Name [ 2138.044505] sysfs: cannot create duplicate filename '/devices/virtual/block/rbd0' [ 2138.044508] Modules linked in: ip6table_filter ip6_tables iptable_filter acpi_cpufreq mperf ip_tables cpufreq_powersave ebtable_nat cpufreq_userspace ebtables x_tables cpufreq_conservative cpufreq_stats cn microcode ib_iser rdma_cm ib_addr iw_cm ib_cm ib_sa ib_mad ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi fuse nfsd nfs nfs_acl auth_rpcgss fscache lockd sunrpc kvm_intel kvm bridge stp ext2 rbd libceph coretemp tcp_yeah tcp_vegas loop dm_crypt snd_hda_codec_realtek nvidia(P) snd_hda_intel snd_hda_codec snd_hwdep nv_tco snd_pcm psmouse i2c_nforce2 i2c_core snd_page_alloc evdev serio_raw snd_timer snd pcspkr soundcore processor button asus_atk0110 ext4 crc16 jbd2 mbcache btrfs crc32c libcrc32c zlib_deflate dm_mod sd_mod sr_mod cdrom crc_t10dif ohci_hcd ata_generic pata_amd sata_nv ehci_hcd libata fan forcedeth thermal thermal_sys scsi_mod usbcore usb_common [last unloaded: scsi_wait_scan] [ 2138.044607] Pid: 16891, comm: rbd Tainted: P O 3.2.0-2-amd64 #1 [ 2138.044610] Call Trace: [ 2138.044616] [81046811] ? warn_slowpath_common+0x78/0x8c [ 2138.044620] [810468bd] ? warn_slowpath_fmt+0x45/0x4a [ 2138.044624] [8114e918] ? sysfs_add_one+0x83/0x96 [ 2138.044628] [8114e991] ? create_dir+0x66/0xa0 [ 2138.044631] [8114ea66] ? sysfs_create_dir+0x85/0x9b [ 2138.044636] [811afb6b] ? vsnprintf+0x7c/0x427 [ 2138.044640] [811a9aa2] ? kobject_add_internal+0xc8/0x181 [ 2138.044643] [811a9e77] ? kobject_add+0x95/0xa4 [ 2138.044647] [810363c7] ? should_resched+0x5/0x23 [ 2138.044651] [811a99d5] ? kobject_get+0x12/0x17 [ 2138.044655] [8119ccb4] ? get_disk+0x8d/0x8d [ 2138.044659] [8124bd13] ? device_add+0xd6/0x587 [ 2138.044663] [8124ad4e] ? dev_set_name+0x42/0x47 [ 2138.044667] [8119d8db] ? register_disk+0x37/0x147 [ 2138.044670] [8119ce48] ? blk_register_region+0x22/0x27 [ 2138.044674] [8119db6b] ? add_disk+0x180/0x26c [ 2138.044681] [a0e994d0] ? rbd_add+0x7b2/0xa32 [rbd] [ 2138.044685] [810363c7] ? should_resched+0x5/0x23 [ 2138.044689] [8114d477] ? sysfs_write_file+0xe0/0x11c [ 2138.044693] [810f92a7] ? vfs_write+0xa2/0xe9 [ 2138.044697] [810f9484] ? sys_write+0x45/0x6b [ 2138.044701] [8134e492] ? system_call_fastpath+0x16/0x1b [ 2138.044704] ---[ end trace b7a29490cafc363d ]--- [ 2138.044708] kobject_add_internal failed for rbd0 with -EEXIST, don't try to register things with the same name in the same directory. [ 2138.044723] Pid: 16891, comm: rbd Tainted: PW O 3.2.0-2-amd64 #1 [ 2138.044725] Call Trace: [ 2138.044729] [811a9b31] ? kobject_add_internal+0x157/0x181 [ 2138.044733] [811a9e77] ? kobject_add+0x95/0xa4 [ 2138.044736] [810363c7] ? should_resched+0x5/0x23 [ 2138.044740] [811a99d5] ? kobject_get+0x12/0x17 [ 2138.044743] [8119ccb4] ? get_disk+0x8d/0x8d [ 2138.044746] [8124bd13] ? device_add+0xd6/0x587 [ 2138.044750] [8124ad4e] ?
Re: 'rbd map' asynchronous behavior
On 05/15/2012 04:49 AM, Andrey Korolyov wrote: Hi, There are strange bug when I tried to map excessive amounts of block devices inside the pool, like following for vol in $(rbd ls); do rbd map $vol; [some-microsleep]; [some operation or nothing, I have stubbed guestfs mount here] ; [some-microsleep]; unmap /dev/rbd/rbd/$vol ; [some-microsleep]; done, udev or rbd seems to be somehow late and mapping fails. There is no real-world harm at all, and such case can be easily avoided, but on busy cluster timeout increases and I was able to catch same thing on two-osd config in recovering state. For 0.1 second on healthy cluster, all works okay, for 0.05 it may fail with following trace(just for me, because I am testing on relatively old and crappy hardware, so others may catch that on smaller intervals): udev is asynchronous by nature. The rbd tool itself doesn't wait for /dev to be populated because you may not be using the default udev rule (or not using udev at all). Our test framework polls for the device to make sure 'rbd map' and udev completed: https://github.com/ceph/teuthology/blob/d6b9bd8b63c8c6c1181ece1f6941829d8d1d5152/teuthology/task/rbd.py#L190 Josh -- To unsubscribe from this list: send the line unsubscribe ceph-devel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
