[Gluster-users] high CPU consumption , 500%~900%

Wed Nov 4 15:30:16 UTC 2015

I hava a  gluster replica 3 volume, there are about  10 clients, and clients has  little file to read or write, but the server  cpu consumption is very hight, about 500%~900% until I turn  cluster.entry-self-heal, cluster.metadata-self-heal, cluster.data-self-heal, cluster.self-heal-daemon off. 

following is the log of a brick of the replica volume.

[2015-11-03 19:28:33.016724] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-105008-2015/11/03-18:28:17:422242-kcr-dist-repl-client-1-0
[2015-11-03 19:28:33.016766] I [server-handshake.c:575:server_setvolume] 0-kcr-dist-repl-server: accepted client from localhost.localdomain-105008-2015/11/03-18:28:17:422242-kcr-dist-repl-client-1-0 (version: 3.5.1)
[2015-11-03 19:28:33.019580] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-105008-2015/11/03-18:28:17:422242-kcr-dist-repl-client-1-0
[2015-11-03 19:28:33.464996] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-4364-2015/11/03-15:25:06:807512-kcr-dist-repl-client-1-0
.....
[2015-11-03 19:30:51.504660] I [server.c:521:server_rpc_notify] 0-kcr-dist-repl-server: disconnecting connectionfrom localhost.localdomain-4364-2015/11/03-15:25:06:807512-kcr-dist-repl-client-1-0
[2015-11-03 19:30:51.504745] I [client_t.c:294:gf_client_put] 0-kcr-dist-repl-server: Shutting down connection localhost.localdomain-4364-2015/11/03-15:25:06:807512-kcr-dist-repl-client-1-0
[2015-11-03 19:32:48.229133] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-4470-2015/11/03-19:32:48:53943-kcr-dist-repl-client-1-0
[2015-11-03 19:32:48.229175] I [server-handshake.c:575:server_setvolume] 0-kcr-dist-repl-server: accepted client from localhost.localdomain-4470-2015/11/03-19:32:48:53943-kcr-dist-repl-client-1-0 (version: 3.5.1)
[2015-11-03 19:32:48.233469] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-4470-2015/11/03-19:32:48:53943-kcr-dist-repl-client-1-0
[2015-11-03 19:37:58.984458] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-30443-2015/11/03-19:37:59:347743-kcr-dist-repl-client-1-0
[2015-11-03 19:37:58.984501] I [server-handshake.c:575:server_setvolume] 0-kcr-dist-repl-server: accepted client from localhost.localdomain-30443-2015/11/03-19:37:59:347743-kcr-dist-repl-client-1-0 (version: 3.5.1)
[2015-11-03 19:37:58.984910] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-30443-2015/11/03-19:37:59:347743-kcr-dist-repl-client-1-0
[2015-11-03 19:46:31.564244] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=mailserver15-7968-2015/11/03-19:46:31:973535-kcr-dist-repl-client-1-0
[2015-11-03 19:46:31.564391] I [server-handshake.c:575:server_setvolume] 0-kcr-dist-repl-server: accepted client from mailserver15-7968-2015/11/03-19:46:31:973535-kcr-dist-repl-client-1-0 (version: 3.5.1)
[2015-11-03 19:46:31.570121] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=mailserver15-7968-2015/11/03-19:46:31:973535-kcr-dist-repl-client-1-0
[2015-11-03 19:54:18.705266] I [server.c:521:server_rpc_notify] 0-kcr-dist-repl-server: disconnecting connectionfrom mailserver15-7968-2015/11/03-19:46:31:973535-kcr-dist-repl-client-1-0
[2015-11-03 19:54:18.705293] I [client_t.c:294:gf_client_put] 0-kcr-dist-repl-server: Shutting down connection mailserver15-7968-2015/11/03-19:46:31:973535-kcr-dist-repl-client-1-0
[2015-11-03 19:54:18.705320] W [entrylk.c:736:pl_entrylk_log_cleanup] 0-kcr-dist-repl-server: releasing lock on 71ff3a55-c15f-42c2-a257-f6e182c532ad held by {client=0xb0a090, pid=-1 lk-owner=dcecf5d2687f0000}
[2015-11-03 19:54:18.705334] I [server-helpers.c:290:do_fd_cleanup] 0-kcr-dist-repl-server: fd cleanup on /2
[2015-11-03 19:54:18.724274] E [client_t.c:384:gf_client_unref] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/locks.so(pl_flush_cbk+0xb9) [0x7fda012a7369] (-->/usr/lib64/glusterfs/3.5.1/xlator/performance/io-threads.so(iot_flush_cbk+0xb9) [0x7fda0108ccb9] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_flush_cbk+0xed) [0x7fda0083420d]))) 0-client_t: client is NULL
....
[2015-11-04 00:21:00.765660] E [client_t.c:384:gf_client_unref] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/locks.so(pl_flush_cbk+0xb9) [0x7fda012a7369] (-->/usr/lib64/glusterfs/3.5.1/xlator/performance/io-threads.so(iot_flush_cbk+0xb9) [0x7fda0108ccb9] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_flush_cbk+0xed) [0x7fda0083420d]))) 0-client_t: client is NULL
[2015-11-04 00:21:17.209306] W [server-resolve.c:440:resolve_anonfd_simple] 0-server: inode for the gfid (0f331c8b-77ce-4e05-af6d-d6c2da694597) is not found. anonymous fd creation failed
[2015-11-04 00:21:17.209373] W [server-resolve.c:440:resolve_anonfd_simple] 0-server: inode for the gfid (0f331c8b-77ce-4e05-af6d-d6c2da694597) is not found. anonymous fd creation failed
[2015-11-04 00:21:17.314340] W [server-resolve.c:440:resolve_anonfd_simple] 0-server: inode for the gfid (0f331c8b-77ce-4e05-af6d-d6c2da694597) is not found. anonymous fd creation failed
[2015-11-04 00:21:17.314410] W [server-resolve.c:440:resolve_anonfd_simple] 0-server: inode for the gfid (0f331c8b-77ce-4e05-af6d-d6c2da694597) is not found. anonymous fd creation failed
[2015-11-04 00:46:58.081022] I [server.c:521:server_rpc_notify] 0-kcr-dist-repl-server: disconnecting connectionfrom centossearch2-8456-2015/11/03-20:01:44:425601-kcr-dist-repl-client-1-0
[2015-11-04 00:46:58.081046] I [client_t.c:294:gf_client_put] 0-kcr-dist-repl-server: Shutting down connection centossearch2-8456-2015/11/03-20:01:44:425601-kcr-dist-repl-client-1-0
[2015-11-04 00:47:05.137319] I [server.c:521:server_rpc_notify] 0-kcr-dist-repl-server: disconnecting connectionfrom fileserver14-29449-2015/11/03-21:34:12:870543-kcr-dist-repl-client-1-0
[2015-11-04 00:47:05.137343] I [client_t.c:294:gf_client_put] 0-kcr-dist-repl-server: Shutting down connection fileserver14-29449-2015/11/03-21:34:12:870543-kcr-dist-repl-client-1-0
[2015-11-04 01:05:55.969120] E [posix.c:369:posix_setattr] 0-kcr-dist-repl-posix: setattr (lstat) on /data/kcr4/.glusterfs/9d/67/9d673cf1-ad0e-42ef-9df0-7f9ef46d14ee failed: No such file or directory
[2015-11-04 01:05:55.969150] I [server-rpc-fops.c:1748:server_setattr_cbk] 0-kcr-dist-repl-server: 264293: SETATTR <gfid:9d673cf1-ad0e-42ef-9df0-7f9ef46d14ee> (9d673cf1-ad0e-42ef-9df0-7f9ef46d14ee) ==> (No such file or directory)
[2015-11-04 01:09:34.988081] I [server.c:521:server_rpc_notify] 0-kcr-dist-repl-server: disconnecting connectionfrom debian-27686-2015/11/03-22:05:17:383058-kcr-dist-repl-client-1-0
[2015-11-04 01:09:34.988110] I [client_t.c:294:gf_client_put] 0-kcr-dist-repl-server: Shutting down connection debian-27686-2015/11/03-22:05:17:383058-kcr-dist-repl-client-1-0
[2015-11-04 01:09:34.988131] W [entrylk.c:736:pl_entrylk_log_cleanup] 0-kcr-dist-repl-server: releasing lock on 347318a1-6f8e-4bc7-aebd-d336545a4e32 held by {client=0xc6dc60, pid=-1 lk-owner=8c6938756e7f0000}
[2015-11-04 01:09:34.988142] I [server-helpers.c:290:do_fd_cleanup] 0-kcr-dist-repl-server: fd cleanup on /625081
[2015-11-04 01:09:34.988188] E [client_t.c:384:gf_client_unref] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/locks.so(pl_flush_cbk+0xb9) [0x7fda012a7369] (-->/usr/lib64/glusterfs/3.5.1/xlator/performance/io-threads.so(iot_flush_cbk+0xb9) [0x7fda0108ccb9] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_flush_cbk+0xed) [0x7fda0083420d]))) 0-client_t: client is NULL
[2015-11-04 02:32:23.812947] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-22172-2015/11/04-02:32:23:863539-kcr-dist-repl-client-1-0
[2015-11-04 02:32:23.812992] I [server-handshake.c:575:server_setvolume] 0-kcr-dist-repl-server: accepted client from localhost.localdomain-22172-2015/11/04-02:32:23:863539-kcr-dist-repl-client-1-0 (version: 3.5.1)
[2015-11-04 02:32:23.815214] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-22172-2015/11/04-02:32:23:863539-kcr-dist-repl-client-1-0
[2015-11-04 02:55:15.668994] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-32807-2015/11/04-02:55:15:635867-kcr-dist-repl-client-1-0
[2015-11-04 02:55:15.669038] I [server-handshake.c:575:server_setvolume] 0-kcr-dist-repl-server: accepted client from localhost.localdomain-32807-2015/11/04-02:55:15:635867-kcr-dist-repl-client-1-0 (version: 3.5.1)
[2015-11-04 02:55:15.669597] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-32807-2015/11/04-02:55:15:635867-kcr-dist-repl-client-1-0
[2015-11-04 03:10:38.016256] I [server.c:521:server_rpc_notify] 0-kcr-dist-repl-server: disconnecting connectionfrom localhost.localdomain-27198-2015/11/03-22:05:25:666462-kcr-dist-repl-client-1-0
[2015-11-04 03:10:38.016281] I [client_t.c:294:gf_client_put] 0-kcr-dist-repl-server: Shutting down connection localhost.localdomain-27198-2015/11/03-22:05:25:666462-kcr-dist-repl-client-1-0
[2015-11-04 03:10:51.482727] I [client_t.c:184:gf_client_get] 0-kcr-dist-repl-server: client_uid=localhost.localdomain-33599-2015/11/04-03:10:51:421969-kcr-dist-repl-client-1-0
...
[2015-11-04 14:10:15.052542] I [glusterfsd-mgmt.c:56:mgmt_cbk_spec] 0-mgmt: Volume file changed
[2015-11-04 14:10:15.052843] I [glusterfsd-mgmt.c:56:mgmt_cbk_spec] 0-mgmt: Volume file changed
[2015-11-04 14:10:15.053073] I [glusterfsd-mgmt.c:1307:mgmt_getspec_cbk] 0-glusterfs: No change in volfile, continuing
[2015-11-04 14:10:15.053224] I [glusterfsd-mgmt.c:1307:mgmt_getspec_cbk] 0-glusterfs: No change in volfile, continuing
[2015-11-04 14:10:15.053549] I [glusterfsd-mgmt.c:1307:mgmt_getspec_cbk] 0-glusterfs: No change in volfile, continuing
[2015-11-04 14:19:54.035644] I [server.c:521:server_rpc_notify] 0-kcr-dist-repl-server: disconnecting connectionfrom file2-71563-2015/11/04-13:37:10:628600-kcr-dist-repl-client-1-0
[2015-11-04 14:19:54.035674] I [client_t.c:294:gf_client_put] 0-kcr-dist-repl-server: Shutting down connection file2-71563-2015/11/04-13:37:10:628600-kcr-dist-repl-client-1-0
[2015-11-04 14:19:54.035697] W [entrylk.c:736:pl_entrylk_log_cleanup] 0-kcr-dist-repl-server: releasing lock on d49d5666-0bb8-4334-89b8-6b4578acc2d9 held by {client=0xbf16a0, pid=-1 lk-owner=842edca1e77f0000}
[2015-11-04 14:19:54.035713] I [server-helpers.c:290:do_fd_cleanup] 0-kcr-dist-repl-server: fd cleanup on /1089090
[2015-11-04 14:19:54.035772] E [client_t.c:384:gf_client_unref] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/locks.so(pl_flush_cbk+0xb9) [0x7fda012a7369] (-->/usr/lib64/glusterfs/3.5.1/xlator/performance/io-threads.so(iot_flush_cbk+0xb9) [0x7fda0108ccb9] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_flush_cbk+0xed) [0x7fda0083420d]))) 0-client_t: client is NULL
[2015-11-04 14:19:54.073643] I [server.c:521:server_rpc_notify] 0-kcr-dist-repl-server: disconnecting connectionfrom fileserver14-44639-2015/11/04-13:43:04:809843-kcr-dist-repl-client-1-0
[2015-11-04 14:19:54.073662] I [client_t.c:294:gf_client_put] 0-kcr-dist-repl-server: Shutting down connection fileserver14-44639-2015/11/04-13:43:04:809843-kcr-dist-repl-client-1-0
[2015-11-04 14:19:54.073678] W [entrylk.c:736:pl_entrylk_log_cleanup] 0-kcr-dist-repl-server: releasing lock on dd1979b6-7e9d-4f04-a23e-dda06c44451c held by {client=0xf8a7f0, pid=-1 lk-owner=840ea47a417f0000}
[2015-11-04 14:19:54.073698] I [server-helpers.c:290:do_fd_cleanup] 0-kcr-dist-repl-server: fd cleanup on /3711849
[2015-11-04 14:19:54.073752] E [client_t.c:384:gf_client_unref] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/locks.so(pl_flush_cbk+0xb9) [0x7fda012a7369] (-->/usr/lib64/glusterfs/3.5.1/xlator/performance/io-threads.so(iot_flush_cbk+0xb9) [0x7fda0108ccb9] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_flush_cbk+0xed) [0x7fda0083420d]))) 0-client_t: client is NULL
[2015-11-04 14:20:00.002641] I [server.c:521:server_rpc_notify] 0-kcr-dist-repl-server: disconnecting connectionfrom centossearch2-20187-2015/11/04-13:31:08:479860-kcr-dist-repl-client-1-0
[2015-11-04 14:20:00.002670] I [client_t.c:294:gf_client_put] 0-kcr-dist-repl-server: Shutting down connection centossearch2-20187-2015/11/04-13:31:08:479860-kcr-dist-repl-client-1-0
[2015-11-04 14:20:00.002702] W [entrylk.c:736:pl_entrylk_log_cleanup] 0-kcr-dist-repl-server: releasing lock on adc865bc-beaa-4825-aaa8-c30f5d83d83d held by {client=0xb896f0, pid=-1 lk-owner=44411a6e1f2b0000}
[2015-11-04 14:20:00.002715] I [server-helpers.c:290:do_fd_cleanup] 0-kcr-dist-repl-server: fd cleanup on /534043
[2015-11-04 14:20:00.002763] E [client_t.c:384:gf_client_unref] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/locks.so(pl_flush_cbk+0xb9) [0x7fda012a7369] (-->/usr/lib64/glusterfs/3.5.1/xlator/performance/io-threads.so(iot_flush_cbk+0xb9) [0x7fda0108ccb9] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_flush_cbk+0xed) [0x7fda0083420d]))) 0-client_t: client is NULL
....
[2015-11-04 14:25:23.458465] I [server.c:521:server_rpc_notify] 0-kcr-dist-repl-server: disconnecting connectionfrom debian1-2221-2015/11/04-13:22:15:614835-kcr-dist-repl-client-1-0
[2015-11-04 14:25:23.458496] I [client_t.c:294:gf_client_put] 0-kcr-dist-repl-server: Shutting down connection debian1-2221-2015/11/04-13:22:15:614835-kcr-dist-repl-client-1-0
[2015-11-04 14:25:23.458516] W [entrylk.c:736:pl_entrylk_log_cleanup] 0-kcr-dist-repl-server: releasing lock on 3a1b182b-b239-4baa-8a0a-d68f3d8ad3ad held by {client=0xe54b40, pid=-1 lk-owner=8c997a45007f0000}
[2015-11-04 14:25:23.458531] I [server-helpers.c:290:do_fd_cleanup] 0-kcr-dist-repl-server: fd cleanup on /2665638
[2015-11-04 14:25:23.458578] E [client_t.c:384:gf_client_unref] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/locks.so(pl_flush_cbk+0xb9) [0x7fda012a7369] (-->/usr/lib64/glusterfs/3.5.1/xlator/performance/io-threads.so(iot_flush_cbk+0xb9) [0x7fda0108ccb9] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_flush_cbk+0xed) [0x7fda0083420d]))) 0-client_t: client is NULL
[2015-11-04 14:25:23.620508] I [socket.c:3134:socket_submit_reply] 0-tcp.kcr-dist-repl-server: not connected (priv->connected = -1)
[2015-11-04 14:25:23.620528] E [rpcsvc.c:1244:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x17603, Program: GlusterFS 3.3, ProgVers: 330, Proc: 27) to rpc-transport (tcp.kcr-dist-repl-server)
[2015-11-04 14:25:23.620583] E [server.c:190:server_submit_reply] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/marker.so(marker_lookup_cbk+0x10e) [0x7fda00c6314e] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_lookup_cbk+0x113) [0x7fda0082cc63] (-->/usr/lib64/glusterfs/3.5.1/xlator/protocol/server.so(server_lookup_cbk+0x34d) [0x7fda00613f4d]))) 0-: Reply submission failed
[2015-11-04 14:25:23.620658] E [rpcsvc.c:1244:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x17604, Program: GlusterFS 3.3, ProgVers: 330, Proc: 27) to rpc-transport (tcp.kcr-dist-repl-server)
[2015-11-04 14:25:23.620685] E [server.c:190:server_submit_reply] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/marker.so(marker_lookup_cbk+0x10e) [0x7fda00c6314e] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_lookup_cbk+0x113) [0x7fda0082cc63] (-->/usr/lib64/glusterfs/3.5.1/xlator/protocol/server.so(server_lookup_cbk+0x34d) [0x7fda00613f4d]))) 0-: Reply submission failed
[2015-11-04 14:25:23.620743] E [rpcsvc.c:1244:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x17605, Program: GlusterFS 3.3, ProgVers: 330, Proc: 27) to rpc-transport (tcp.kcr-dist-repl-server)
[2015-11-04 14:25:23.620766] E [server.c:190:server_submit_reply] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/marker.so(marker_lookup_cbk+0x10e) [0x7fda00c6314e] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_lookup_cbk+0x113) [0x7fda0082cc63] (-->/usr/lib64/glusterfs/3.5.1/xlator/protocol/server.so(server_lookup_cbk+0x34d) [0x7fda00613f4d]))) 0-: Reply submission failed
[2015-11-04 14:25:23.620831] E [rpcsvc.c:1244:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x17606, Program: GlusterFS 3.3, ProgVers: 330, Proc: 27) to rpc-transport (tcp.kcr-dist-repl-server)
[2015-11-04 14:25:23.620854] E [server.c:190:server_submit_reply] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/marker.so(marker_lookup_cbk+0x10e) [0x7fda00c6314e] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_lookup_cbk+0x113) [0x7fda0082cc63] (-->/usr/lib64/glusterfs/3.5.1/xlator/protocol/server.so(server_lookup_cbk+0x34d) [0x7fda00613f4d]))) 0-: Reply submission failed
[2015-11-04 14:25:23.620910] E [rpcsvc.c:1244:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x17607, Program: GlusterFS 3.3, ProgVers: 330, Proc: 27) to rpc-transport (tcp.kcr-dist-repl-server)
[2015-11-04 14:25:23.620939] E [server.c:190:server_submit_reply] (-->/usr/lib64/glusterfs/3.5.1/xlator/features/marker.so(marker_lookup_cbk+0x10e) [0x7fda00c6314e] (-->/usr/lib64/glusterfs/3.5.1/xlator/debug/io-stats.so(io_stats_lookup_cbk+0x113) [0x7fda0082cc63] (-->/usr/lib64/glusterfs/3.5.1/xlator/protocol/server.so(server_lookup_cbk+0x34d) [0x7fda00613f4d]))) 0-: Reply submission failed
[20

Thanks you for any help ...Norbert
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.gluster.org/pipermail/gluster-users/attachments/20151104/82071ed2/attachment.html>