Kool Aid Served Daily

I've been working on a kernel to user space door call which encodes the data in an XDR stream. Normally, I view XDR output as it goes across the wire with snoop. As this stuff is not exposed, I ended up writing a little piece of code to dump the bits on the console. I know I had some problems when I wrote it, but I'm just going to give you the current code:

void
sped_xdr_dump(XDR *x)
{
        int     i;
        int     j;
        char    buf[100];
        char    str[10];
        char    cbuf[4];

        j = 0;
        memset(&cbuf, '\0', 4);

        buf[0] = '\0';
        for (i = 0; i < x->x_handy; i++) {
                cbuf[0] = x->x_private[i];
                sprintf(str, " %X", cbuf[0]);
                strcat(buf, str);
                j++;
                if (j == 8) {
                        syslog(LOG_ERR, "%s", buf);
                        j = 0;
                        buf[0] = '\0';
                }
        }

        if (j != 0) {
                syslog(LOG_ERR, "%s", buf);
        }
}

The crap with cbuf is where I consider this code to be fat. It is a lazy hack because I felt the bytes were running together. It is lazy because I don't need it. And it is where I should be looking for bugs. Anyway, with the following input:

> fec3fce8::print XDR 
{
    x_op = 1 (XDR_DECODE)
    x_ops = 0xfee45bd8
    x_public = 0
    x_private = 0xfec3fdd0
    x_base = 0xfec3fdd0
    x_handy = 0x30
}
> 0xfec3fdd0/48B
0xfec3fdd0:     0       0       0       2       0       0       0       0
                0       0       0       2       0       3       d       a0
                0       0       0       a       2       0       0       0
                0       0       0       a       2f      6e      69      70
                70      79      2f      68      32      62      0       0
                0       0       0       0       0       0       0       0

As shown by mdb, which I don't like, I get the following output:

Apr  3 12:04:06 pnfs-3-15 last message repeated 1 time
Apr  3 12:04:22 pnfs-3-15 sped[100920]:  0 0 0 2 0 0 0 0
Apr  3 12:04:22 pnfs-3-15 sped[100920]:  0 0 0 2 0 3 D FFFFFFA0
Apr  3 12:04:22 pnfs-3-15 sped[100920]:  0 0 0 A 2 0 0 0
Apr  3 12:04:22 pnfs-3-15 sped[100920]:  0 0 0 A 2F 6E 69 70
Apr  3 12:04:22 pnfs-3-15 sped[100920]:  70 79 2F 68 32 62 0 0
Apr  3 12:04:22 pnfs-3-15 sped[100920]:  0 0 0 0 0 0 0 0

Where is FFFFFFA0 coming from? Okay, I took the code and stuck it in a driver:

> cat y.c
#include <sys/systm.h>
#include <sys/sdt.h>
#include <rpc/types.h>
#include <rpc/svc.h>
#include <rpc/xdr.h>

#include <rpc/auth_sys.h>

#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <string.h>

void
sped_xdr_dump(char *jack, int len)
{
        int     i;
        int     j;
        char    buf[100];
        char    str[10];
        char    cbuf[4];

        j = 0;
        memset(&cbuf, '\0', 4);

        buf[0] = '\0';
        for (i = 0; i < len; i++) {
                cbuf[0] = jack[i];
                sprintf(str, " %X", cbuf[0]);
                strcat(buf, str);
                j++;
                if (j == 8) {
                        printf("%s\n", buf);
                        j = 0;
                        buf[0] = '\0';
                }
        }

        if (j != 0) {
                printf("%s\n", buf);
        }
}

int
main(int argc, char *argv[])
{
	char	jack[] = {
            0x0,  0x0,  0x0,  0x2,  0x0,  0x0,  0x0,  0x0,
            0x0,  0x0,  0x0,  0x2,  0x0,  0x3,  0xd,  0xa0,
            0x0,  0x0,  0x0,  0xa,  0x2,  0x0,  0x0,  0x0,
            0x0,  0x0,  0x0,  0xa,  0x2f, 0x6e, 0x69, 0x70,
            0x70, 0x79, 0x2f, 0x68, 0x32, 0x62, 0x0,  0x0,
            0x0,  0x0,  0x0,  0x0,  0x0,  0x0,  0x0,  0x0

	};

	sped_xdr_dump(jack, sizeof(jack));
	return (0);
}
>  ./a.out 
 0 0 0 2 0 0 0 0
 0 0 0 2 0 3 D FFFFFFA0
 0 0 0 A 2 0 0 0
 0 0 0 A 2F 6E 69 70
 70 79 2F 68 32 62 0 0
 0 0 0 0 0 0 0 0

So, I've captured the problem. Using gdb, I can get to the heart of the issue:

Breakpoint 3, sped_xdr_dump (jack=0x8047134 "", len=48) at x.c:32
32	                cbuf[0] = jack[i];
5: str = " D\000\000\000\000\000\000X\003"
4: j = 7
3: i = 15
2: jack[i] = -96 '?'
1: cbuf = "\r\000\000"
(gdb) p jack[i-1]
$1 = 13 '\r'
(gdb) q

As tempting as it is to say that I'm grabbing a bit from the previous word, it is clear that the fat code is really working. And while I could do shenanigans with bit shifting, the problem isn't in the way I am explicitly pulling out the data. Nor is the " %X" an issue.

The real issue is that I've got the wrong type of data, I'm trying to print out signed data, and 'A0' has a high order bit set.

> diff y.c y1.c	
21c21
<         char    cbuf[4];
---
>         unsigned char    cbuf[4];
> ./a.out 
 0 0 0 2 0 0 0 0
 0 0 0 2 0 3 D A0
 0 0 0 A 2 0 0 0
 0 0 0 A 2F 6E 69 70
 70 79 2F 68 32 62 0 0
 0 0 0 0 0 0 0 0

Okay, we can do better than that. We need to get rid of cbuf:

> diff y.c y2.c
21d20
<         char    cbuf[4];
24d22
<         memset(&cbuf, '\0', 4);
28,29c26
<                 cbuf[0] = jack[i];
<                 sprintf(str, " %X", cbuf[0]);
---
>                 sprintf(str, " %X", (unsigned char)jack[i]);
> ./a.out
 0 0 0 2 0 0 0 0
 0 0 0 2 0 3 D A0
 0 0 0 A 2 0 0 0
 0 0 0 A 2F 6E 69 70
 70 79 2F 68 32 62 0 0
 0 0 0 0 0 0 0 0

And we need to clean-up the output:

> diff y2.c y3.c
26c26
<                 sprintf(str, " %X", (unsigned char)jack[i]);
---
>                 sprintf(str, " %2X", (unsigned char)jack[i]);
> ./a.out
  0  0  0  2  0  0  0  0
  0  0  0  2  0  3  D A0
  0  0  0  A  2  0  0  0
  0  0  0  A 2F 6E 69 70
 70 79 2F 68 32 62  0  0
  0  0  0  0  0  0  0  0

I might be able to make it even more either smarter or compact, but it is now throw away code. But even thow away code has to be functionally correct. When it isn't, look for areas where you are doing more work than you need to. If you remember you tried something and weren't convinced it would work, and it only worked partially, go back and question that code.