Bug 764078 (GLUSTER-2346) - Log message enhancements in GlusterFS - phase 1
Summary: Log message enhancements in GlusterFS - phase 1
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: GLUSTER-2346
Deadline: 2011-03-01
Product: GlusterFS
Classification: Community
Component: logging
Version: mainline
Hardware: All
OS: All
urgent
low
Target Milestone: ---
Assignee: Amar Tumballi
QA Contact:
URL:
Whiteboard:
: 765111 (view as bug list)
Depends On: GLUSTER-2262 GLUSTER-2332
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-02-01 07:21 UTC by Amar Tumballi
Modified: 2015-12-01 16:45 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:
Regression: RTNR
Mount Type: All
Documentation: DP
CRM:
Verified Versions:


Attachments (Terms of Use)

Description Amar Tumballi 2011-02-01 07:21:53 UTC
This bug is an enhancement bug. Tasks involved are

1. Cover whole code path and add the logs in all the missing places

2. Change the log-level of logs to appropriate levels

3. Utilize 'gf_log_callingfn()' (to get the backtrace) wherever necessary.

4. Make log messages more informative (to both users and developers)

5. By default all the critical logs should goto 'syslog'

Comment 1 Anand Avati 2011-02-25 16:06:56 UTC
PATCH: http://patches.gluster.com/patch/6272 in master (dht: log filename on failed reavalidate)

Comment 2 Anand Avati 2011-02-28 14:47:02 UTC
PATCH: http://patches.gluster.com/patch/6275 in master (libglusterfs/xlator.c: whitespace cleanup)

Comment 3 Anand Avati 2011-02-28 14:47:09 UTC
PATCH: http://patches.gluster.com/patch/6276 in master (cluster/afr: Whitespace cleanup)

Comment 4 Anand Avati 2011-02-28 14:47:13 UTC
PATCH: http://patches.gluster.com/patch/6277 in master (cluster/afr: Re-factoring code for alignment)

Comment 5 Anand Avati 2011-02-28 14:47:18 UTC
PATCH: http://patches.gluster.com/patch/6278 in master (libglusterfs/dict.c: Whitespace cleanup)

Comment 6 Anand Avati 2011-02-28 14:47:23 UTC
PATCH: http://patches.gluster.com/patch/6279 in master (performance/io-cache: Whitespace cleanup)

Comment 7 Vijay Bellur 2011-03-09 10:45:22 UTC
PATCH: http://patches.gluster.com/patch/6350 in release-3.1 (libglusterfs: add 'graph_id' in logging)

Comment 8 Vijay Bellur 2011-03-17 15:57:08 UTC
PATCH: http://patches.gluster.com/patch/6458 in master (libglusterfs: logging/mem-pool section white-space cleanup)

Comment 9 Vijay Bellur 2011-03-17 15:57:14 UTC
PATCH: http://patches.gluster.com/patch/6459 in master (libglusterfs: gf_log_nomem() and other minor updates)

Comment 10 Vijay Bellur 2011-03-17 15:57:20 UTC
PATCH: http://patches.gluster.com/patch/6460 in master (libglusterfs: all header files updated)

Comment 11 Vijay Bellur 2011-03-17 15:57:25 UTC
PATCH: http://patches.gluster.com/patch/6462 in master (storage/posix: whitespace cleanup)

Comment 12 Vijay Bellur 2011-03-17 15:57:30 UTC
PATCH: http://patches.gluster.com/patch/6463 in master (libglusterfs/src/*.c: whitespace cleanup)

Comment 13 Vijay Bellur 2011-03-17 15:57:34 UTC
PATCH: http://patches.gluster.com/patch/6464 in master (storage/posix: log enhancements)

Comment 14 Vijay Bellur 2011-03-17 15:57:38 UTC
PATCH: http://patches.gluster.com/patch/6465 in master (glusterfsd: whitespace cleanup)

Comment 15 Vijay Bellur 2011-03-17 15:57:42 UTC
PATCH: http://patches.gluster.com/patch/6466 in master (glusterfsd: log enhancement)

Comment 16 Vijay Bellur 2011-03-17 15:57:46 UTC
PATCH: http://patches.gluster.com/patch/6467 in master (rpc/rpc-lib : log enhancements)

Comment 17 Vijay Bellur 2011-03-17 15:57:50 UTC
PATCH: http://patches.gluster.com/patch/6468 in master (rpc-transport: whitespace cleanup)

Comment 18 Vijay Bellur 2011-03-17 15:57:54 UTC
PATCH: http://patches.gluster.com/patch/6469 in master (rpc-transport: log enhancement)

Comment 19 Vijay Bellur 2011-03-17 15:57:58 UTC
PATCH: http://patches.gluster.com/patch/6470 in master (performance/io-cache: whitespace related changes to adhere to coding guidelines.)

Comment 20 Vijay Bellur 2011-03-17 15:58:02 UTC
PATCH: http://patches.gluster.com/patch/6471 in master (performance/io-cache: logging enhancements)

Comment 21 Vijay Bellur 2011-03-17 15:58:06 UTC
PATCH: http://patches.gluster.com/patch/6472 in master (performance/quick-read: whitespace related changes to adhere to coding guidelines.)

Comment 22 Vijay Bellur 2011-03-17 15:58:10 UTC
PATCH: http://patches.gluster.com/patch/6473 in master (performance/quick-read: propagate errors during open back to actual fops.)

Comment 23 Vijay Bellur 2011-03-17 15:58:14 UTC
PATCH: http://patches.gluster.com/patch/6474 in master (performance/quick-read: logging enhancements)

Comment 24 Vijay Bellur 2011-03-17 15:58:18 UTC
PATCH: http://patches.gluster.com/patch/6475 in master (performance/read-ahead: white space related changes to adhere to coding guidelines.)

Comment 25 Vijay Bellur 2011-03-17 15:58:22 UTC
PATCH: http://patches.gluster.com/patch/6476 in master (performance/read-ahead: logging enhancements.)

Comment 26 Vijay Bellur 2011-03-17 15:58:26 UTC
PATCH: http://patches.gluster.com/patch/6477 in master (performance/write-behind: whitespace cleanup.)

Comment 27 Vijay Bellur 2011-03-17 15:58:30 UTC
PATCH: http://patches.gluster.com/patch/6478 in master (performance/write-behind: logging enhancements)

Comment 28 Vijay Bellur 2011-03-17 15:58:34 UTC
PATCH: http://patches.gluster.com/patch/6479 in master (performance/stat-prefetch: whitespace related changes to adhere to coding guidelines.)

Comment 29 Vijay Bellur 2011-03-17 15:58:38 UTC
PATCH: http://patches.gluster.com/patch/6480 in master (performance/stat-prefetch: logging enhancements)

Comment 30 Vijay Bellur 2011-03-17 15:58:43 UTC
PATCH: http://patches.gluster.com/patch/6481 in master (features/access-control: White space related changes to adhere to coding guidelines.)

Comment 31 Vijay Bellur 2011-03-17 15:58:47 UTC
PATCH: http://patches.gluster.com/patch/6482 in master (features/access-control: logging enhancement)

Comment 32 Vijay Bellur 2011-03-17 15:58:51 UTC
PATCH: http://patches.gluster.com/patch/6483 in master (features/locks: White space related changes to adhere to coding guidelines.)

Comment 33 Vijay Bellur 2011-03-17 15:58:54 UTC
PATCH: http://patches.gluster.com/patch/6484 in master (features/locks: logging enhancement)

Comment 34 Vijay Bellur 2011-03-17 15:58:59 UTC
PATCH: http://patches.gluster.com/patch/6485 in master (cluster/dht: whitespace cleanup)

Comment 35 Vijay Bellur 2011-03-17 15:59:03 UTC
PATCH: http://patches.gluster.com/patch/6486 in master (cluster/dht: log enhancements)

Comment 36 Vijay Bellur 2011-03-17 15:59:07 UTC
PATCH: http://patches.gluster.com/patch/6487 in master (protocol/auth directory updated with whitespace cleanup and proper logs)

Comment 37 Vijay Bellur 2011-03-17 15:59:11 UTC
PATCH: http://patches.gluster.com/patch/6488 in master (protocol/server: White space cleanup and NULL check validations.)

Comment 38 Vijay Bellur 2011-03-17 15:59:15 UTC
PATCH: http://patches.gluster.com/patch/6489 in master (protocol/server: log enhancements)

Comment 39 Vijay Bellur 2011-03-17 15:59:20 UTC
PATCH: http://patches.gluster.com/patch/6490 in master (protocol/client: log enhancement)

Comment 40 Vijay Bellur 2011-03-18 03:11:07 UTC
PATCH: http://patches.gluster.com/patch/6461 in master (libglusterfs/src/*.c: log enhancement)

Comment 41 Vijay Bellur 2011-03-19 00:36:33 UTC
PATCH: http://patches.gluster.com/patch/6508 in master (libglusterfs: added graph id in logging)

Comment 42 Vijay Bellur 2011-03-19 00:36:38 UTC
PATCH: http://patches.gluster.com/patch/6509 in master (debug/io-stats: don't log the dangling volume message)

Comment 43 Vijay Bellur 2011-03-22 08:55:02 UTC
PATCH: http://patches.gluster.com/patch/6553 in master (free priv structure if something fails in init for locks)

Comment 44 Amar Tumballi 2011-03-22 09:56:03 UTC
Round-1 of commits went in. There are 3 major modules pending (cluster/afr, nfs, glusterd/cli), of which I will try to finish afr before the 3.2.0 code-freeze.

Moving this out of the 3.2.0 target.

Comment 45 Vijay Bellur 2011-03-23 04:14:02 UTC
PATCH: http://patches.gluster.com/patch/6558 in master (do not check loc and fd since they can be passed as NULL only)

Comment 46 Vijay Bellur 2011-03-29 08:14:33 UTC
PATCH: http://patches.gluster.com/patch/6575 in master (cluster/afr: whitespace cleanup)

Comment 47 Vijay Bellur 2011-03-31 08:19:51 UTC
PATCH: http://patches.gluster.com/patch/6627 in master (cluster/afr: white-space cleanup - part 2)

Comment 48 Vijay Bellur 2011-04-01 10:08:26 UTC
PATCH: http://patches.gluster.com/patch/6626 in master (cluster/afr: log enhancement - part 2)

Comment 49 Vijay Bellur 2011-04-01 10:08:32 UTC
PATCH: http://patches.gluster.com/patch/6628 in master (cluster/afr: log enhancement - part 3)

Comment 50 Amar Tumballi 2011-04-09 00:49:08 UTC
011-04-09 08:48:31.547443] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:31.547507] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:31.829272] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:31.848020] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:31.897977] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:31.898221] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:31.910918] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:31.976308] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:31.976426] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:31.988662] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.1679] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.8139] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.15971] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.48038] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.59444] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.74549] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.79570] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.92815] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.106067] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.106172] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.199387] W [iobuf.c:669:iobref_size] 0-: iobref not found
[2011-04-09 08:48:32.204672] W [iobuf.c:669:iobref_size] 0-: iobref not found

These logs have no meaning and we are seeing them in client log more than 10 entries per second. Need to make it 'gf_log_callingfn()'. 

http://patches.gluster.com/patch/6680/ does the same. Need to get it in.

Comment 51 Amar Tumballi 2011-04-09 01:10:59 UTC
> [2011-04-09 08:48:32.199387] W [iobuf.c:669:iobref_size] 0-: iobref not found
> [2011-04-09 08:48:32.204672] W [iobuf.c:669:iobref_size] 0-: iobref not found
> 
> These logs have no meaning and we are seeing them in client log more than 10
> entries per second. Need to make it 'gf_log_callingfn()'. 
> 
> http://patches.gluster.com/patch/6680/ does the same. Need to get it in.

[2011-04-09 09:39:23.217592] E [iobuf.c:718:iobref_size] (-->/usr/local/lib/glusterfs/3.1.0git/xlator/performance/io-cache.so(ioc_fault_cbk+0x6d9) [0x7ff51bc44fa9] (-->/usr/local/lib/glusterfs/3.1.0git/xlator/performance/io-cache.so(__ioc_inode_flush+0x2b) [0x7ff51bc3f99b] (-->/usr/local/lib/glusterfs/3.1.0git/xlator/performance/io-cache.so(ioc_page_destroy+0x2b) [0x7ff51bc4348b]))) 0-iobuf: invalid argument: iobref
[2011-04-09 09:39:23.237073] E [iobuf.c:718:iobref_size] (-->/usr/local/lib/glusterfs/3.1.0git/xlator/performance/io-cache.so(ioc_fault_cbk+0x6d9) [0x7ff51bc44fa9] (-->/usr/local/lib/glusterfs/3.1.0git/xlator/performance/io-cache.so(__ioc_inode_flush+0x2b) [0x7ff51bc3f99b] (-->/usr/local/lib/glusterfs/3.1.0git/xlator/performance/io-cache.so(ioc_page_destroy+0x2b) [0x7ff51bc4348b]))) 0-iobuf: invalid argument: iobref

With the patch, it seems to be called from ioc_page_destroy().

Comment 52 Anand Avati 2011-04-11 03:52:46 UTC
PATCH: http://patches.gluster.com/patch/6766 in master (protocol/server: prevent unnessary logs in INFO level)

Comment 53 Anand Avati 2011-04-12 03:50:22 UTC
PATCH: http://patches.gluster.com/patch/6782 in master (libglusterfs/src: bring in VALIDATE_OR_GOTO to args)

Comment 54 Anand Avati 2011-04-13 01:50:04 UTC
PATCH: http://patches.gluster.com/patch/6812 in master (protocol/client: convert to errno before checking for EAGAIN)

Comment 55 Anand Avati 2011-04-13 04:38:50 UTC
PATCH: http://patches.gluster.com/patch/6834 in master (remove excessive logs due to log enhancement)

Comment 56 Anand Avati 2011-04-13 05:04:13 UTC
PATCH: http://patches.gluster.com/patch/6801 in master (mgmt/glusterd: Remove excessive INFO logs)

Comment 57 Anand Avati 2011-04-21 04:39:43 UTC
PATCH: http://patches.gluster.com/patch/6992 in master (glusterd: log the error immedietly after the syscall failure)

Comment 58 Anand Avati 2011-04-21 11:38:36 UTC
PATCH: http://patches.gluster.com/patch/7025 in master (prevent few excessive logs)

Comment 59 Anand Avati 2011-05-03 14:17:05 UTC
PATCH: http://patches.gluster.com/patch/7108 in master (loc_t: add 'gfid' and 'pargfid' fields)

Comment 60 Anand Avati 2011-05-04 09:00:03 UTC
PATCH: http://patches.gluster.com/patch/7142 in master (cluster/afr: set loc gfids for fresh lookup)

Comment 61 Anand Avati 2011-06-14 04:13:47 UTC
PATCH: http://patches.gluster.com/patch/7453 in release-3.1 (loc_t: add 'gfid' and 'pargfid' fields)

Comment 62 Anand Avati 2011-06-14 04:13:55 UTC
PATCH: http://patches.gluster.com/patch/7452 in release-3.2 (loc_t: add 'gfid' and 'pargfid' fields)

Comment 63 Anand Avati 2011-06-16 13:15:45 UTC
PATCH: http://patches.gluster.com/patch/7435 in master (rdma: fix the excessive logs)

Comment 64 Anand Avati 2011-06-17 02:02:17 UTC
PATCH: http://patches.gluster.com/patch/7522 in master (logging: fill proper domain names at places where it is missing)

Comment 65 Amar Tumballi 2011-07-05 01:32:03 UTC
With 3.2.x releases, Phase-1 of log message improvement is complete. I will be opening another bug for Phase-2, which will include more enhancements. Will be targeting that for 3.3.0 release.

Comment 66 Anand Avati 2011-07-29 05:26:34 UTC
CHANGE: http://review.gluster.com/49 (- If open fails and there are any other fops waiting on that open, those fops) merged in release-3.1 by Anand Avati (avati)

Comment 67 Vikas Gorur 2011-08-09 23:26:27 UTC
*** Bug 3379 has been marked as a duplicate of this bug. ***

Comment 68 Anand Avati 2011-09-08 03:30:17 UTC
CHANGE: http://review.gluster.com/372 (most of this resulted in taking a 'ref' on NULL iobuf.) merged in release-3.2 by Anand Avati (avati)

Comment 69 Anand Avati 2011-09-14 07:52:53 UTC
CHANGE: http://review.gluster.com/417 (helps getting output of 'glusterfs --version' from the users while) merged in release-3.1 by Vijay Bellur (vijay)

Comment 70 Anand Avati 2011-09-14 07:53:37 UTC
CHANGE: http://review.gluster.com/415 (helps getting output of 'glusterfs --version' from the users while) merged in master by Vijay Bellur (vijay)

Comment 71 Anand Avati 2011-09-16 02:14:36 UTC
CHANGE: http://review.gluster.com/416 (helps getting output of 'glusterfs --version' from the users while) merged in release-3.2 by Vijay Bellur (vijay)

Comment 72 Anand Avati 2011-10-07 03:35:49 UTC
CHANGE: http://review.gluster.com/562 (Change-Id: I5c2b170977f21c9a83d36f60d9a145c6cc221358) merged in master by Vijay Bellur (vijay)

Comment 73 Anand Avati 2011-10-07 09:58:00 UTC
CHANGE: http://review.gluster.com/567 (Change-Id: I95271def60a1977777f0b5576ae5fbbb59352778) merged in release-3.2 by Vijay Bellur (vijay)

Comment 74 Anand Avati 2011-10-28 09:00:22 UTC
CHANGE: http://review.gluster.com/621 (Change-Id: Ic4cd16618925656a12049f28f9b30bcac2242d4b) merged in release-3.2 by Vijay Bellur (vijay)


Note You need to log in before you can comment on or make changes to this bug.