Lindsay Mathieson
2016-Apr-27 07:55 UTC
[Gluster-users] FIle size error when restoring backups causes restore failure.
I'm getting the following file size error when restoring proxmox qemu backups via gfapi. I don't think the issue is with proxmox as I have tested the same restore process with other storages with no problem(nfs, cephfs, ceph rbd). Also if I restore the the gluster *fuse* mount it works ok. Have tested with: performance.stat-prefetch: off performance.strict-write-ordering: on still same problem. This is with sharded storage - as soon as I some time I'll test with non-shared storage. Error is bolded at the end of the logging restore vma archive: lzop -d -c /mnt/nas-backups-smb/dump/vzdump-qemu-910-2016_04_23-08_22_07.vma.lzo|vma extract -v -r /var/tmp/vzdumptmp8999.fifo - /var/tmp/vzdumptmp8999 CFG: size: 391 name: qemu-server.conf DEV: dev_id=1 size: 34359738368 devname: drive-scsi0 CTIME: Sat Apr 23 08:22:11 2016 [2016-04-27 07:02:21.688878] I [MSGID: 104045] [glfs-master.c:95:notify] 0-gfapi: New graph 766e622d-3930-3033-2d32-3031362d3034 (0) coming up [2016-04-27 07:02:21.688921] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-0: parent translators are ready, attempting connect on transport [2016-04-27 07:02:21.689530] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-1: parent translators are ready, attempting connect on transport [2016-04-27 07:02:21.689793] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-0: changing port to 49156 (from 0) [2016-04-27 07:02:21.689951] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-2: parent translators are ready, attempting connect on transport [2016-04-27 07:02:21.690608] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-0: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:21.690977] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-1: changing port to 49155 (from 0) [2016-04-27 07:02:21.691032] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-0: Connected to datastore4-client-0, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:21.691068] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-0: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:21.691148] I [MSGID: 108005] [afr-common.c:4007:afr_notify] 0-datastore4-replicate-0: Subvolume 'datastore4-client-0' came back up; going online. [2016-04-27 07:02:21.691235] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-0: Server lk version = 1 [2016-04-27 07:02:21.691430] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-2: changing port to 49155 (from 0) [2016-04-27 07:02:21.691867] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-1: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:21.692350] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-1: Connected to datastore4-client-1, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:21.692369] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-1: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:21.692474] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-2: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:21.692590] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-1: Server lk version = 1 [2016-04-27 07:02:21.692926] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-2: Connected to datastore4-client-2, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:21.692942] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-2: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:21.708641] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-2: Server lk version = 1 [2016-04-27 07:02:21.709796] I [MSGID: 108031] [afr-common.c:1900:afr_local_discovery_cbk] 0-datastore4-replicate-0: selecting local read_child datastore4-client-0 [2016-04-27 07:02:21.710401] I [MSGID: 104041] [glfs-resolve.c:869:__glfs_active_subvol] 0-datastore4: switched to graph 766e622d-3930-3033-2d32-3031362d3034 (0) [2016-04-27 07:02:21.828061] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-0: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:21.828125] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-1: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:21.828140] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-0: disconnected from datastore4-client-0. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:21.828163] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-2: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:21.828181] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-1: disconnected from datastore4-client-1. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:21.828205] W [MSGID: 108001] [afr-common.c:4090:afr_notify] 0-datastore4-replicate-0: Client-quorum is not met [2016-04-27 07:02:21.828235] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-2: disconnected from datastore4-client-2. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:21.828248] E [MSGID: 108006] [afr-common.c:4046:afr_notify] 0-datastore4-replicate-0: All subvolumes are down. Going offline until atleast one of them comes back up. [2016-04-27 07:02:21.828442] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=84 max=3 total=3 [2016-04-27 07:02:21.829252] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=156 max=5 total=5 [2016-04-27 07:02:21.830686] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=108 max=1 total=1 [2016-04-27 07:02:21.830733] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=588 max=3 total=24 [2016-04-27 07:02:21.830747] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=124 max=3 total=24 [2016-04-27 07:02:21.830765] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=1300 max=2 total=13 [2016-04-27 07:02:21.830781] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=588 max=3 total=24 [2016-04-27 07:02:21.830856] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=124 max=3 total=24 [2016-04-27 07:02:21.830872] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=1300 max=3 total=13 [2016-04-27 07:02:21.830887] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=588 max=4 total=24 [2016-04-27 07:02:21.830899] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=124 max=4 total=24 [2016-04-27 07:02:21.830912] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=1300 max=2 total=13 [2016-04-27 07:02:21.830978] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-replicate-0: size=10524 max=2 total=13 [2016-04-27 07:02:21.831173] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=1148 max=0 total=0 [2016-04-27 07:02:21.831240] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=2284 max=2 total=9 [2016-04-27 07:02:21.831373] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-shard: size=1396 max=1 total=7 [2016-04-27 07:02:21.831392] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-readdir-ahead: size=52 max=0 total=0 [2016-04-27 07:02:21.831406] I [io-stats.c:2951:fini] 0-datastore4: io-stats translator unloaded [2016-04-27 07:02:21.831467] I [MSGID: 101191] [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with index 1 [2016-04-27 07:02:21.831493] I [MSGID: 101191] [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with index 2 [2016-04-27 07:02:22.688831] I [MSGID: 104045] [glfs-master.c:95:notify] 0-gfapi: New graph 766e622d-3930-3033-2d32-3031362d3034 (0) coming up [2016-04-27 07:02:22.688873] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-0: parent translators are ready, attempting connect on transport [2016-04-27 07:02:22.689466] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-1: parent translators are ready, attempting connect on transport [2016-04-27 07:02:22.689732] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-0: changing port to 49156 (from 0) [2016-04-27 07:02:22.689879] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-2: parent translators are ready, attempting connect on transport [2016-04-27 07:02:22.690547] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-0: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:22.690803] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-1: changing port to 49155 (from 0) [2016-04-27 07:02:22.690923] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-0: Connected to datastore4-client-0, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:22.690945] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-0: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:22.691002] I [MSGID: 108005] [afr-common.c:4007:afr_notify] 0-datastore4-replicate-0: Subvolume 'datastore4-client-0' came back up; going online. [2016-04-27 07:02:22.691033] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-0: Server lk version = 1 [2016-04-27 07:02:22.691486] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-2: changing port to 49155 (from 0) [2016-04-27 07:02:22.691749] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-1: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:22.692262] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-1: Connected to datastore4-client-1, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:22.692279] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-1: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:22.692489] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-2: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:22.692497] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-1: Server lk version = 1 [2016-04-27 07:02:22.693084] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-2: Connected to datastore4-client-2, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:22.693102] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-2: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:22.708424] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-2: Server lk version = 1 [2016-04-27 07:02:22.709613] I [MSGID: 108031] [afr-common.c:1900:afr_local_discovery_cbk] 0-datastore4-replicate-0: selecting local read_child datastore4-client-0 [2016-04-27 07:02:22.710086] I [MSGID: 104041] [glfs-resolve.c:869:__glfs_active_subvol] 0-datastore4: switched to graph 766e622d-3930-3033-2d32-3031362d3034 (0) [2016-04-27 07:02:22.850510] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-0: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:22.850579] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-1: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:22.850598] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-0: disconnected from datastore4-client-0. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:22.850634] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-1: disconnected from datastore4-client-1. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:22.850639] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-2: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:22.850679] W [MSGID: 108001] [afr-common.c:4090:afr_notify] 0-datastore4-replicate-0: Client-quorum is not met [2016-04-27 07:02:22.850705] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-2: disconnected from datastore4-client-2. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:22.850718] E [MSGID: 108006] [afr-common.c:4046:afr_notify] 0-datastore4-replicate-0: All subvolumes are down. Going offline until atleast one of them comes back up. [2016-04-27 07:02:22.850832] W [inode.c:1792:inode_table_destroy] (-->/usr/lib/x86_64-linux-gnu/libgfapi.so.0(glfs_fini+0x3f9) [0x7f4f48434239] -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy_all+0x4e) [0x7f4f481a584e] -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy+0xe3) [0x7f4f481a5753] ) 0-gfapi: Active inode(0x7f4f334002cc) with refcount(1) found during cleanup [2016-04-27 07:02:22.851009] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=84 max=4 total=4 [2016-04-27 07:02:22.851785] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=156 max=5 total=5 [2016-04-27 07:02:22.853155] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=108 max=2 total=2 [2016-04-27 07:02:22.853203] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=588 max=3 total=47 [2016-04-27 07:02:22.853220] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=124 max=3 total=47 [2016-04-27 07:02:22.853239] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=1300 max=2 total=32 [2016-04-27 07:02:22.853257] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=588 max=4 total=46 [2016-04-27 07:02:22.853271] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=124 max=4 total=46 [2016-04-27 07:02:22.853287] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=1300 max=3 total=32 [2016-04-27 07:02:22.853305] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=588 max=4 total=46 [2016-04-27 07:02:22.853387] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=124 max=4 total=46 [2016-04-27 07:02:22.853407] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=1300 max=3 total=32 [2016-04-27 07:02:22.853424] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-replicate-0: size=10524 max=3 total=25 [2016-04-27 07:02:22.853598] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=1148 max=0 total=0 [2016-04-27 07:02:22.853660] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=2284 max=3 total=17 [2016-04-27 07:02:22.853841] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-shard: size=1396 max=1 total=8 [2016-04-27 07:02:22.853863] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-readdir-ahead: size=52 max=0 total=0 [2016-04-27 07:02:22.853879] I [io-stats.c:2951:fini] 0-datastore4: io-stats translator unloaded [2016-04-27 07:02:22.853951] I [MSGID: 101191] [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with index 1 [2016-04-27 07:02:22.853951] I [MSGID: 101191] [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with index 2 [2016-04-27 07:02:23.694923] I [MSGID: 104045] [glfs-master.c:95:notify] 0-gfapi: New graph 766e622d-3930-3033-2d32-3031362d3034 (0) coming up [2016-04-27 07:02:23.694967] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-0: parent translators are ready, attempting connect on transport [2016-04-27 07:02:23.695603] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-1: parent translators are ready, attempting connect on transport [2016-04-27 07:02:23.695866] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-0: changing port to 49156 (from 0) [2016-04-27 07:02:23.696034] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-2: parent translators are ready, attempting connect on transport [2016-04-27 07:02:23.696707] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-0: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:23.696940] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-1: changing port to 49155 (from 0) [2016-04-27 07:02:23.697128] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-0: Connected to datastore4-client-0, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:23.697148] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-0: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:23.697220] I [MSGID: 108005] [afr-common.c:4007:afr_notify] 0-datastore4-replicate-0: Subvolume 'datastore4-client-0' came back up; going online. [2016-04-27 07:02:23.697319] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-0: Server lk version = 1 [2016-04-27 07:02:23.697510] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-2: changing port to 49155 (from 0) [2016-04-27 07:02:23.697770] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-1: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:23.698338] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-1: Connected to datastore4-client-1, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:23.698358] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-1: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:23.698451] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-2: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:23.698560] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-1: Server lk version = 1 [2016-04-27 07:02:23.698993] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-2: Connected to datastore4-client-2, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:23.699012] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-2: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:23.714625] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-2: Server lk version = 1 [2016-04-27 07:02:23.715924] I [MSGID: 108031] [afr-common.c:1900:afr_local_discovery_cbk] 0-datastore4-replicate-0: selecting local read_child datastore4-client-0 [2016-04-27 07:02:23.716481] I [MSGID: 104041] [glfs-resolve.c:869:__glfs_active_subvol] 0-datastore4: switched to graph 766e622d-3930-3033-2d32-3031362d3034 (0) [2016-04-27 07:02:26.752833] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-0: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:26.752896] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-1: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:26.752913] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-0: disconnected from datastore4-client-0. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:26.752938] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-2: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:26.752945] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-1: disconnected from datastore4-client-1. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:26.752968] W [MSGID: 108001] [afr-common.c:4090:afr_notify] 0-datastore4-replicate-0: Client-quorum is not met [2016-04-27 07:02:26.752972] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-2: disconnected from datastore4-client-2. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:26.752988] E [MSGID: 108006] [afr-common.c:4046:afr_notify] 0-datastore4-replicate-0: All subvolumes are down. Going offline until atleast one of them comes back up. [2016-04-27 07:02:26.753114] W [inode.c:1792:inode_table_destroy] (-->/usr/lib/x86_64-linux-gnu/libgfapi.so.0(glfs_fini+0x3f9) [0x7f4f48434239] -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy_all+0x4e) [0x7f4f481a584e] -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy+0xe3) [0x7f4f481a5753] ) 0-gfapi: Active inode(0x7f4f334002cc) with refcount(1) found during cleanup [2016-04-27 07:02:26.753377] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=84 max=68 total=68 [2016-04-27 07:02:26.754185] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=156 max=69 total=69 [2016-04-27 07:02:26.755549] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=108 max=65 total=70 [2016-04-27 07:02:26.755576] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=588 max=40 total=1319 [2016-04-27 07:02:26.755589] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=124 max=40 total=1319 [2016-04-27 07:02:26.755604] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=1300 max=40 total=1179 [2016-04-27 07:02:26.755618] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=588 max=40 total=1278 [2016-04-27 07:02:26.755672] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=124 max=40 total=1278 [2016-04-27 07:02:26.755686] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=1300 max=40 total=1139 [2016-04-27 07:02:26.755799] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=588 max=34 total=1278 [2016-04-27 07:02:26.755813] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=124 max=34 total=1278 [2016-04-27 07:02:26.755826] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=1300 max=34 total=1139 [2016-04-27 07:02:26.755840] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-replicate-0: size=10524 max=68 total=817 [2016-04-27 07:02:26.756044] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=1148 max=0 total=0 [2016-04-27 07:02:26.756079] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=2284 max=3 total=425 [2016-04-27 07:02:26.756198] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-shard: size=1396 max=2 total=353 [2016-04-27 07:02:26.756217] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-readdir-ahead: size=52 max=0 total=0 [2016-04-27 07:02:26.756240] I [io-stats.c:2951:fini] 0-datastore4: io-stats translator unloaded [2016-04-27 07:02:26.756301] I [MSGID: 101191] [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with index 2 [2016-04-27 07:02:26.756307] I [MSGID: 101191] [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with index 1 [2016-04-27 07:02:27.705915] I [MSGID: 104045] [glfs-master.c:95:notify] 0-gfapi: New graph 766e622d-3930-3033-2d32-3031362d3034 (0) coming up [2016-04-27 07:02:27.705960] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-0: parent translators are ready, attempting connect on transport [2016-04-27 07:02:27.706592] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-1: parent translators are ready, attempting connect on transport [2016-04-27 07:02:27.706894] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-0: changing port to 49156 (from 0) [2016-04-27 07:02:27.707080] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-2: parent translators are ready, attempting connect on transport [2016-04-27 07:02:27.707725] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-0: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:27.708041] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-1: changing port to 49155 (from 0) [2016-04-27 07:02:27.708118] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-0: Connected to datastore4-client-0, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:27.708136] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-0: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:27.708275] I [MSGID: 108005] [afr-common.c:4007:afr_notify] 0-datastore4-replicate-0: Subvolume 'datastore4-client-0' came back up; going online. [2016-04-27 07:02:27.708314] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-0: Server lk version = 1 [2016-04-27 07:02:27.708572] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-2: changing port to 49155 (from 0) [2016-04-27 07:02:27.708883] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-1: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:27.709394] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-1: Connected to datastore4-client-1, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:27.709412] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-1: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:27.709500] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-2: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:27.709594] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-1: Server lk version = 1 [2016-04-27 07:02:27.710035] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-2: Connected to datastore4-client-2, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:27.710050] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-2: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:27.725555] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-2: Server lk version = 1 [2016-04-27 07:02:27.726714] I [MSGID: 108031] [afr-common.c:1900:afr_local_discovery_cbk] 0-datastore4-replicate-0: selecting local read_child datastore4-client-0 [2016-04-27 07:02:27.727273] I [MSGID: 104041] [glfs-resolve.c:869:__glfs_active_subvol] 0-datastore4: switched to graph 766e622d-3930-3033-2d32-3031362d3034 (0) [2016-04-27 07:02:27.846128] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-0: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:27.846199] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-1: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:27.846218] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-0: disconnected from datastore4-client-0. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:27.846240] I [MSGID: 114021] [client.c:2115:notify] 0-datastore4-client-2: current graph is no longer active, destroying rpc_client [2016-04-27 07:02:27.846262] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-1: disconnected from datastore4-client-1. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:27.846280] I [MSGID: 114018] [client.c:2030:client_rpc_notify] 0-datastore4-client-2: disconnected from datastore4-client-2. Client process will keep trying to connect to glusterd until brick's port is available [2016-04-27 07:02:27.846281] W [MSGID: 108001] [afr-common.c:4090:afr_notify] 0-datastore4-replicate-0: Client-quorum is not met [2016-04-27 07:02:27.846321] E [MSGID: 108006] [afr-common.c:4046:afr_notify] 0-datastore4-replicate-0: All subvolumes are down. Going offline until atleast one of them comes back up. [2016-04-27 07:02:27.846432] W [inode.c:1792:inode_table_destroy] (-->/usr/lib/x86_64-linux-gnu/libgfapi.so.0(glfs_fini+0x3f9) [0x7f4f48434239] -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy_all+0x4e) [0x7f4f481a584e] -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy+0xe3) [0x7f4f481a5753] ) 0-gfapi: Active inode(0x7f4f334002cc) with refcount(1) found during cleanup [2016-04-27 07:02:27.846595] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=84 max=4 total=4 [2016-04-27 07:02:27.847357] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=156 max=5 total=5 [2016-04-27 07:02:27.848715] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=108 max=2 total=6 [2016-04-27 07:02:27.848759] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=588 max=3 total=34 [2016-04-27 07:02:27.848772] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=124 max=3 total=34 [2016-04-27 07:02:27.848787] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=1300 max=2 total=19 [2016-04-27 07:02:27.848801] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=588 max=3 total=29 [2016-04-27 07:02:27.848812] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=124 max=3 total=29 [2016-04-27 07:02:27.848825] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=1300 max=2 total=15 [2016-04-27 07:02:27.848838] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=588 max=4 total=29 [2016-04-27 07:02:27.848849] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=124 max=4 total=29 [2016-04-27 07:02:27.848861] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=1300 max=3 total=15 [2016-04-27 07:02:27.848875] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-replicate-0: size=10524 max=2 total=25 [2016-04-27 07:02:27.849040] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=1148 max=0 total=0 [2016-04-27 07:02:27.849127] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=2284 max=2 total=21 [2016-04-27 07:02:27.849227] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-shard: size=1396 max=1 total=10 [2016-04-27 07:02:27.849323] I [MSGID: 101053] [mem-pool.c:616:mem_pool_destroy] 0-datastore4-readdir-ahead: size=52 max=0 total=0 [2016-04-27 07:02:27.849346] I [io-stats.c:2951:fini] 0-datastore4: io-stats translator unloaded [2016-04-27 07:02:27.849412] I [MSGID: 101191] [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with index 1 Formatting 'gluster://vnb.proxmox.softlog/datastore4/images/910/vm-910-disk-1.qcow2', fmt=qcow2 size=34359738368 encryption=off cluster_size=65536 preallocation=metadata lazy_refcounts=off refcount_bits=16 [2016-04-27 07:02:27.849412] I [MSGID: 101191] [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with index 2 new volume ID is 'gluster4:910/vm-910-disk-1.qcow2' map 'drive-scsi0' to 'gluster://vnb.proxmox.softlog/datastore4/images/910/vm-910-disk-1.qcow2' (write zeros = 0) [2016-04-27 07:02:28.733310] I [MSGID: 104045] [glfs-master.c:95:notify] 0-gfapi: New graph 766e622d-3930-3032-2d32-3031362d3034 (0) coming up [2016-04-27 07:02:28.733357] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-0: parent translators are ready, attempting connect on transport [2016-04-27 07:02:28.733998] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-1: parent translators are ready, attempting connect on transport [2016-04-27 07:02:28.734250] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-0: changing port to 49156 (from 0) [2016-04-27 07:02:28.734475] I [MSGID: 114020] [client.c:2106:notify] 0-datastore4-client-2: parent translators are ready, attempting connect on transport [2016-04-27 07:02:28.735120] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-0: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:28.735455] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-1: changing port to 49155 (from 0) [2016-04-27 07:02:28.735567] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-0: Connected to datastore4-client-0, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:28.735585] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-0: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:28.735653] I [MSGID: 108005] [afr-common.c:4007:afr_notify] 0-datastore4-replicate-0: Subvolume 'datastore4-client-0' came back up; going online. [2016-04-27 07:02:28.735722] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-0: Server lk version = 1 [2016-04-27 07:02:28.735915] I [rpc-clnt.c:1868:rpc_clnt_reconfig] 0-datastore4-client-2: changing port to 49155 (from 0) [2016-04-27 07:02:28.736400] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-1: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:28.736916] I [MSGID: 114057] [client-handshake.c:1437:select_server_supported_programs] 0-datastore4-client-2: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2016-04-27 07:02:28.736950] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-1: Connected to datastore4-client-1, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:28.736970] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-1: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:28.737195] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-1: Server lk version = 1 [2016-04-27 07:02:28.737370] I [MSGID: 114046] [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-2: Connected to datastore4-client-2, attached to remote volume '/tank/vmdata/datastore4'. [2016-04-27 07:02:28.737389] I [MSGID: 114047] [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-2: Server and Client lk-version numbers are not same, reopening the fds [2016-04-27 07:02:28.753072] I [MSGID: 114035] [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-2: Server lk version = 1 [2016-04-27 07:02:28.754705] I [MSGID: 108031] [afr-common.c:1900:afr_local_discovery_cbk] 0-datastore4-replicate-0: selecting local read_child datastore4-client-0 [2016-04-27 07:02:28.755138] I [MSGID: 104041] [glfs-resolve.c:869:__glfs_active_subvol] 0-datastore4: switched to graph 766e622d-3930-3032-2d32-3031362d3034 (0) *** (process:9002): ERROR **: vma_reader_register_bs for stream drive-scsi0 failed - unexpected size 34365243392 != 34359738368/bin/bash: line 1: 9001 Broken pipe lzop -d -c /mnt/nas-backups-smb/dump/vzdump-qemu-910-2016_04_23-08_22_07.vma.lzo 9002 Trace/breakpoint trap | vma extract -v -r /var/tmp/vzdumptmp8999.fifo - /var/tmp/vzdumptmp8999temporary volume 'gluster4:910/vm-910-disk-1.qcow2' sucessfuly removedTASK ERROR: command 'lzop -d -c /mnt/nas-backups-smb/dump/vzdump-qemu-910-2016_04_23-08_22_07.vma.lzo|vma extract -v -r /var/tmp/vzdumptmp8999.fifo - /var/tmp/vzdumptmp8999' failed: exit code 133* -- Lindsay -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://www.gluster.org/pipermail/gluster-users/attachments/20160427/39795965/attachment.html>
Krutika Dhananjay
2016-Apr-27 12:20 UTC
[Gluster-users] FIle size error when restoring backups causes restore failure.
Hmm could you get me the output of `getfattr -d -m . -e hex <path-to-the-vm-file> from all the three bricks? And also the `ls -l` output of this vm file as seen from the mount point. -Krutika On Wed, Apr 27, 2016 at 1:25 PM, Lindsay Mathieson < lindsay.mathieson at gmail.com> wrote:> I'm getting the following file size error when restoring proxmox qemu > backups via gfapi. I don't think the issue is with proxmox as I have tested > the same restore process with other storages with no problem(nfs, cephfs, > ceph rbd). Also if I restore the the gluster *fuse* mount it works ok. > > Have tested with: > > performance.stat-prefetch: off > performance.strict-write-ordering: on > > still same problem. > > This is with sharded storage - as soon as I some time I'll test with > non-shared storage. > > Error is bolded at the end of the logging > > restore vma archive: lzop -d -c > /mnt/nas-backups-smb/dump/vzdump-qemu-910-2016_04_23-08_22_07.vma.lzo|vma > extract -v -r /var/tmp/vzdumptmp8999.fifo - /var/tmp/vzdumptmp8999 > CFG: size: 391 name: qemu-server.conf > DEV: dev_id=1 size: 34359738368 devname: drive-scsi0 > CTIME: Sat Apr 23 08:22:11 2016 > [2016-04-27 07:02:21.688878] I [MSGID: 104045] [glfs-master.c:95:notify] > 0-gfapi: New graph 766e622d-3930-3033-2d32-3031362d3034 (0) coming up > [2016-04-27 07:02:21.688921] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-0: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:21.689530] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-1: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:21.689793] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-0: changing port to 49156 (from 0) > [2016-04-27 07:02:21.689951] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-2: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:21.690608] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-0: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:21.690977] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-1: changing port to 49155 (from 0) > [2016-04-27 07:02:21.691032] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-0: > Connected to datastore4-client-0, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:21.691068] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-0: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:21.691148] I [MSGID: 108005] > [afr-common.c:4007:afr_notify] 0-datastore4-replicate-0: Subvolume > 'datastore4-client-0' came back up; going online. > [2016-04-27 07:02:21.691235] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-0: > Server lk version = 1 > [2016-04-27 07:02:21.691430] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-2: changing port to 49155 (from 0) > [2016-04-27 07:02:21.691867] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-1: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:21.692350] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-1: > Connected to datastore4-client-1, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:21.692369] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-1: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:21.692474] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-2: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:21.692590] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-1: > Server lk version = 1 > [2016-04-27 07:02:21.692926] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-2: > Connected to datastore4-client-2, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:21.692942] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-2: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:21.708641] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-2: > Server lk version = 1 > [2016-04-27 07:02:21.709796] I [MSGID: 108031] > [afr-common.c:1900:afr_local_discovery_cbk] 0-datastore4-replicate-0: > selecting local read_child datastore4-client-0 > [2016-04-27 07:02:21.710401] I [MSGID: 104041] > [glfs-resolve.c:869:__glfs_active_subvol] 0-datastore4: switched to graph > 766e622d-3930-3033-2d32-3031362d3034 (0) > [2016-04-27 07:02:21.828061] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-0: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:21.828125] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-1: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:21.828140] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-0: disconnected from > datastore4-client-0. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:21.828163] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-2: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:21.828181] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-1: disconnected from > datastore4-client-1. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:21.828205] W [MSGID: 108001] > [afr-common.c:4090:afr_notify] 0-datastore4-replicate-0: Client-quorum is > not met > [2016-04-27 07:02:21.828235] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-2: disconnected from > datastore4-client-2. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:21.828248] E [MSGID: 108006] > [afr-common.c:4046:afr_notify] 0-datastore4-replicate-0: All subvolumes are > down. Going offline until atleast one of them comes back up. > [2016-04-27 07:02:21.828442] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=84 max=3 total=3 > [2016-04-27 07:02:21.829252] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=156 max=5 total=5 > [2016-04-27 07:02:21.830686] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=108 max=1 total=1 > [2016-04-27 07:02:21.830733] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=588 max=3 > total=24 > [2016-04-27 07:02:21.830747] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=124 max=3 > total=24 > [2016-04-27 07:02:21.830765] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=1300 max=2 > total=13 > [2016-04-27 07:02:21.830781] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=588 max=3 > total=24 > [2016-04-27 07:02:21.830856] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=124 max=3 > total=24 > [2016-04-27 07:02:21.830872] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=1300 max=3 > total=13 > [2016-04-27 07:02:21.830887] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=588 max=4 > total=24 > [2016-04-27 07:02:21.830899] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=124 max=4 > total=24 > [2016-04-27 07:02:21.830912] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=1300 max=2 > total=13 > [2016-04-27 07:02:21.830978] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-replicate-0: size=10524 > max=2 total=13 > [2016-04-27 07:02:21.831173] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=1148 max=0 total=0 > [2016-04-27 07:02:21.831240] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=2284 max=2 total=9 > [2016-04-27 07:02:21.831373] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-shard: size=1396 max=1 > total=7 > [2016-04-27 07:02:21.831392] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-readdir-ahead: size=52 max=0 > total=0 > [2016-04-27 07:02:21.831406] I [io-stats.c:2951:fini] 0-datastore4: > io-stats translator unloaded > [2016-04-27 07:02:21.831467] I [MSGID: 101191] > [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with > index 1 > [2016-04-27 07:02:21.831493] I [MSGID: 101191] > [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with > index 2 > [2016-04-27 07:02:22.688831] I [MSGID: 104045] [glfs-master.c:95:notify] > 0-gfapi: New graph 766e622d-3930-3033-2d32-3031362d3034 (0) coming up > [2016-04-27 07:02:22.688873] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-0: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:22.689466] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-1: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:22.689732] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-0: changing port to 49156 (from 0) > [2016-04-27 07:02:22.689879] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-2: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:22.690547] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-0: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:22.690803] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-1: changing port to 49155 (from 0) > [2016-04-27 07:02:22.690923] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-0: > Connected to datastore4-client-0, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:22.690945] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-0: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:22.691002] I [MSGID: 108005] > [afr-common.c:4007:afr_notify] 0-datastore4-replicate-0: Subvolume > 'datastore4-client-0' came back up; going online. > [2016-04-27 07:02:22.691033] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-0: > Server lk version = 1 > [2016-04-27 07:02:22.691486] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-2: changing port to 49155 (from 0) > [2016-04-27 07:02:22.691749] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-1: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:22.692262] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-1: > Connected to datastore4-client-1, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:22.692279] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-1: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:22.692489] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-2: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:22.692497] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-1: > Server lk version = 1 > [2016-04-27 07:02:22.693084] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-2: > Connected to datastore4-client-2, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:22.693102] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-2: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:22.708424] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-2: > Server lk version = 1 > [2016-04-27 07:02:22.709613] I [MSGID: 108031] > [afr-common.c:1900:afr_local_discovery_cbk] 0-datastore4-replicate-0: > selecting local read_child datastore4-client-0 > [2016-04-27 07:02:22.710086] I [MSGID: 104041] > [glfs-resolve.c:869:__glfs_active_subvol] 0-datastore4: switched to graph > 766e622d-3930-3033-2d32-3031362d3034 (0) > [2016-04-27 07:02:22.850510] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-0: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:22.850579] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-1: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:22.850598] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-0: disconnected from > datastore4-client-0. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:22.850634] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-1: disconnected from > datastore4-client-1. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:22.850639] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-2: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:22.850679] W [MSGID: 108001] > [afr-common.c:4090:afr_notify] 0-datastore4-replicate-0: Client-quorum is > not met > [2016-04-27 07:02:22.850705] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-2: disconnected from > datastore4-client-2. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:22.850718] E [MSGID: 108006] > [afr-common.c:4046:afr_notify] 0-datastore4-replicate-0: All subvolumes are > down. Going offline until atleast one of them comes back up. > [2016-04-27 07:02:22.850832] W [inode.c:1792:inode_table_destroy] > (-->/usr/lib/x86_64-linux-gnu/libgfapi.so.0(glfs_fini+0x3f9) > [0x7f4f48434239] > -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy_all+0x4e) > [0x7f4f481a584e] > -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy+0xe3) > [0x7f4f481a5753] ) 0-gfapi: Active inode(0x7f4f334002cc) with refcount(1) > found during cleanup > [2016-04-27 07:02:22.851009] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=84 max=4 total=4 > [2016-04-27 07:02:22.851785] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=156 max=5 total=5 > [2016-04-27 07:02:22.853155] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=108 max=2 total=2 > [2016-04-27 07:02:22.853203] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=588 max=3 > total=47 > [2016-04-27 07:02:22.853220] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=124 max=3 > total=47 > [2016-04-27 07:02:22.853239] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=1300 max=2 > total=32 > [2016-04-27 07:02:22.853257] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=588 max=4 > total=46 > [2016-04-27 07:02:22.853271] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=124 max=4 > total=46 > [2016-04-27 07:02:22.853287] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=1300 max=3 > total=32 > [2016-04-27 07:02:22.853305] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=588 max=4 > total=46 > [2016-04-27 07:02:22.853387] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=124 max=4 > total=46 > [2016-04-27 07:02:22.853407] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=1300 max=3 > total=32 > [2016-04-27 07:02:22.853424] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-replicate-0: size=10524 > max=3 total=25 > [2016-04-27 07:02:22.853598] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=1148 max=0 total=0 > [2016-04-27 07:02:22.853660] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=2284 max=3 total=17 > [2016-04-27 07:02:22.853841] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-shard: size=1396 max=1 > total=8 > [2016-04-27 07:02:22.853863] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-readdir-ahead: size=52 max=0 > total=0 > [2016-04-27 07:02:22.853879] I [io-stats.c:2951:fini] 0-datastore4: > io-stats translator unloaded > [2016-04-27 07:02:22.853951] I [MSGID: 101191] > [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with > index 1 > [2016-04-27 07:02:22.853951] I [MSGID: 101191] > [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with > index 2 > [2016-04-27 07:02:23.694923] I [MSGID: 104045] [glfs-master.c:95:notify] > 0-gfapi: New graph 766e622d-3930-3033-2d32-3031362d3034 (0) coming up > [2016-04-27 07:02:23.694967] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-0: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:23.695603] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-1: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:23.695866] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-0: changing port to 49156 (from 0) > [2016-04-27 07:02:23.696034] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-2: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:23.696707] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-0: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:23.696940] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-1: changing port to 49155 (from 0) > [2016-04-27 07:02:23.697128] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-0: > Connected to datastore4-client-0, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:23.697148] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-0: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:23.697220] I [MSGID: 108005] > [afr-common.c:4007:afr_notify] 0-datastore4-replicate-0: Subvolume > 'datastore4-client-0' came back up; going online. > [2016-04-27 07:02:23.697319] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-0: > Server lk version = 1 > [2016-04-27 07:02:23.697510] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-2: changing port to 49155 (from 0) > [2016-04-27 07:02:23.697770] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-1: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:23.698338] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-1: > Connected to datastore4-client-1, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:23.698358] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-1: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:23.698451] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-2: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:23.698560] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-1: > Server lk version = 1 > [2016-04-27 07:02:23.698993] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-2: > Connected to datastore4-client-2, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:23.699012] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-2: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:23.714625] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-2: > Server lk version = 1 > [2016-04-27 07:02:23.715924] I [MSGID: 108031] > [afr-common.c:1900:afr_local_discovery_cbk] 0-datastore4-replicate-0: > selecting local read_child datastore4-client-0 > [2016-04-27 07:02:23.716481] I [MSGID: 104041] > [glfs-resolve.c:869:__glfs_active_subvol] 0-datastore4: switched to graph > 766e622d-3930-3033-2d32-3031362d3034 (0) > [2016-04-27 07:02:26.752833] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-0: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:26.752896] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-1: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:26.752913] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-0: disconnected from > datastore4-client-0. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:26.752938] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-2: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:26.752945] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-1: disconnected from > datastore4-client-1. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:26.752968] W [MSGID: 108001] > [afr-common.c:4090:afr_notify] 0-datastore4-replicate-0: Client-quorum is > not met > [2016-04-27 07:02:26.752972] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-2: disconnected from > datastore4-client-2. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:26.752988] E [MSGID: 108006] > [afr-common.c:4046:afr_notify] 0-datastore4-replicate-0: All subvolumes are > down. Going offline until atleast one of them comes back up. > [2016-04-27 07:02:26.753114] W [inode.c:1792:inode_table_destroy] > (-->/usr/lib/x86_64-linux-gnu/libgfapi.so.0(glfs_fini+0x3f9) > [0x7f4f48434239] > -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy_all+0x4e) > [0x7f4f481a584e] > -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy+0xe3) > [0x7f4f481a5753] ) 0-gfapi: Active inode(0x7f4f334002cc) with refcount(1) > found during cleanup > [2016-04-27 07:02:26.753377] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=84 max=68 total=68 > [2016-04-27 07:02:26.754185] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=156 max=69 total=69 > [2016-04-27 07:02:26.755549] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=108 max=65 total=70 > [2016-04-27 07:02:26.755576] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=588 max=40 > total=1319 > [2016-04-27 07:02:26.755589] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=124 max=40 > total=1319 > [2016-04-27 07:02:26.755604] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=1300 max=40 > total=1179 > [2016-04-27 07:02:26.755618] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=588 max=40 > total=1278 > [2016-04-27 07:02:26.755672] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=124 max=40 > total=1278 > [2016-04-27 07:02:26.755686] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=1300 max=40 > total=1139 > [2016-04-27 07:02:26.755799] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=588 max=34 > total=1278 > [2016-04-27 07:02:26.755813] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=124 max=34 > total=1278 > [2016-04-27 07:02:26.755826] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=1300 max=34 > total=1139 > [2016-04-27 07:02:26.755840] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-replicate-0: size=10524 > max=68 total=817 > [2016-04-27 07:02:26.756044] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=1148 max=0 total=0 > [2016-04-27 07:02:26.756079] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=2284 max=3 > total=425 > [2016-04-27 07:02:26.756198] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-shard: size=1396 max=2 > total=353 > [2016-04-27 07:02:26.756217] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-readdir-ahead: size=52 max=0 > total=0 > [2016-04-27 07:02:26.756240] I [io-stats.c:2951:fini] 0-datastore4: > io-stats translator unloaded > [2016-04-27 07:02:26.756301] I [MSGID: 101191] > [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with > index 2 > [2016-04-27 07:02:26.756307] I [MSGID: 101191] > [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with > index 1 > [2016-04-27 07:02:27.705915] I [MSGID: 104045] [glfs-master.c:95:notify] > 0-gfapi: New graph 766e622d-3930-3033-2d32-3031362d3034 (0) coming up > [2016-04-27 07:02:27.705960] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-0: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:27.706592] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-1: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:27.706894] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-0: changing port to 49156 (from 0) > [2016-04-27 07:02:27.707080] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-2: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:27.707725] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-0: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:27.708041] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-1: changing port to 49155 (from 0) > [2016-04-27 07:02:27.708118] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-0: > Connected to datastore4-client-0, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:27.708136] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-0: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:27.708275] I [MSGID: 108005] > [afr-common.c:4007:afr_notify] 0-datastore4-replicate-0: Subvolume > 'datastore4-client-0' came back up; going online. > [2016-04-27 07:02:27.708314] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-0: > Server lk version = 1 > [2016-04-27 07:02:27.708572] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-2: changing port to 49155 (from 0) > [2016-04-27 07:02:27.708883] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-1: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:27.709394] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-1: > Connected to datastore4-client-1, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:27.709412] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-1: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:27.709500] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-2: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:27.709594] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-1: > Server lk version = 1 > [2016-04-27 07:02:27.710035] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-2: > Connected to datastore4-client-2, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:27.710050] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-2: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:27.725555] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-2: > Server lk version = 1 > [2016-04-27 07:02:27.726714] I [MSGID: 108031] > [afr-common.c:1900:afr_local_discovery_cbk] 0-datastore4-replicate-0: > selecting local read_child datastore4-client-0 > [2016-04-27 07:02:27.727273] I [MSGID: 104041] > [glfs-resolve.c:869:__glfs_active_subvol] 0-datastore4: switched to graph > 766e622d-3930-3033-2d32-3031362d3034 (0) > [2016-04-27 07:02:27.846128] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-0: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:27.846199] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-1: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:27.846218] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-0: disconnected from > datastore4-client-0. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:27.846240] I [MSGID: 114021] [client.c:2115:notify] > 0-datastore4-client-2: current graph is no longer active, destroying > rpc_client > [2016-04-27 07:02:27.846262] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-1: disconnected from > datastore4-client-1. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:27.846280] I [MSGID: 114018] > [client.c:2030:client_rpc_notify] 0-datastore4-client-2: disconnected from > datastore4-client-2. Client process will keep trying to connect to glusterd > until brick's port is available > [2016-04-27 07:02:27.846281] W [MSGID: 108001] > [afr-common.c:4090:afr_notify] 0-datastore4-replicate-0: Client-quorum is > not met > [2016-04-27 07:02:27.846321] E [MSGID: 108006] > [afr-common.c:4046:afr_notify] 0-datastore4-replicate-0: All subvolumes are > down. Going offline until atleast one of them comes back up. > [2016-04-27 07:02:27.846432] W [inode.c:1792:inode_table_destroy] > (-->/usr/lib/x86_64-linux-gnu/libgfapi.so.0(glfs_fini+0x3f9) > [0x7f4f48434239] > -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy_all+0x4e) > [0x7f4f481a584e] > -->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(inode_table_destroy+0xe3) > [0x7f4f481a5753] ) 0-gfapi: Active inode(0x7f4f334002cc) with refcount(1) > found during cleanup > [2016-04-27 07:02:27.846595] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=84 max=4 total=4 > [2016-04-27 07:02:27.847357] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=156 max=5 total=5 > [2016-04-27 07:02:27.848715] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-gfapi: size=108 max=2 total=6 > [2016-04-27 07:02:27.848759] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=588 max=3 > total=34 > [2016-04-27 07:02:27.848772] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=124 max=3 > total=34 > [2016-04-27 07:02:27.848787] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-0: size=1300 max=2 > total=19 > [2016-04-27 07:02:27.848801] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=588 max=3 > total=29 > [2016-04-27 07:02:27.848812] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=124 max=3 > total=29 > [2016-04-27 07:02:27.848825] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-1: size=1300 max=2 > total=15 > [2016-04-27 07:02:27.848838] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=588 max=4 > total=29 > [2016-04-27 07:02:27.848849] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=124 max=4 > total=29 > [2016-04-27 07:02:27.848861] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-client-2: size=1300 max=3 > total=15 > [2016-04-27 07:02:27.848875] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-replicate-0: size=10524 > max=2 total=25 > [2016-04-27 07:02:27.849040] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=1148 max=0 total=0 > [2016-04-27 07:02:27.849127] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-dht: size=2284 max=2 total=21 > [2016-04-27 07:02:27.849227] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-shard: size=1396 max=1 > total=10 > [2016-04-27 07:02:27.849323] I [MSGID: 101053] > [mem-pool.c:616:mem_pool_destroy] 0-datastore4-readdir-ahead: size=52 max=0 > total=0 > [2016-04-27 07:02:27.849346] I [io-stats.c:2951:fini] 0-datastore4: > io-stats translator unloaded > [2016-04-27 07:02:27.849412] I [MSGID: 101191] > [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with > index 1 > Formatting > 'gluster://vnb.proxmox.softlog/datastore4/images/910/vm-910-disk-1.qcow2', > fmt=qcow2 size=34359738368 encryption=off cluster_size=65536 > preallocation=metadata lazy_refcounts=off refcount_bits=16 > [2016-04-27 07:02:27.849412] I [MSGID: 101191] > [event-epoll.c:663:event_dispatch_epoll_worker] 0-epoll: Exited thread with > index 2 > new volume ID is 'gluster4:910/vm-910-disk-1.qcow2' > map 'drive-scsi0' to > 'gluster://vnb.proxmox.softlog/datastore4/images/910/vm-910-disk-1.qcow2' > (write zeros = 0) > [2016-04-27 07:02:28.733310] I [MSGID: 104045] [glfs-master.c:95:notify] > 0-gfapi: New graph 766e622d-3930-3032-2d32-3031362d3034 (0) coming up > [2016-04-27 07:02:28.733357] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-0: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:28.733998] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-1: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:28.734250] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-0: changing port to 49156 (from 0) > [2016-04-27 07:02:28.734475] I [MSGID: 114020] [client.c:2106:notify] > 0-datastore4-client-2: parent translators are ready, attempting connect on > transport > [2016-04-27 07:02:28.735120] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-0: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:28.735455] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-1: changing port to 49155 (from 0) > [2016-04-27 07:02:28.735567] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-0: > Connected to datastore4-client-0, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:28.735585] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-0: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:28.735653] I [MSGID: 108005] > [afr-common.c:4007:afr_notify] 0-datastore4-replicate-0: Subvolume > 'datastore4-client-0' came back up; going online. > [2016-04-27 07:02:28.735722] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-0: > Server lk version = 1 > [2016-04-27 07:02:28.735915] I [rpc-clnt.c:1868:rpc_clnt_reconfig] > 0-datastore4-client-2: changing port to 49155 (from 0) > [2016-04-27 07:02:28.736400] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-1: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:28.736916] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-datastore4-client-2: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-04-27 07:02:28.736950] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-1: > Connected to datastore4-client-1, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:28.736970] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-1: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:28.737195] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-1: > Server lk version = 1 > [2016-04-27 07:02:28.737370] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-datastore4-client-2: > Connected to datastore4-client-2, attached to remote volume > '/tank/vmdata/datastore4'. > [2016-04-27 07:02:28.737389] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-datastore4-client-2: > Server and Client lk-version numbers are not same, reopening the fds > [2016-04-27 07:02:28.753072] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-datastore4-client-2: > Server lk version = 1 > [2016-04-27 07:02:28.754705] I [MSGID: 108031] > [afr-common.c:1900:afr_local_discovery_cbk] 0-datastore4-replicate-0: > selecting local read_child datastore4-client-0 > [2016-04-27 07:02:28.755138] I [MSGID: 104041] > [glfs-resolve.c:869:__glfs_active_subvol] 0-datastore4: switched to graph > 766e622d-3930-3032-2d32-3031362d3034 (0) > > > > > > *** (process:9002): ERROR **: vma_reader_register_bs for stream > drive-scsi0 failed - unexpected size 34365243392 != 34359738368/bin/bash: > line 1: 9001 Broken pipe lzop -d -c > /mnt/nas-backups-smb/dump/vzdump-qemu-910-2016_04_23-08_22_07.vma.lzo > 9002 Trace/breakpoint trap | vma extract -v -r > /var/tmp/vzdumptmp8999.fifo - /var/tmp/vzdumptmp8999temporary volume > 'gluster4:910/vm-910-disk-1.qcow2' sucessfuly removedTASK ERROR: command > 'lzop -d -c > /mnt/nas-backups-smb/dump/vzdump-qemu-910-2016_04_23-08_22_07.vma.lzo|vma > extract -v -r /var/tmp/vzdumptmp8999.fifo - /var/tmp/vzdumptmp8999' failed: > exit code 133* > > > -- > Lindsay > > _______________________________________________ > Gluster-users mailing list > Gluster-users at gluster.org > http://www.gluster.org/mailman/listinfo/gluster-users >-------------- next part -------------- An HTML attachment was scrubbed... URL: <http://www.gluster.org/pipermail/gluster-users/attachments/20160427/354aa809/attachment.html>
Lindsay Mathieson
2016-Apr-28 03:24 UTC
[Gluster-users] FIle size error when restoring backups causes restore failure.
On 27 April 2016 at 17:55, Lindsay Mathieson <lindsay.mathieson at gmail.com> wrote:> I'm getting the following file size error when restoring proxmox qemu > backups via gfapi. I don't think the issue is with proxmox as I have tested > the same restore process with other storages with no problem(nfs, cephfs, > ceph rbd). Also if I restore the the gluster *fuse* mount it works ok.I did some more testing and tracing through code and it appears to be a problem with the proxmox restore script, not gluster. My apologies for the false alarm. -- Lindsay -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://www.gluster.org/pipermail/gluster-users/attachments/20160428/0ff10305/attachment.html>