Issues with qemu-img, libgfapi, and encryption at rest

[Ziemowit Pierzycki]

Hi,

Encryption-at-rest has been supported for some time now. The client is responsible for encrypting the files with a help of a master key file. I have a properly setup environment and everything appears to be working fine but when I use qemu-img to move a file to gluster I get the following:

# qemu-img convert -f raw -O raw linux.iso gluster://gluster01/virt0/linux.raw
[2017-06-06 16:52:25.489720] E [mem-pool.c:579:mem_put] (-->/lib64/libglusterfs.so.0(syncop_lookup+0x4e5) [0x7f30f7a36d35] -->/lib64/libglusterfs.so.0(+0x59f02) [0x7f30f7a32f02] -->/lib64/libglusterfs.so.0(mem_put+0x190) [0x7f30f7a24a60] ) 0-mem-pool: mem-pool ptr is NULL
[2017-06-06 16:52:25.490778] E [mem-pool.c:579:mem_put] (-->/lib64/libglusterfs.so.0(syncop_lookup+0x4e5) [0x7f30f7a36d35] -->/lib64/libglusterfs.so.0(+0x59f02) [0x7f30f7a32f02] -->/lib64/libglusterfs.so.0(mem_put+0x190) [0x7f30f7a24a60] ) 0-mem-pool: mem-pool ptr is NULL
[2017-06-06 16:52:25.492263] E [mem-pool.c:579:mem_put] (-->/lib64/libglusterfs.so.0(syncop_lookup+0x4e5) [0x7f30f7a36d35] -->/lib64/libglusterfs.so.0(+0x59f02) [0x7f30f7a32f02] -->/lib64/libglusterfs.so.0(mem_put+0x190) [0x7f30f7a24a60] ) 0-mem-pool: mem-pool ptr is NULL
[2017-06-06 16:52:25.497226] E [mem-pool.c:579:mem_put] (-->/lib64/libglusterfs.so.0(syncop_create+0x44d) [0x7f30f7a3cf5d] -->/lib64/libglusterfs.so.0(+0x59f02) [0x7f30f7a32f02] -->/lib64/libglusterfs.so.0(mem_put+0x190) [0x7f30f7a24a60] ) 0-mem-pool: mem-pool ptr is NULL

On and on until I get this message:

[2017-06-06 17:00:03.467361] E [MSGID: 108006] [afr-common.c:4409:afr_notify] 0-virt0-replicate-0: All subvolumes are down. Going offline until atleast one of them comes back up.
[2017-06-06 17:00:03.467442] E [MSGID: 108006] [afr-common.c:4409:afr_notify] 0-virt0-replicate-1: All subvolumes are down. Going offline until atleast one of them comes back up.

I asked for help assuming it's a problem with glusterfs and was told it appears qemu-img's implementation of libgfapi doesn't call the xlator function correctly.

[Ziemowit Pierzycki (ziemowit)]

I'm using Fedora 24 with version:

qemu-img 2.6.2
glusterfs-api-3.8.12

[Thomas Huth (th-huth)]

When reporting bugs to the QEMU project, please always try with the latest release first (distros are often not shipping the latest version). So can you please try with the latest release of QEMU (currently version 2.9.0)?

[Ziemowit Pierzycki (ziemowit)]

Just upgraded to 2.9.0 and actually I see a different issue:

# qemu-img convert -O raw fedora.iso gluster://dalpinfglt04/virt0/fedora6.raw
[2017-06-07 16:52:43.300902] C [rpc-clnt-ping.c:160:rpc_clnt_ping_timer_expired] 0-virt0-client-2: server 172.19.38.42:49152 has not responded in the last 42 seconds, disconnecting.
[2017-06-07 17:02:44.342745] E [rpc-clnt.c:365:saved_frames_unwind] (--> /lib64/libglusterfs.so.0(_gf_log_callingfn+0x17d)[0x7f78c3e4fe6d] (--> /lib64/libgfrpc.so.0(saved_frames_unwind+0x1d1)[0x7f78c3c169a1] (--> /lib64/libgfrpc.so.0(saved_frames_destroy+0xe)[0x7f78c3c16abe] (--> /lib64/libgfrpc.so.0(rpc_clnt_connection_cleanup+0x87)[0x7f78c3c18157] (--> /lib64/libgfrpc.so.0(rpc_clnt_notify+0x288)[0x7f78c3c18c28] ))))) 0-virt0-client-2: forced unwinding frame type(GlusterFS 3.3) op(WRITE(13)) called at 2017-06-07 16:52:00.618744 (xid=0x1c)
[2017-06-07 17:02:44.342952] E [rpc-clnt.c:365:saved_frames_unwind] (--> /lib64/libglusterfs.so.0(_gf_log_callingfn+0x17d)[0x7f78c3e4fe6d] (--> /lib64/libgfrpc.so.0(saved_frames_unwind+0x1d1)[0x7f78c3c169a1] (--> /lib64/libgfrpc.so.0(saved_frames_destroy+0xe)[0x7f78c3c16abe] (--> /lib64/libgfrpc.so.0(rpc_clnt_connection_cleanup+0x87)[0x7f78c3c18157] (--> /lib64/libgfrpc.so.0(rpc_clnt_notify+0x288)[0x7f78c3c18c28] ))))) 0-virt0-client-2: forced unwinding frame type(GF-DUMP) op(NULL(2)) called at 2017-06-07 16:52:00.618753 (xid=0x1d)
[2017-06-07 17:02:44.343415] E [MSGID: 114031] [client-rpc-fops.c:1593:client3_3_finodelk_cbk] 0-virt0-client-2: remote operation failed [Transport endpoint is not connected]
[2017-06-07 17:08:49.367264] C [rpc-clnt-ping.c:160:rpc_clnt_ping_timer_expired] 0-virt0-client-3: server 172.19.38.43:49152 has not responded in the last 42 seconds, disconnecting.
[2017-06-07 17:13:29.969206] E [rpc-clnt.c:365:saved_frames_unwind] (--> /lib64/libglusterfs.so.0(_gf_log_callingfn+0x17d)[0x7f78c3e4fe6d] (--> /lib64/libgfrpc.so.0(saved_frames_unwind+0x1d1)[0x7f78c3c169a1] (--> /lib64/libgfrpc.so.0(saved_frames_destroy+0xe)[0x7f78c3c16abe] (--> /lib64/libgfrpc.so.0(rpc_clnt_connection_cleanup+0x87)[0x7f78c3c18157] (--> /lib64/libgfrpc.so.0(rpc_clnt_notify+0x288)[0x7f78c3c18c28] ))))) 0-virt0-client-3: forced unwinding frame type(GlusterFS 3.3) op(WRITE(13)) called at 2017-06-07 17:08:06.371259 (xid=0x22)
[2017-06-07 17:13:29.969250] E [MSGID: 114031] [client-rpc-fops.c:1593:client3_3_finodelk_cbk] 0-virt0-client-3: remote operation failed [Transport endpoint is not connected]
[2017-06-07 17:13:29.969355] E [rpc-clnt.c:365:saved_frames_unwind] (--> /lib64/libglusterfs.so.0(_gf_log_callingfn+0x17d)[0x7f78c3e4fe6d] (--> /lib64/libgfrpc.so.0(saved_frames_unwind+0x1d1)[0x7f78c3c169a1] (--> /lib64/libgfrpc.so.0(saved_frames_destroy+0xe)[0x7f78c3c16abe] (--> /lib64/libgfrpc.so.0(rpc_clnt_connection_cleanup+0x87)[0x7f78c3c18157] (--> /lib64/libgfrpc.so.0(rpc_clnt_notify+0x288)[0x7f78c3c18c28] ))))) 0-virt0-client-3: forced unwinding frame type(GF-DUMP) op(NULL(2)) called at 2017-06-07 17:08:06.371268 (xid=0x23)
[2017-06-07 17:13:29.972665] E [MSGID: 108008] [afr-transaction.c:2619:afr_write_txn_refresh_done] 0-virt0-replicate-1: Failing FSETXATTR on gfid 86042280-9ae1-444f-8342-be4442f8...

[Thomas Huth (th-huth)]

This is an automated cleanup. This bug report has been moved to QEMU's
new bug tracker on gitlab.com and thus gets marked as 'expired' now.
Please continue with the discussion here:

 https://gitlab.com/qemu-project/qemu/-/issues/145