ocfs2: Reduce object size of mlog uses

Using a function for __mlog_printk instead of a macro reduces the object size of built-in.o more than 120KB, or ~10% overall (x86-64 defconfig with all ocfs2 options)

$ size fs/ocfs2/built-in.o*
   text	   data	    bss	    dec	    hex	filename
 936255	 118071	 134408	1188734	 12237e	fs/ocfs2/built-in.o.new
1064081	 118071	 134408	1316560	 1416d0	fs/ocfs2/built-in.o.old

fs/ocfs2/cluster/masklog.c +7 -0

@@ -64,6 +64,23 @@ static ssize_t mlog_mask_store(u64 mask, const char *buf, size_t count)
 	return count;
 }
 
+void __mlog_printk(const char *level, const char *func, int line,
+		   const char *fmt, ...)
+{
+	struct va_format vaf;
+	va_list args;
+
+	va_start(args, fmt);

fs/ocfs2/cluster/masklog.c +0 -0

 struct mlog_attribute {
 	struct attribute attr;
 	u64 mask;

fs/ocfs2/cluster/masklog.h +0 -0

index 7fdc25a..6036e6a 100644

fs/ocfs2/cluster/masklog.h +2 -4

 	unsigned long _cpu = get_cpu();	\
 	put_cpu();			\
 	_cpu;				\

@@ -178,21 +179,25 @@ extern struct mlog_bits mlog_and_bits, mlog_not_bits;
  * before ##args is intentional. Otherwise, gcc 2.95 will eat the
  * previous token if args expands to nothing.
  */
-#define __mlog_printk(level, fmt, args...)				\
-	printk(level "(%s,%u,%lu):%s:%d " fmt, current->comm,		\
-	       task_pid_nr(current), __mlog_cpu_guess,			\
-	       __PRETTY_FUNCTION__, __LINE__ , ##args)
+__printf(4, 5)
+void __mlog_printk(const char *level, const char *func, int line,

fs/ocfs2/cluster/masklog.h +2 -1

-			__mlog_printk(KERN_ERR, "ERROR: "fmt , ##args);	\
+			__mlog_printk(KERN_ERR, __func__, __LINE__,	\
+				      "ERROR: " fmt, ##__VA_ARGS__);	\
 		else if (__m & ML_NOTICE)				\

Quoted 8 lines · On Fri, 17 Apr 2015 00:17:50 -0700 Joe Perches <[email protected]> wrote:

Using a function for __mlog_printk instead of a macro reduces the object size of built-in.o more than 120KB, or ~10% overall (x86-64 defconfig with all ocfs2 options)

$ size fs/ocfs2/built-in.o*
   text	   data	    bss	    dec	    hex	filename
 936255	 118071	 134408	1188734	 12237e	fs/ocfs2/built-in.o.new
1064081	 118071	 134408	1316560	 1416d0	fs/ocfs2/built-in.o.old

It's a start.

Quoted 20 lines

fs/ocfs2/cluster/masklog.c +14 -0

@@ -64,6 +64,23 @@ static ssize_t mlog_mask_store(u64 mask, const char *buf, size_t count)
 	return count;
 }
 
+void __mlog_printk(const char *level, const char *func, int line,
+		   const char *fmt, ...)
+{
+	struct va_format vaf;
+	va_list args;
+
+	va_start(args, fmt);
+
+	vaf.fmt = fmt;
+	vaf.va = &args;
+
+	printk("%s(%s,%u,%lu):%s:%d %pV",
+	       level, current->comm, task_pid_nr(current), __mlog_cpu_guess,
+	       func, line, &vaf);

fs/ocfs2/cluster/masklog.c static ssize_t mlog_mask_store(u64 mask, const char *buf, size_t count) · line 83

Quoted 3 lines

fs/ocfs2/cluster/masklog.c +3 -0

+
+	va_end(args);
+}

Logging function-name and line-number was a bit weird. I wonder if anyone will mind if this is converted to file-n-line, as God intended. That will shrink rodata a bit, because number-of-files is a lot less than number-of-functions.

fs/ocfs2/cluster/masklog.c static ssize_t mlog_mask_store(u64 mask, const char *buf, size_t count)

Quoted 8 lines

fs/ocfs2/cluster/masklog.c +2 -1

-#define mlog(mask, fmt, args...) do {					\
+#define mlog(mask, fmt, ...)						\
+do {									\
 	u64 __m = MLOG_MASK_PREFIX | (mask);				\
 	if ((__m & ML_ALLOWED_BITS) &&					\
 	    __mlog_test_u64(__m, mlog_and_bits) &&			\
 	    !__mlog_test_u64(__m, mlog_not_bits)) {			\
 		if (__m & ML_ERROR)					\

All this goop can also be uninlined?

I guess this patch is a step on the way - a 10% shrink is decent. But I believe that with full uninlining of the ocfs2 logging code we can shrink the filesystem's footprint by 50%.

If you feel like undertaking such a rotorooting then go wild - that should wake 'em up ;)

Quoted 8 lines · On Fri, 17 Apr 2015 00:17:50 -0700 Joe Perches <[email protected]> wrote:

Using a function for __mlog_printk instead of a macro reduces the object size of built-in.o more than 120KB, or ~10% overall (x86-64 defconfig with all ocfs2 options)

$ size fs/ocfs2/built-in.o*
   text	   data	    bss	    dec	    hex	filename
 936255	 118071	 134408	1188734	 12237e	fs/ocfs2/built-in.o.new
1064081	 118071	 134408	1316560	 1416d0	fs/ocfs2/built-in.o.old

It's a start.

Quoted 20 lines

fs/ocfs2/cluster/masklog.c +14 -0

@@ -64,6 +64,23 @@ static ssize_t mlog_mask_store(u64 mask, const char *buf, size_t count)
 	return count;
 }
 
+void __mlog_printk(const char *level, const char *func, int line,
+		   const char *fmt, ...)
+{
+	struct va_format vaf;
+	va_list args;
+
+	va_start(args, fmt);
+
+	vaf.fmt = fmt;
+	vaf.va = &args;
+
+	printk("%s(%s,%u,%lu):%s:%d %pV",
+	       level, current->comm, task_pid_nr(current), __mlog_cpu_guess,
+	       func, line, &vaf);

fs/ocfs2/cluster/masklog.c static ssize_t mlog_mask_store(u64 mask, const char *buf, size_t count) · line 83

Quoted 3 lines

fs/ocfs2/cluster/masklog.c +3 -0

+
+	va_end(args);
+}

Logging function-name and line-number was a bit weird. I wonder if anyone will mind if this is converted to file-n-line, as God intended. That will shrink rodata a bit, because number-of-files is a lot less than number-of-functions.

Quoted 4 lines

fs/ocfs2/cluster/masklog.c +2 -1

-			__mlog_printk(KERN_ERR, "ERROR: "fmt , ##args);	\
+			__mlog_printk(KERN_ERR, __func__, __LINE__,	\
+				      "ERROR: " fmt, ##__VA_ARGS__);	\

fs/ocfs2/cluster/masklog.c static ssize_t mlog_mask_store(u64 mask, const char *buf, size_t count)

Quoted 10 lines

fs/ocfs2/cluster/masklog.c +5 -2

 		else if (__m & ML_NOTICE)				\
-			__mlog_printk(KERN_NOTICE, fmt , ##args);	\
-		else __mlog_printk(KERN_INFO, fmt , ##args);		\
+			__mlog_printk(KERN_NOTICE, __func__, __LINE__,	\
+				      fmt, ##__VA_ARGS__);		\
+		else							\
+			__mlog_printk(KERN_INFO, __func__, __LINE__,	\
+				      fmt, ##__VA_ARGS__);		\
 	}								\
 } while (0)

I guess this patch is a step on the way - a 10% shrink is decent. But I believe that with full uninlining of the ocfs2 logging code we can shrink the filesystem's footprint by 50%.

This code needs some pretty serious rework and rethink, perhaps involving a change to the emitted info. I was hoping one of the ocfs2 developers would take the bait, but they're all in hiding.

If you feel like undertaking such a rotorooting then go wild - that should wake 'em up ;)

Quoted 3 lines

This code needs some pretty serious rework and rethink, perhaps involving a change to the emitted info. I was hoping one of the ocfs2 developers would take the bait, but they're all in hiding.

If it functions the same and doesn't have a major performance change, I'm pretty sure it'll be fine. We sometimes ask customers to enable some of the debugging if they are having an issue. I would ask that it be tested on a live system - a local fs, no cluster or cluster config required.

Quoted 4 lines · On Thu, 23 Apr 2015 16:04:18 -0700 Mark Fasheh <[email protected]> wrote:

Quoted 3 lines

This code needs some pretty serious rework and rethink, perhaps involving a change to the emitted info. I was hoping one of the ocfs2 developers would take the bait, but they're all in hiding.

Quoted 4 lines

If it functions the same and doesn't have a major performance change, I'm pretty sure it'll be fine. We sometimes ask customers to enable some of the debugging if they are having an issue. I would ask that it be tested on a live system - a local fs, no cluster or cluster config required.

Is there a simpleton's guide to testing ocfs2 on a local disk? One which assumes a starting point of "knows how to type".

Quoted 11 lines · Andrew Morton

Quoted 8 lines · On Thu, 23 Apr 2015 16:04:18 -0700 Mark Fasheh <[email protected]> wrote:

Quoted 3 lines

This code needs some pretty serious rework and rethink, perhaps involving a change to the emitted info. I was hoping one of the ocfs2 developers would take the bait, but they're all in hiding.

If it functions the same and doesn't have a major performance change, I'm pretty sure it'll be fine. We sometimes ask customers to enable some of the debugging if they are having an issue. I would ask that it be tested on a live system - a local fs, no cluster or cluster config required.

Quoted 2 lines

Is there a simpleton's guide to testing ocfs2 on a local disk? One which assumes a starting point of "knows how to type".

See http://docs.oracle.com/cd/E37670_01/E41138/html/ol_crlcl_ocfs2.html

Quoted 2 lines · Andrew Morton

If you feel like undertaking such a rotorooting then go wild - that should wake 'em up ;)

Ok, I've taken the bait :)

Quoted 5 lines · Mark Fasheh

Quoted 2 lines · Andrew Morton

If you feel like undertaking such a rotorooting then go wild - that should wake 'em up ;)

Ok, I've taken the bait :)

"Here fishy, fishy...", erm, "Here Fasheh, Fasheh..."

With that out of the way:

A couple of possibilities:

o I wonder whether or not file/func/line matter at all. I think they don't.
Removing them would reduce code size ~90K

o There's a small logging improvement possible in tcp.c.

Both below:

----------------------------------------------------------

 fs/ocfs2/cluster/masklog.c | 7 +++----
 fs/ocfs2/cluster/masklog.h | 8 +++-----
 2 files changed, 6 insertions(+), 9 deletions(-)

fs/ocfs2/cluster/masklog.c +3 -4

index fc5e522..8b9816f 100644
@@ -77,8 +77,7 @@ static ssize_t mlog_mask_store(u64 mask, const char *buf, size_t count)
 	_cpu;								\
 })
 
-void __mlog_printk(const u64 *mask, const char *func, int line,
-		   const char *fmt, ...)
+void __mlog_printk(const u64 *mask, const char *fmt, ...)
 {
 	struct va_format vaf;
 	va_list args;

@@ -103,9 +102,9 @@ void __mlog_printk(const u64 *mask, const char *func, int line,
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	printk("%s(%s,%u,%lu):%s:%d %s%pV",
+	printk("%s(%s,%u,%lu) %s%pV",
 	       level, current->comm, task_pid_nr(current), __mlog_cpu_guess,
-	       func, line, prefix, &vaf);
+	       prefix, &vaf);
 
 	va_end(args);
 }

fs/ocfs2/cluster/masklog.h +3 -6

index 308ea0e..9e93f19 100644
@@ -162,9 +162,8 @@ extern struct mlog_bits mlog_and_bits, mlog_not_bits;
 
 #endif
 
-__printf(4, 5)
-void __mlog_printk(const u64 *m, const char *func, int line,
-		   const char *fmt, ...);
+__printf(2, 3)
+void __mlog_printk(const u64 *m, const char *fmt, ...);
 
 /*
  * Testing before the __mlog_printk call lets the compiler eliminate the

@@ -174,8 +173,7 @@ void __mlog_printk(const u64 *m, const char *func, int line,
 do {									\
 	u64 _m = MLOG_MASK_PREFIX | (mask);				\
 	if (_m & ML_ALLOWED_BITS)					\
-		__mlog_printk(&_m, __func__, __LINE__, fmt,		\
-			      ##__VA_ARGS__);				\
+		__mlog_printk(&_m, fmt, ##__VA_ARGS__);			\
 } while (0)
 
 #define mlog_errno(st) ({						\
 
----------------------------------------------------------
 
 fs/ocfs2/cluster/tcp.c | 60 +++++++++++++++++++++++++++++++-------------------
 1 file changed, 37 insertions(+), 23 deletions(-)

fs/ocfs2/cluster/tcp.c +37 -23

index 56c403a..2c74973 100644
@@ -78,29 +78,43 @@
 			  &sc->sc_node->nd_ipv4_address,		\
 			  ntohs(sc->sc_node->nd_ipv4_port)
 
-/*
- * In the following two log macros, the whitespace after the ',' just
- * before ##args is intentional. Otherwise, gcc 2.95 will eat the
- * previous token if args expands to nothing.
- */
-#define msglog(hdr, fmt, args...) do {					\
-	typeof(hdr) __hdr = (hdr);					\
-	mlog(ML_MSG, "[mag %u len %u typ %u stat %d sys_stat %d "	\
-	     "key %08x num %u] " fmt,					\
-	     be16_to_cpu(__hdr->magic), be16_to_cpu(__hdr->data_len), 	\
-	     be16_to_cpu(__hdr->msg_type), be32_to_cpu(__hdr->status),	\
-	     be32_to_cpu(__hdr->sys_status), be32_to_cpu(__hdr->key),	\
-	     be32_to_cpu(__hdr->msg_num) ,  ##args);			\
-} while (0)
-
-#define sclog(sc, fmt, args...) do {					\
-	typeof(sc) __sc = (sc);						\
-	mlog(ML_SOCKET, "[sc %p refs %d sock %p node %u page %p "	\
-	     "pg_off %zu] " fmt, __sc,					\
-	     atomic_read(&__sc->sc_kref.refcount), __sc->sc_sock,	\
-	    __sc->sc_node->nd_num, __sc->sc_page, __sc->sc_page_off ,	\
-	    ##args);							\
-} while (0)
+__printf(2, 3)
+void msglog(struct o2net_msg *hdr, const char *fmt, ...)
+{
+	struct va_format vaf;
+	va_list args;
+
+	va_start(args, fmt);
+
+	vaf.fmt = fmt;
+	vaf.va = &args;
+
+	mlog(ML_MSG, "[mag %u len %u typ %u stat %d sys_stat %d key %08x num %u] %pV",
+	     be16_to_cpu(hdr->magic), be16_to_cpu(hdr->data_len),
+	     be16_to_cpu(hdr->msg_type), be32_to_cpu(hdr->status),
+	     be32_to_cpu(hdr->sys_status), be32_to_cpu(hdr->key),
+	     be32_to_cpu(hdr->msg_num), &vaf);
+
+	va_end(args);
+}
+
+__printf(2, 3)
+void sclog(struct o2net_sock_container *sc, const char *fmt, ...)
+{
+	struct va_format vaf;
+	va_list args;
+
+	va_start(args, fmt);
+
+	vaf.fmt = fmt;
+	vaf.va = &args;
+
+	mlog(ML_SOCKET, "[sc %p refs %d sock %p node %u page %p pg_off %zu] %pV",
+	     sc, atomic_read(&sc->sc_kref.refcount), sc->sc_sock,
+	     sc->sc_node->nd_num, sc->sc_page, sc->sc_page_off, &vaf);
+
+	va_end(args);
+}
 
 static DEFINE_RWLOCK(o2net_handler_lock);
 static struct rb_root o2net_handler_tree = RB_ROOT;

_______________________________________________
Ocfs2-devel mailing list
Ocfs2-devel at oss.oracle.com
https://oss.oracle.com/mailman/listinfo/ocfs2-devel

Quoted 7 lines · Joe Perches

Quoted 4 lines · Mark Fasheh

Quoted 2 lines · Andrew Morton

If you feel like undertaking such a rotorooting then go wild - that should wake 'em up ;)

Ok, I've taken the bait :)

"Here fishy, fishy...", erm, "Here Fasheh, Fasheh..." With that out of the way:

:)

Quoted 5 lines

A couple of possibilities:

o I wonder whether or not file/func/line matter at all. I think they don't.
Removing them would reduce code size ~90K

They do to those that are debugging live Ocfs2 modules. I would like at least one pair kept please.

Quoted 1 line

o There's a small logging improvement possible in tcp.c.

This part looks good to me though, thanks for it.