Attachment 1482106 Details for Bug 1627060 – patchy-rebalance.log for x86

patchy-rebalance.log for x86

rebalance_x86.log (text/plain), 42.16 KB, created by abhays on 2018-09-10 11:52:14 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: abhays

Created: 2018-09-10 11:52:14 UTC

Size: 42.16 KB

patch

obsolete

>[2018-09-05 10:17:04.613267] I [MSGID: 100030] [glusterfsd.c:2741:main] 0-/usr/local/sbin/glusterfs: Started running /usr/local/sbin/glusterfs version 4.1.1 (args: /usr/local/sbin/glusterfs -s localhost --volfile-id rebalance/patchy --xlator-option *dht.use-readdirp=yes --xlator-option *dht.lookup-unhashed=yes --xlator-option *dht.assert-no-child-down=yes --xlator-option *dht.readdir-optimize=on --process-name rebalance --xlator-option *dht.rebalance-cmd=5 --xlator-option *dht.node-uuid=6c3831b4-56da-43a6-9228-017dbad36c9b --xlator-option *dht.commit-hash=3699206404 --socket-file /var/run/gluster/gluster-rebalance-fbf341bb-d321-4da0-9d45-edfb4e6de998.sock --pid-file /var/lib/glusterd/vols/patchy/rebalance/6c3831b4-56da-43a6-9228-017dbad36c9b.pid -l /var/log/glusterfs/patchy-rebalance.log)
>[2018-09-05 10:17:04.621973] I [MSGID: 101190] [event-epoll.c:617:event_dispatch_epoll_worker] 0-epoll: Started thread with index 1
>[2018-09-05 10:17:09.624356] I [MSGID: 109104] [dht-shared.c:710:dht_init] 0-patchy-dht: dht_init using commit hash 3699206404
>[2018-09-05 10:17:09.625931] I [MSGID: 114020] [client.c:2328:notify] 0-patchy-client-0: parent translators are ready, attempting connect on transport
>[2018-09-05 10:17:09.627580] I [MSGID: 114020] [client.c:2328:notify] 0-patchy-client-1: parent translators are ready, attempting connect on transport
>Final graph:
>+------------------------------------------------------------------------------+
>  1: volume patchy-client-0
>  2:     type protocol/client
>  3:     option ping-timeout 42
>  4:     option remote-host hostname
>  5:     option remote-subvolume /d/backends/patchy1
>  6:     option transport-type socket
>  7:     option transport.address-family inet
>  8:     option username 1acc24df-ba7b-463f-bbb4-5ccaeed5b3b1
>  9:     option password 89aff2a0-14f2-4e6a-ab50-e8d7f8a44a1f
> 10:     option transport.tcp-user-timeout 0
> 11:     option transport.socket.keepalive-time 20
> 12:     option transport.socket.keepalive-interval 2
> 13:     option transport.socket.keepalive-count 9
> 14: end-volume
> 15:  
> 16: volume patchy-client-1
> 17:     type protocol/client
> 18:     option ping-timeout 42
> 19:     option remote-host hostname
> 20:     option remote-subvolume /d/backends/patchy3
> 21:     option transport-type socket
> 22:     option transport.address-family inet
> 23:     option username 1acc24df-ba7b-463f-bbb4-5ccaeed5b3b1
> 24:     option password 89aff2a0-14f2-4e6a-ab50-e8d7f8a44a1f
> 25:     option transport.tcp-user-timeout 0
> 26:     option transport.socket.keepalive-time 20
> 27:     option transport.socket.keepalive-interval 2
> 28:     option transport.socket.keepalive-count 9
> 29: end-volume
> 30:  
> 31: volume patchy-dht
> 32:     type cluster/distribute
> 33:     option use-readdirp yes
> 34:     option lookup-unhashed yes
> 35:     option assert-no-child-down yes
> 36:     option readdir-optimize on
> 37:     option rebalance-cmd 5
> 38:     option node-uuid 6c3831b4-56da-43a6-9228-017dbad36c9b
> 39:     option commit-hash 3699206404
> 40:     option lock-migration off
> 41:     option force-migration off
> 42:     subvolumes patchy-client-0 patchy-client-1
> 43: end-volume
> 44:  
> 45: volume patchy
> 46:     type debug/io-stats
> 47:     option log-level INFO
> 48:     option latency-measurement off
> 49:     option count-fop-hits off
> 50:     subvolumes patchy-dht
> 51: end-volume
> 52:  
>+------------------------------------------------------------------------------+
>[2018-09-05 10:17:09.630111] W [rpc-clnt.c:1753:rpc_clnt_submit] 0-patchy-client-0: error returned while attempting to connect to host:(null), port:0
>[2018-09-05 10:17:09.630207] W [rpc-clnt.c:1753:rpc_clnt_submit] 0-patchy-client-1: error returned while attempting to connect to host:(null), port:0
>[2018-09-05 10:17:09.630280] I [MSGID: 101190] [event-epoll.c:617:event_dispatch_epoll_worker] 0-epoll: Started thread with index 2
>[2018-09-05 10:17:09.630352] W [rpc-clnt.c:1753:rpc_clnt_submit] 0-patchy-client-0: error returned while attempting to connect to host:(null), port:0
>[2018-09-05 10:17:09.630415] W [rpc-clnt.c:1753:rpc_clnt_submit] 0-patchy-client-1: error returned while attempting to connect to host:(null), port:0
>[2018-09-05 10:17:09.630480] I [rpc-clnt.c:2105:rpc_clnt_reconfig] 0-patchy-client-0: changing port to 49152 (from 0)
>[2018-09-05 10:17:09.630519] I [rpc-clnt.c:2105:rpc_clnt_reconfig] 0-patchy-client-1: changing port to 49154 (from 0)
>[2018-09-05 10:17:09.632261] W [rpc-clnt.c:1753:rpc_clnt_submit] 0-patchy-client-1: error returned while attempting to connect to host:(null), port:0
>[2018-09-05 10:17:09.632580] W [rpc-clnt.c:1753:rpc_clnt_submit] 0-patchy-client-1: error returned while attempting to connect to host:(null), port:0
>[2018-09-05 10:17:09.635670] I [MSGID: 114046] [client-handshake.c:1176:client_setvolume_cbk] 0-patchy-client-1: Connected to patchy-client-1, attached to remote volume '/d/backends/patchy3'.
>[2018-09-05 10:17:09.636079] W [rpc-clnt.c:1753:rpc_clnt_submit] 0-patchy-client-0: error returned while attempting to connect to host:(null), port:0
>[2018-09-05 10:17:09.636309] W [rpc-clnt.c:1753:rpc_clnt_submit] 0-patchy-client-0: error returned while attempting to connect to host:(null), port:0
>[2018-09-05 10:17:09.638029] I [MSGID: 114046] [client-handshake.c:1176:client_setvolume_cbk] 0-patchy-client-0: Connected to patchy-client-0, attached to remote volume '/d/backends/patchy1'.
>[2018-09-05 10:17:09.640298] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.640316] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.640322] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.641794] I [MSGID: 109005] [dht-selfheal.c:2342:dht_selfheal_directory] 0-patchy-dht: Directory selfheal failed: Unable to form layout for directory /
>[2018-09-05 10:17:09.642067] I [dht-rebalance.c:4599:gf_defrag_start_crawl] 0-patchy-dht: gf_defrag_start_crawl using commit hash 3699206404
>[2018-09-05 10:17:09.643690] I [MSGID: 109081] [dht-common.c:5628:dht_setxattr] 0-patchy-dht: fixing the layout of /
>[2018-09-05 10:17:09.647071] E [MSGID: 109039] [dht-common.c:4080:dht_find_local_subvol_cbk] 0-patchy-dht: getxattr err for dir [No data available]
>[2018-09-05 10:17:09.647190] E [MSGID: 109039] [dht-common.c:4080:dht_find_local_subvol_cbk] 0-patchy-dht: getxattr err for dir [No data available]
>[2018-09-05 10:17:09.648318] I [MSGID: 0] [dht-rebalance.c:4673:gf_defrag_start_crawl] 0-patchy-dht: local subvols are patchy-client-0
>[2018-09-05 10:17:09.648405] I [MSGID: 0] [dht-rebalance.c:4679:gf_defrag_start_crawl] 0-patchy-dht: node uuids are 6c3831b4-56da-43a6-9228-017dbad36c9b
>[2018-09-05 10:17:09.648432] I [MSGID: 0] [dht-rebalance.c:4673:gf_defrag_start_crawl] 0-patchy-dht: local subvols are patchy-client-1
>[2018-09-05 10:17:09.648459] I [MSGID: 0] [dht-rebalance.c:4679:gf_defrag_start_crawl] 0-patchy-dht: node uuids are 6c3831b4-56da-43a6-9228-017dbad36c9b
>[2018-09-05 10:17:09.649046] I [MSGID: 0] [dht-rebalance.c:4357:gf_defrag_total_file_size] 0-patchy-dht: local subvol: patchy-client-0,cnt = 16940675072
>[2018-09-05 10:17:09.649586] I [MSGID: 0] [dht-rebalance.c:4357:gf_defrag_total_file_size] 0-patchy-dht: local subvol: patchy-client-1,cnt = 16940675072
>[2018-09-05 10:17:09.649619] I [MSGID: 0] [dht-rebalance.c:4361:gf_defrag_total_file_size] 0-patchy-dht: Total size files = 33881350144
>[2018-09-05 10:17:09.650129] I [MSGID: 0] [dht-rebalance.c:4386:gf_defrag_total_file_cnt] 0-patchy-dht: local subvol: patchy-client-0,cnt = 328391
>[2018-09-05 10:17:09.651454] I [MSGID: 0] [dht-rebalance.c:4386:gf_defrag_total_file_cnt] 0-patchy-dht: local subvol: patchy-client-1,cnt = 328391
>[2018-09-05 10:17:09.651496] I [MSGID: 0] [dht-rebalance.c:4397:gf_defrag_total_file_cnt] 0-patchy-dht: Total number of files = 656782
>[2018-09-05 10:17:09.652404] I [dht-rebalance.c:4755:gf_defrag_start_crawl] 0-DHT: Thread[0] creation successful
>[2018-09-05 10:17:09.652499] I [dht-rebalance.c:4755:gf_defrag_start_crawl] 0-DHT: Thread[1] creation successful
>[2018-09-05 10:17:09.653081] I [dht-rebalance.c:4755:gf_defrag_start_crawl] 0-DHT: Thread[2] creation successful
>[2018-09-05 10:17:09.653197] I [dht-rebalance.c:4755:gf_defrag_start_crawl] 0-DHT: Thread[3] creation successful
>[2018-09-05 10:17:09.653248] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.653270] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.653287] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.654450] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.654472] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.655168] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.655195] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.656304] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.656446] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.657495] I [MSGID: 109063] [dht-layout.c:693:dht_layout_normalize] 0-patchy-dht: Found anomalies in /a (gfid = b333837e-9d87-4d91-a5de-330f6c04bfc7). Holes=1 overlaps=0
>[2018-09-05 10:17:09.658352] I [dict.c:491:dict_get] (-->/usr/local/lib/glusterfs/4.1.1/xlator/protocol/client.so(+0x5b321) [0x7f5a928d3321] -->/usr/local/lib/glusterfs/4.1.1/xlator/cluster/distribute.so(+0x1fda5) [0x7f5a925e1da5] -->/usr/local/lib/libglusterfs.so.0(dict_get+0xfb) [0x7f5a982ecb0b] ) 0-dict: !this || key=trusted.glusterfs.dht.mds [Invalid argument]
>[2018-09-05 10:17:09.652535]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 193 0 rebalance_completed ++++++++++
>[2018-09-05 10:17:09.661797] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.662516] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.662532] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.663194] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.663210] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.664180] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.664222] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.664229] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.664873] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.664914] I [MSGID: 109081] [dht-common.c:5628:dht_setxattr] 0-patchy-dht: fixing the layout of /a
>[2018-09-05 10:17:09.666196] I [dht-rebalance.c:3353:gf_defrag_process_dir] 0-patchy-dht: migrate data called on /a
>[2018-09-05 10:17:09.666221] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.666228] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.669121] I [dht-rebalance.c:3567:gf_defrag_process_dir] 0-patchy-dht: Migration operation on dir /a took 0.00 secs
>[2018-09-05 10:17:09.670874] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.672819] I [MSGID: 109063] [dht-layout.c:693:dht_layout_normalize] 0-patchy-dht: Found anomalies in /1 (gfid = 443522ef-85e8-43a6-9f56-004a4dc6a6d5). Holes=1 overlaps=0
>[2018-09-05 10:17:09.673681] I [dict.c:491:dict_get] (-->/usr/local/lib/glusterfs/4.1.1/xlator/protocol/client.so(+0x5b321) [0x7f5a928d3321] -->/usr/local/lib/glusterfs/4.1.1/xlator/cluster/distribute.so(+0x1fda5) [0x7f5a925e1da5] -->/usr/local/lib/libglusterfs.so.0(dict_get+0xfb) [0x7f5a982ecb0b] ) 0-dict: !this || key=trusted.glusterfs.dht.mds [Invalid argument]
>[2018-09-05 10:17:09.676789] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.677683] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.677700] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.678316] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.678331] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.679154] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.679205] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.680507] I [MSGID: 109063] [dht-layout.c:693:dht_layout_normalize] 0-patchy-dht: Found anomalies in /1/2 (gfid = 3d22775c-5411-4a90-87b3-fbd13de7c5d1). Holes=1 overlaps=0
>[2018-09-05 10:17:09.682046] I [dict.c:491:dict_get] (-->/usr/local/lib/glusterfs/4.1.1/xlator/protocol/client.so(+0x5b321) [0x7f5a928d3321] -->/usr/local/lib/glusterfs/4.1.1/xlator/cluster/distribute.so(+0x1fda5) [0x7f5a925e1da5] -->/usr/local/lib/libglusterfs.so.0(dict_get+0xfb) [0x7f5a982ecb0b] ) 0-dict: !this || key=trusted.glusterfs.dht.mds [Invalid argument]
>[2018-09-05 10:17:09.686480] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.687932] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.687964] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.688761] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.688788] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.691512] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.691606] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.693051] I [MSGID: 109063] [dht-layout.c:693:dht_layout_normalize] 0-patchy-dht: Found anomalies in /1/2/3 (gfid = f7aec08f-116c-43a1-9377-8542ecabf85d). Holes=1 overlaps=0
>[2018-09-05 10:17:09.693917] I [dict.c:491:dict_get] (-->/usr/local/lib/glusterfs/4.1.1/xlator/protocol/client.so(+0x5b321) [0x7f5a928d3321] -->/usr/local/lib/glusterfs/4.1.1/xlator/cluster/distribute.so(+0x1fda5) [0x7f5a925e1da5] -->/usr/local/lib/libglusterfs.so.0(dict_get+0xfb) [0x7f5a982ecb0b] ) 0-dict: !this || key=trusted.glusterfs.dht.mds [Invalid argument]
>[2018-09-05 10:17:09.696206] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.696770] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.696840] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.696851] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.697568] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.697583] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.698460] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.698500] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.698508] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.699242] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.699286] I [MSGID: 109081] [dht-common.c:5628:dht_setxattr] 0-patchy-dht: fixing the layout of /1/2/3
>[2018-09-05 10:17:09.700734] I [dht-rebalance.c:3353:gf_defrag_process_dir] 0-patchy-dht: migrate data called on /1/2/3
>[2018-09-05 10:17:09.700759] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.700767] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.709050] I [dht-rebalance.c:3567:gf_defrag_process_dir] 0-patchy-dht: Migration operation on dir /1/2/3 took 0.01 secs
>[2018-09-05 10:17:09.716727] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.716788] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.717672] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.717731] I [MSGID: 109081] [dht-common.c:5628:dht_setxattr] 0-patchy-dht: fixing the layout of /1/2
>[2018-09-05 10:17:09.728145] I [dht-rebalance.c:3353:gf_defrag_process_dir] 0-patchy-dht: migrate data called on /1/2
>[2018-09-05 10:17:09.728212] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.728223] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.731435] I [dht-rebalance.c:3567:gf_defrag_process_dir] 0-patchy-dht: Migration operation on dir /1/2 took 0.00 secs
>[2018-09-05 10:17:09.733258] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.733288] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.734861] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.734942] I [MSGID: 109081] [dht-common.c:5628:dht_setxattr] 0-patchy-dht: fixing the layout of /1
>[2018-09-05 10:17:09.736384] I [dht-rebalance.c:3353:gf_defrag_process_dir] 0-patchy-dht: migrate data called on /1
>[2018-09-05 10:17:09.736416] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.736427] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.738625] I [dht-rebalance.c:3567:gf_defrag_process_dir] 0-patchy-dht: Migration operation on dir /1 took 0.00 secs
>[2018-09-05 10:17:09.740221] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.741396] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.742001] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.742017] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.742603] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.742616] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.743421] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.743469] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.744301] I [MSGID: 109063] [dht-layout.c:693:dht_layout_normalize] 0-patchy-dht: Found anomalies in /.trashcan/1 (gfid = 385cdfc0-d80c-4a2d-b24c-ed53d7a8c541). Holes=1 overlaps=0
>[2018-09-05 10:17:09.745076] I [dict.c:491:dict_get] (-->/usr/local/lib/glusterfs/4.1.1/xlator/protocol/client.so(+0x5b321) [0x7f5a928d3321] -->/usr/local/lib/glusterfs/4.1.1/xlator/cluster/distribute.so(+0x1fda5) [0x7f5a925e1da5] -->/usr/local/lib/libglusterfs.so.0(dict_get+0xfb) [0x7f5a982ecb0b] ) 0-dict: !this || key=trusted.glusterfs.dht.mds [Invalid argument]
>[2018-09-05 10:17:09.747514] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.748467] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.748506] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.749053] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.749074] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.750248] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.750733] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.751973] I [MSGID: 109063] [dht-layout.c:693:dht_layout_normalize] 0-patchy-dht: Found anomalies in /.trashcan/1/2 (gfid = c04083d1-61f7-415d-a1cb-ac62ddaa4532). Holes=1 overlaps=0
>[2018-09-05 10:17:09.752765] I [dict.c:491:dict_get] (-->/usr/local/lib/glusterfs/4.1.1/xlator/protocol/client.so(+0x5b321) [0x7f5a928d3321] -->/usr/local/lib/glusterfs/4.1.1/xlator/cluster/distribute.so(+0x1fda5) [0x7f5a925e1da5] -->/usr/local/lib/libglusterfs.so.0(dict_get+0xfb) [0x7f5a982ecb0b] ) 0-dict: !this || key=trusted.glusterfs.dht.mds [Invalid argument]
>[2018-09-05 10:17:09.755487] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.756070] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.756196] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.756223] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.756713] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.756729] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.757370] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.757441] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.758470] I [MSGID: 109063] [dht-layout.c:693:dht_layout_normalize] 0-patchy-dht: Found anomalies in /.trashcan/1/2/3 (gfid = 7681aa7d-3c25-442d-88b3-ffb2b076164b). Holes=1 overlaps=0
>[2018-09-05 10:17:09.759226] I [dict.c:491:dict_get] (-->/usr/local/lib/glusterfs/4.1.1/xlator/protocol/client.so(+0x5b321) [0x7f5a928d3321] -->/usr/local/lib/glusterfs/4.1.1/xlator/cluster/distribute.so(+0x1fda5) [0x7f5a925e1da5] -->/usr/local/lib/libglusterfs.so.0(dict_get+0xfb) [0x7f5a982ecb0b] ) 0-dict: !this || key=trusted.glusterfs.dht.mds [Invalid argument]
>[2018-09-05 10:17:09.761521] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.762176] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.762195] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.762621] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.762640] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.763454] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.763516] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.763534] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.764001] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.764062] I [MSGID: 109081] [dht-common.c:5628:dht_setxattr] 0-patchy-dht: fixing the layout of /.trashcan/1/2/3
>[2018-09-05 10:17:09.765237] I [dht-rebalance.c:3353:gf_defrag_process_dir] 0-patchy-dht: migrate data called on /.trashcan/1/2/3
>[2018-09-05 10:17:09.765276] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.765288] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.767603] I [dht-rebalance.c:3567:gf_defrag_process_dir] 0-patchy-dht: Migration operation on dir /.trashcan/1/2/3 took 0.00 secs
>[2018-09-05 10:17:09.769233] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.769254] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.769812] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.769872] I [MSGID: 109081] [dht-common.c:5628:dht_setxattr] 0-patchy-dht: fixing the layout of /.trashcan/1/2
>[2018-09-05 10:17:09.771034] I [dht-rebalance.c:3353:gf_defrag_process_dir] 0-patchy-dht: migrate data called on /.trashcan/1/2
>[2018-09-05 10:17:09.771068] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.771085] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.773110] I [dht-rebalance.c:3567:gf_defrag_process_dir] 0-patchy-dht: Migration operation on dir /.trashcan/1/2 took 0.00 secs
>[2018-09-05 10:17:09.775560] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.775582] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.776102] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.776142] I [MSGID: 109081] [dht-common.c:5628:dht_setxattr] 0-patchy-dht: fixing the layout of /.trashcan/1
>[2018-09-05 10:17:09.777214] I [dht-rebalance.c:3353:gf_defrag_process_dir] 0-patchy-dht: migrate data called on /.trashcan/1
>[2018-09-05 10:17:09.777340] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.777353] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.780831] I [dht-rebalance.c:3567:gf_defrag_process_dir] 0-patchy-dht: Migration operation on dir /.trashcan/1 took 0.00 secs
>[2018-09-05 10:17:09.782982] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.783847] I [MSGID: 109063] [dht-layout.c:693:dht_layout_normalize] 0-patchy-dht: Found anomalies in /.trashcan/internal_op (gfid = 00000000-0000-0000-0000-000000000006). Holes=1 overlaps=0
>[2018-09-05 10:17:09.783889] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.786977] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.787582] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.787598] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.788054] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.788066] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.788715] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.788776] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.788790] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.789268] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.789323] I [MSGID: 109081] [dht-common.c:5628:dht_setxattr] 0-patchy-dht: fixing the layout of /.trashcan/internal_op
>[2018-09-05 10:17:09.791239] I [dht-rebalance.c:3353:gf_defrag_process_dir] 0-patchy-dht: migrate data called on /.trashcan/internal_op
>[2018-09-05 10:17:09.791402] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.791412] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.793270] I [dht-rebalance.c:3567:gf_defrag_process_dir] 0-patchy-dht: Migration operation on dir /.trashcan/internal_op took 0.00 secs
>[2018-09-05 10:17:09.794950] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.795014] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.795509] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.795944] I [MSGID: 109081] [dht-common.c:5628:dht_setxattr] 0-patchy-dht: fixing the layout of /.trashcan
>[2018-09-05 10:17:09.797336] I [dht-rebalance.c:3353:gf_defrag_process_dir] 0-patchy-dht: migrate data called on /.trashcan
>[2018-09-05 10:17:09.797479] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.797486] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.799553] I [dht-rebalance.c:3567:gf_defrag_process_dir] 0-patchy-dht: Migration operation on dir /.trashcan took 0.00 secs
>[2018-09-05 10:17:09.801017] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.801077] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.801598] I [dht-helper.c:933:dht_last_up_subvol] 0-patchy-dht: dht_last_up_subvol() returns with child = patchy-client-1
>[2018-09-05 10:17:09.801655] I [MSGID: 109081] [dht-common.c:5628:dht_setxattr] 0-patchy-dht: fixing the layout of /
>[2018-09-05 10:17:09.802573] I [dht-rebalance.c:3353:gf_defrag_process_dir] 0-patchy-dht: migrate data called on /
>[2018-09-05 10:17:09.802720] I [dht-helper.c:903:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with time = Wed Sep  5 10:17:09 2018
>
>[2018-09-05 10:17:09.802734] I [dht-helper.c:905:dht_first_up_subvol] 0-patchy-dht: dht_first_up_subvol() returns with child = patchy-client-0
>[2018-09-05 10:17:09.803695] I [dht-rebalance.c:2770:gf_defrag_migrate_single_file] 0-patchy-dht: gf_defrag_migrate_single_file() calling gf_defrag_should_i_migrate()
>[2018-09-05 10:17:09.803728] I [dht-rebalance.c:2778:gf_defrag_migrate_single_file] 0-patchy-dht: gf_defrag_migrate_single_file() outside gf_defrag_should_i_migrate()
>[2018-09-05 10:17:09.803793] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.804433] I [dht-rebalance.c:2770:gf_defrag_migrate_single_file] 0-patchy-dht: gf_defrag_migrate_single_file() calling gf_defrag_should_i_migrate()
>[2018-09-05 10:17:09.804457] I [dht-rebalance.c:2778:gf_defrag_migrate_single_file] 0-patchy-dht: gf_defrag_migrate_single_file() outside gf_defrag_should_i_migrate()
>[2018-09-05 10:17:09.804512] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.805159] I [dht-rebalance.c:2794:gf_defrag_migrate_single_file] 0-patchy-dht: gf_defrag_migrate_single_file() outside syncop_lookup()
>[2018-09-05 10:17:09.805183] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-0
>[2018-09-05 10:17:09.805194] I [dht-rebalance.c:2808:gf_defrag_migrate_single_file] 0-patchy-dht: gf_defrag_migrate_single_file() outside dht_subvol_get_hashed()
>[2018-09-05 10:17:09.805202] I [dht-rebalance.c:2819:gf_defrag_migrate_single_file] 0-patchy-dht: gf_defrag_migrate_single_file() outside dht_subvol_get_cached()
>[2018-09-05 10:17:09.805210] I [dht-rebalance.c:2823:gf_defrag_migrate_single_file] 0-patchy-dht: hashed_subvol == cached_subvol
>[2018-09-05 10:17:09.805877] I [dht-rebalance.c:2794:gf_defrag_migrate_single_file] 0-patchy-dht: gf_defrag_migrate_single_file() outside syncop_lookup()
>[2018-09-05 10:17:09.805899] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.805929] I [dht-rebalance.c:2808:gf_defrag_migrate_single_file] 0-patchy-dht: gf_defrag_migrate_single_file() outside dht_subvol_get_hashed()
>[2018-09-05 10:17:09.805939] I [dht-rebalance.c:2819:gf_defrag_migrate_single_file] 0-patchy-dht: gf_defrag_migrate_single_file() outside dht_subvol_get_cached()
>[2018-09-05 10:17:09.805950] I [dht-rebalance.c:2829:gf_defrag_migrate_single_file] 0-patchy-dht: Attempting to migrate data (null) with gfid 00000000-0000-0000-0000-000000000001 from patchy-client-0 -> patchy-client-1
>[2018-09-05 10:17:09.805966] I [dht-rebalance.c:2846:gf_defrag_migrate_single_file] 0-patchy-dht: gf_defrag_migrate_single_file() outside create_frame()
>[2018-09-05 10:17:09.805977] I [dht-rebalance.c:1645:dht_migrate_file] 0-patchy-dht: /rebal2: attempting to move from patchy-client-0 to patchy-client-1
>[2018-09-05 10:17:09.805907] I [dht-rebalance.c:3567:gf_defrag_process_dir] 0-patchy-dht: Migration operation on dir / took 0.00 secs
>[2018-09-05 10:17:09.811217] I [dht-rebalance.c:4804:gf_defrag_start_crawl] 0-DHT: crawling file-system completed
>[2018-09-05 10:17:09.834351] I [dht-helper.c:985:dht_subvol_get_hashed] 0-patchy-dht: dht_subvol_get_hashed() returns with hashed_subvol = patchy-client-1
>[2018-09-05 10:17:09.835258] I [MSGID: 109022] [dht-rebalance.c:2274:dht_migrate_file] 0-patchy-dht: completed migration of /rebal2 from subvolume patchy-client-0 to patchy-client-1
>[2018-09-05 10:17:09.837453] I [MSGID: 109028] [dht-rebalance.c:5229:gf_defrag_status_get] 0-patchy-dht: Rebalance is completed. Time taken is 0.00 secs
>[2018-09-05 10:17:09.837473] I [MSGID: 109028] [dht-rebalance.c:5233:gf_defrag_status_get] 0-patchy-dht: Files migrated: 1, size: 4, lookups: 2, failures: 0, skipped: 0
>[2018-09-05 10:17:09.837797] W [glusterfsd.c:1514:cleanup_and_exit] (-->/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba) [0x7f5a97a806ba] -->/usr/local/sbin/glusterfs(glusterfs_sigwaiter+0xdd) [0x4094bd] -->/usr/local/sbin/glusterfs(cleanup_and_exit+0x4b) [0x4092eb] ) 0-: received signum (15), shutting down
>[2018-09-05 10:17:09.919918]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 200 Y wildcard_exists /d/backends/patchy3/rebal2 ++++++++++
>[2018-09-05 10:17:09.945922]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 201 Y wildcard_exists /d/backends/patchy1/.trashcan/internal_op/rebal2_2018-09-05_101709 ++++++++++
>[2018-09-05 10:17:09.964100]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 203 Y force_umount /mnt/glusterfs/0 ++++++++++
>[2018-09-05 10:17:10.012198]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 206 gluster --mode=script --wignore volume stop patchy force ++++++++++
>[2018-09-05 10:17:12.401400]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 209 gluster --mode=script --wignore volume create patchy1 replica 2 pt-ibmibm16101:/d/backends/patchy11 pt-ibmibm16101:/d/backends/patchy12 ++++++++++
>[2018-09-05 10:17:12.545870]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 212 patchy1 volinfo_field patchy1 Volume Name ++++++++++
>[2018-09-05 10:17:12.629579]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 213 Replicate volinfo_field patchy1 Type ++++++++++
>[2018-09-05 10:17:12.718113]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 214 Created volinfo_field patchy1 Status ++++++++++
>[2018-09-05 10:17:12.799194]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 215 2 brick_count patchy1 ++++++++++
>[2018-09-05 10:17:12.886597]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 218 gluster --mode=script --wignore volume set patchy1 features.trash on ++++++++++
>[2018-09-05 10:17:13.468007]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 219 gluster --mode=script --wignore volume set patchy1 features.trash-internal-op on ++++++++++
>[2018-09-05 10:17:13.727389]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 220 on volinfo_field patchy1 features.trash ++++++++++
>[2018-09-05 10:17:13.836456]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 221 on volinfo_field patchy1 features.trash-internal-op ++++++++++
>[2018-09-05 10:17:13.931056]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 222 start_vol patchy1 /mnt/glusterfs/1 /mnt/glusterfs/1/.trashcan ++++++++++
>[2018-09-05 10:17:15.249196]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 225 [ -d /mnt/glusterfs/1/.trashcan/internal_op ] ++++++++++
>[2018-09-05 10:17:15.298608]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 229 [ -e /d/backends/patchy11/self -a -e /d/backends/patchy12/self ] ++++++++++
>[2018-09-05 10:17:18.340638]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 233 1 online_brick_count ++++++++++
>[2018-09-05 10:17:18.780229]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 235 Y wildcard_exists /d/backends/patchy12/.trashcan/self_2018-09-05_101718 ++++++++++
>[2018-09-05 10:17:18.798799]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 238 gluster --mode=script --wignore volume start patchy1 force ++++++++++
>[2018-09-05 10:17:20.109071]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 239 2 online_brick_count ++++++++++
>[2018-09-05 10:17:20.561543]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 240 Y glustershd_up_status ++++++++++
>[2018-09-05 10:17:23.916793]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 245 Y wildcard_exists /d/backends/patchy11/.trashcan/internal_op/self_2018-09-05_101720 ++++++++++
>[2018-09-05 10:17:23.939435]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 248 gluster --mode=script --wignore volume set patchy trash-dir abc ++++++++++
>[2018-09-05 10:17:24.148241]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 249 start_vol patchy /mnt/glusterfs/0 /mnt/glusterfs/0/abc ++++++++++
>[2018-09-05 10:17:24.678308]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 250 [ -e /mnt/glusterfs/0/abc -a ! -e /mnt/glusterfs/0/.trashcan ] ++++++++++
>[2018-09-05 10:17:24.693566]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 251 Y wildcard_exists /d/backends/patchy1/abc/internal_op/rebal2_2018-09-05_101709 ++++++++++
>[2018-09-05 10:17:24.725683]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 255 [ -e /mnt/glusterfs/0/abc/internal_op ] ++++++++++
>[2018-09-05 10:17:24.781320]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 257 [ -e /mnt/glusterfs/0/abc ] ++++++++++
>[2018-09-05 10:17:24.821957]:++++++++++ G_LOG:./tests/features/trash.t: TEST: 259 [ -e /mnt/glusterfs/0/abc ] ++++++++++

Actions: View

Attachments on bug 1627060: 1482096 | 1482106 | 1504554 | 1504577 | 1534338 | 1534784