trace_seq_printf/.print_line question

[Arnaldo Carvalho de Melo <acme@redhat.com>]

Jens, just a FYI about this stuff, not yet ready for reviewing.

Hi Frédéric, Steven,

	Have you guys ever get into this kind of situation?

[root@mica linux-2.6-tip]# cat /sys/kernel/debug/tracing/trace | tail
       kjournald-480   [000]   593.219805:   C   W 2149459 + 8 [0]
          <idle>-0     [000]   593.219849:   A  WS 2149467 + 8 <- (8,2) 44952
       kjournald-480   [000]   607.210959:   Q  WS 2149467 + 8
       kjournald-480   [000]   607.210960:   G  WS 2149467 + 8
       kjournald-480   [000]   607.210963:   P   N
       kjournald-480   [000]   607.210964:   I   W 2149467 + 8
       kjournald-480   [000]   607.210965:   D   W 2149467 + 8
       kjournald-480   [000]   607.210967:   U   N 1
       kjournald-480   [000]   607.210971:   C   W 2149467 + 8 [0]
          <idle>-0     [000]   607.211049: [root@mica linux-2.6-tip]# 

[root@mica linux-2.6-tip]# head /sys/kernel/debug/tracing/trace
# tracer: blk
#
#           TASK-PID    CPU#    TIMESTAMP  FUNCTION
#              | |       |          |         |
  A   W 2147707 + 8 <- (8,2) 43192
       kjournald-480   [000]   254.428659:   Q   W 2147707 + 8
       kjournald-480   [000]   254.428661:   G   W 2147707 + 8
       kjournald-480   [000]   254.428663:   I   W 100410211 + 8
         pdflush-261   [000]   147.328259:   P   N
       kjournald-480   [000]   254.428664:   I   W 2147707 + 8
[root@mica linux-2.6-tip]# 

This is happening in an experiment I'm doing in porting blktrace to the
tracing/ring_buffer infrastructure, the problem always happens at this
function:

static int blk_log_remap(struct trace_seq *s, struct blk_io_entry *t)
{
        char rwbs[6];
        struct blk_io_trace_remap r = { .device = 0, };

        get_pdu_remap(t, &r);
        t->device = r.device_from;
        fill_rwbs(rwbs, t);
        return trace_seq_printf(s, "  A %3s %llu + %u <- (%d,%d) %llu\n",
                                rwbs, (unsigned long long)t->sector,
                                t_sec(t), MAJOR(r.device), MINOR(r.device),
                                (unsigned long long)r.sector);
}

And the registered .print_line routine does check the return of
trace_seq_printf:

               if (!ret)
                        return TRACE_TYPE_PARTIAL_LINE;
        }
        default:
                return TRACE_TYPE_UNHANDLED;
        }

        return TRACE_TYPE_HANDLED;
}

Full patch, still WIPish:
http://oops.ghostprotocols.net:81/acme/blkftrace.patch

- Arnaldo