elastio / elastio-snap

kernel module for taking block-level snapshots and incremental backups of Linux block devices
GNU General Public License v2.0
19 stars 7 forks source link

test_transition_fs_sync_cow_full sometimes crashes on Fedora 34 #236

Closed skypodolsky closed 1 year ago

skypodolsky commented 1 year ago
[  953.523451] --- test_transition_fs_sync_cow_full started ---
[  953.523529] elastio-snap: ioctl command received: 1076379905
[  953.523534] elastio-snap: received setup snap ioctl - 4 : /dev/md4 : /tmp/elastio-snap_004/cow.snap : no_ignore_errors
[  953.523559] elastio-snap: allocating device struct
[  953.523568] elastio-snap: initializing tracer
[  953.523569] elastio-snap: finding block device
[  953.523572] elastio-snap: checking block device is not already being traced
[  953.523573] elastio-snap: fetching the absolute pathname for the base device
[  953.523578] elastio-snap: calculating block device size and offset
[  953.523579] elastio-snap: bdev size = 2092928, offset = 0
[  953.523581] elastio-snap: creating cow manager
[  953.523582] elastio-snap: allocating cow manager, seqid = 1
[  953.523583] elastio-snap: creating cow file
[  953.523640] elastio-snap: allocating cow manager array (64 sections)
[  953.523642] elastio-snap: allocating cow file (52428800 bytes)
[  953.523679] elastio-snap: getting cow file extents from filp=0000000053774523
[  953.523682] elastio-snap: attempting page stealing from python3
[  953.523699] elastio-snap: fiemap for cow file (ret 0), extents 1 (max 1024)
[  953.523702] elastio-snap:    cow file extent: log 0x0, phy 0x1491000, len 52428800
[  953.523719] elastio-snap: writing cow header
[  953.524008] elastio-snap: finding cow file inode
[  953.524011] elastio-snap: getting relative pathname of cow file
[  953.524119] elastio-snap: allocating gendisk & queue
[  953.524155] elastio-snap: setting up make request function
[  953.524156] elastio-snap: setting queue limits
[  953.524158] elastio-snap: initializing gendisk
[  953.524158] elastio-snap: naming gendisk
[  953.524159] elastio-snap: block device size: 2092928
[  953.524163] elastio-snap: adding disk
[  953.524382] debugfs: Directory 'elastio-snap4' with parent 'block' already present!
[  953.524459] elastio-snap: starting mrf kernel thread
[  953.524630] elastio-snap: creating kernel cow thread
[  953.524758] elastio-snap: getting the base block device's make_request_fn
[  953.524762] elastio-snap: original mrf is not empty = 00000000af728642; orig ops = 000000007be23786
[  953.524765] elastio-snap: allocating tracing ops for device with minor 4
[  953.524770] elastio-snap: freezing 'md4'
[  953.558780] elastio-snap: starting tracing
[  953.558786] elastio-snap: thawing 'md4'
[  953.559359] elastio-snap: minor range = 4 - 4
[  953.706647] elastio-snap: ioctl command received: 10740[2061](https://github.com/elastio/elastio-snap/actions/runs/4484649547/jobs/7885376661#step:28:2062)3
[  953.706653] elastio-snap: received transition inc ioctl - 4
[  954.[2082](https://github.com/elastio/elastio-snap/actions/runs/4484649547/jobs/7885376661#step:28:2083)56] elastio-snap: failed wait for all submitted BIOs to be processed after 500 ms. bio submitted = 105, bio processed = 36
[  954.208278] elastio-snap: allocating device struct
[  954.208282] elastio-snap: initializing tracer
[  954.[2083](https://github.com/elastio/elastio-snap/actions/runs/4484649547/jobs/7885376661#step:28:2084)36] elastio-snap: creating kernel cow thread
[  954.208335] BUG: kernel NULL pointer dereference, address: 0000000000000030
[  954.208341] #PF: supervisor read access in kernel mode
[  954.[2084](https://github.com/elastio/elastio-snap/actions/runs/4484649547/jobs/7885376661#step:28:2085)12] #PF: error_code(0x0000) - not-present page
[  954.208422] PGD 0 P4D 0 
[  954.208429] Oops: 0000 [#1] PREEMPT SMP NOPTI
[  954.208442] CPU: 4 PID: 41407 Comm: elastio_snap_co Tainted: G    B   W  OE     5.17.6-100.fc34.x86_64 #1
[  954.208457] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.13.0-1ubuntu1.1 04/01/2014
[  954.208471] RIP: 0010:file_write_block+0x24c/0x320 [elastio_snap]
[  954.208488] Code: 89 ff 89 54 24 18 4c 89 54 24 10 e8 7e a2 ee e5 8b 54 24 18 4c 8b 54 24 10 39 c2 75 70 49 8b 44 24 78 4c 89 ff 4c 89 54 24 10 <48> 8b 40 30 49 89 42 18 e8 d7 9d ee e5 4c 8b 54 24 10 85 c0 0f 85
[  954.[2085](https://github.com/elastio/elastio-snap/actions/runs/4484649547/jobs/7885376661#step:28:2086)15] RSP: 0018:ffffbcafc2f8be30 EFLAGS: 00010246
[  954.208525] RAX: 0000000000000000 RBX: 0000000000000008 RCX: 0000000000000000
[  954.208537] RDX: 0000000000001000 RSI: ffffffffffffffff RDI: ffff959cfe61c800
[  954.208549] RBP: 0000000001468000 R08: 0000000000000000 R09: 0000000000001000
[  954.208559] R10: fffff92ac6499180 R11: ffff959d12646000 R12: ffff959d38196000
[  954.208570] R13: 0000000000000008 R14: ffff959cf1b32000 R15: ffff959cfe61c800
[  954.208584] FS:  0000000000000000(0000) GS:ffff959e35d00000(0000) knlGS:0000000000000000
[  954.208596] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  954.[2086](https://github.com/elastio/elastio-snap/actions/runs/4484649547/jobs/7885376661#step:28:2087)07] CR2: 0000000000000030 CR3: 000000006ae10000 CR4: 0000000000350ee0
[  954.208619] Call Trace:
[  954.208626]  <TASK>
[  954.208634]  snap_cow_thread+0x33a/0x4b0 [elastio_snap]
[  954.208646]  ? _raw_spin_unlock_irqrestore+0x25/0x40
[  954.208659]  ? do_wait_intr_irq+0xa0/0xa0
[  954.208669]  ? snap_handle_read_bio+0x540/0x540 [elastio_snap]
[  954.208680]  kthread+0xe8/0x110
[  954.208688]  ? kthread_complete_and_exit+0x20/0x20
[  954.208697]  ret_from_fork+0x22/0x30
[  954.[2087](https://github.com/elastio/elastio-snap/actions/runs/4484649547/jobs/7885376661#step:28:2088)08]  </TASK>
e-kov commented 1 year ago

kernel: 5.17.6-100.fc34.x86_64

skypodolsky commented 1 year ago

ext4 + raid + qcow2 disks

More than 100 iterations passed, no kernel crashes observed. The task is postponed.