iocb->ki_pos != pos

[Bernd Schubert <bschubert@q-leap.de>]

Hi,

for our customers we are porting lustre to more recent kernel versions and a
customer just run into a bug, which probably I introduced (wrote the
ll_file_aio_write() function). For me it looks more like a generic vfs
problem than a lustre problem, so I'm asking here.

The trace is 

generic_file_aio_write_nolock()
ll_file_aio_write()
do_sync_write() 
ll_file_write()

In do_sync_write() the call is 
        ret = filp->f_op->aio_write(&kiocb, &iov, 1, kiocb.ki_pos);

later on in generic_file_aio_write() it runs into
        BUG_ON(iocb->ki_pos != pos);

In ll_file_aio_write() we only do some lustre locking and lock
inode->i_mutex and then already call generic_file_aio_write_nolock().

I'm now wondering how iocb->ki_pos can be different from pos. Some locking
missing?


Thanks a lot in advance,
Bernd


[166319.275484] ------------[ cut here ]------------
[166319.280281] kernel BUG at mm/filemap.c:2358!
[166319.284777] invalid opcode: 0000 [1] SMP
[166319.289052] CPU 0
[166319.291313] Modules linked in: xt_multiport osc llite lov lquota mdc 
ksocklnd ko2iblnd rdma_cm ib_cm iw_cm ib_addr ptlrpc obdclass lnet lvfs 
libcfs crc32 iptable_filter ipt_MASQUERADE xt_tcpudp iptable_nat nf_nat 
nf_conntrack_ipv4 nf_conntrack ip_tables x_tables ib_ipoib ib_sa 
w83627hf lm85 hwmon_vid i2c_isa pl2303 usbserial ohci_hcd i2c_amd8111 
i2c_amd756 tg3 usbcore k8_edac edac_mc i2c_core ib_mthca ib_mad ib_core
[166319.331360] Pid: 27292, comm: mv Not tainted 2.6.20.11 #1
[166319.337309] RIP: 0010:[<ffffffff8025018c>]  [<ffffffff8025018c>] 
generic_file_aio_write_nolock+0x24/0x80
[166319.347390] RSP: 0018:ffff8100e4befc48  EFLAGS: 00010212
[166319.353244] RAX: 00000000008da7a4 RBX: 0000000000000000 RCX: 
00000000008da784
[166319.361046] RDX: 0000000000000001 RSI: ffff8100e4befe38 RDI: 
ffff8100e4befd48
[166319.368861] RBP: ffff8100cb600598 R08: 0000000000000000 R09: 
ffff8100404a19c0
[166319.376611] R10: ffff8100e4befce8 R11: 0000000000000000 R12: 
ffff8100b1c852c0
[166319.384371] R13: ffff8100cb6006a8 R14: 00000000008da784 R15: 
000007ffffffc000
[166319.392231] FS:  00002b0de3a766d0(0000) GS:ffffffff80671000(0000) 
knlGS:00000000f7b0b6c0
[166319.401026] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[166319.407296] CR2: 00002b0de37f23d0 CR3: 0000000023c76000 CR4: 
00000000000006e0
[166319.415097] Process mv (pid: 27292, threadinfo ffff8100e4bee000, 
task ffff8100d22df180)
[166319.423850] Stack:  0000000000000000 0000000000000004 
ffff8100cb600598 ffff8100b1c852c0
[166319.432632]  ffff8100e4befdc8 ffffffff88337efd 0000000000000000 
0000000000000000
[166319.440793]  ffffffff883686d2 00000000059a2812 ffff8100a594af1c 
ffff8100cb600598
[166319.448551] Call Trace:
[166319.451456]  [<ffffffff88337efd>] :llite:ll_file_aio_write+0x4fc/0x623
[166319.458442]  [<ffffffff802712f0>] do_sync_write+0xc8/0x10b
[166319.464338]  [<ffffffff8023ccd5>] autoremove_wake_function+0x0/0x2e
[166319.471145]  [<ffffffff88360838>] :llite:ll_tree_lock+0x1d5/0x2cf
[166319.477652]  [<ffffffff8835fa86>] :llite:ll_node_from_inode+0x102/0x244
[166319.484724]  [<ffffffff883378ea>] :llite:ll_file_write+0x4b6/0x5cd
[166319.491320]  [<ffffffff802713e3>] vfs_write+0xb0/0x153
[166319.496894]  [<ffffffff80271539>] sys_write+0x45/0x6e
[166319.502442]  [<ffffffff802096ae>] system_call+0x7e/0x83
[166319.508164]
[166319.509868]
[166319.509868] Code: 0f 0b eb fe 48 8d 8f 80 00 00 00 e8 87 fb ff ff 48 
85 c0 48
[166319.519805] RIP  [<ffffffff8025018c>] 
generic_file_aio_write_nolock+0x24/0x80
[166319.527563]  RSP <ffff8100e4befc48>
[166319.531868]