dccp: Reduce noise in output and convert to ktime_t
This fixes the problem that dccp_probe output can grow quite large without apparent benefit (many identical data points), creating huge files (up to over one Gigabyte for a few minutes' test run) which are very hard to post-process (in one instance it got so bad that gnuplot ate up all memory plus swap). The cause for the problem is that the kprobe is inserted into dccp_sendmsg(), which can be called in a polling-mode (whenever the TX queue is full due to congestion-control issues, EAGAIN is returned). This creates many very similar data points, i.e. the increase of processing time does not increase the quality/information of the probe output. The fix is to attach the probe to a different function -- write_xmit was chosen since it gets called continually (both via userspace and timer); an input-path function would stop sampling as soon as the other end stops sending feedback. For comparison the output file sizes for the same 20 second test run over a lossy link: * before / without patch: 118 Megabytes * after / with patch: 1.2 Megabytes and there was much less noise in the output. To allow backward compatibility with scripts that people use, the now-unused `size' field in the output has been replaced with the CCID identifier. This also serves for future compatibility - support for CCID2 is work in progress (depends on the still unfinished SRTT/RTTVAR updates). While at it, the update to ktime_t was also performed. Signed-off-by: Gerrit Renker <gerrit@erg.abdn.ac.uk> Acked-by: Ian McDonald <ian.mcdonald@jandi.co.nz>
This commit is contained in:
parent
a9c1656ab1
commit
b8c6bcee1d
|
@ -46,70 +46,54 @@ static struct {
|
|||
struct kfifo *fifo;
|
||||
spinlock_t lock;
|
||||
wait_queue_head_t wait;
|
||||
struct timespec tstart;
|
||||
ktime_t start;
|
||||
} dccpw;
|
||||
|
||||
static void printl(const char *fmt, ...)
|
||||
{
|
||||
va_list args;
|
||||
int len;
|
||||
struct timespec now;
|
||||
char tbuf[256];
|
||||
|
||||
va_start(args, fmt);
|
||||
getnstimeofday(&now);
|
||||
|
||||
now = timespec_sub(now, dccpw.tstart);
|
||||
|
||||
len = sprintf(tbuf, "%lu.%06lu ",
|
||||
(unsigned long) now.tv_sec,
|
||||
(unsigned long) now.tv_nsec / NSEC_PER_USEC);
|
||||
len += vscnprintf(tbuf+len, sizeof(tbuf)-len, fmt, args);
|
||||
va_end(args);
|
||||
|
||||
kfifo_put(dccpw.fifo, tbuf, len);
|
||||
wake_up(&dccpw.wait);
|
||||
}
|
||||
|
||||
static int jdccp_sendmsg(struct kiocb *iocb, struct sock *sk,
|
||||
struct msghdr *msg, size_t size)
|
||||
static void jdccp_write_xmit(struct sock *sk)
|
||||
{
|
||||
const struct inet_sock *inet = inet_sk(sk);
|
||||
struct ccid3_hc_tx_sock *hctx = NULL;
|
||||
struct timespec tv;
|
||||
char buf[256];
|
||||
int len, ccid = ccid_get_current_tx_ccid(dccp_sk(sk));
|
||||
|
||||
if (ccid_get_current_tx_ccid(dccp_sk(sk)) == DCCPC_CCID3)
|
||||
if (ccid == DCCPC_CCID3)
|
||||
hctx = ccid3_hc_tx_sk(sk);
|
||||
|
||||
if (port == 0 || ntohs(inet->dport) == port ||
|
||||
ntohs(inet->sport) == port) {
|
||||
if (!port || ntohs(inet->dport) == port || ntohs(inet->sport) == port) {
|
||||
|
||||
tv = ktime_to_timespec(ktime_sub(ktime_get(), dccpw.start));
|
||||
len = sprintf(buf, "%lu.%09lu %d.%d.%d.%d:%u %d.%d.%d.%d:%u %d",
|
||||
(unsigned long)tv.tv_sec,
|
||||
(unsigned long)tv.tv_nsec,
|
||||
NIPQUAD(inet->saddr), ntohs(inet->sport),
|
||||
NIPQUAD(inet->daddr), ntohs(inet->dport), ccid);
|
||||
|
||||
if (hctx)
|
||||
printl("%d.%d.%d.%d:%u %d.%d.%d.%d:%u %d %d %d %d %u "
|
||||
"%llu %llu %d\n",
|
||||
NIPQUAD(inet->saddr), ntohs(inet->sport),
|
||||
NIPQUAD(inet->daddr), ntohs(inet->dport), size,
|
||||
len += sprintf(buf + len, " %d %d %d %u %u %u %d",
|
||||
hctx->s, hctx->rtt, hctx->p, hctx->x_calc,
|
||||
hctx->x_recv >> 6, hctx->x >> 6, hctx->t_ipi);
|
||||
else
|
||||
printl("%d.%d.%d.%d:%u %d.%d.%d.%d:%u %d\n",
|
||||
NIPQUAD(inet->saddr), ntohs(inet->sport),
|
||||
NIPQUAD(inet->daddr), ntohs(inet->dport), size);
|
||||
(unsigned)(hctx->x_recv >> 6),
|
||||
(unsigned)(hctx->x >> 6), hctx->t_ipi);
|
||||
|
||||
len += sprintf(buf + len, "\n");
|
||||
kfifo_put(dccpw.fifo, buf, len);
|
||||
wake_up(&dccpw.wait);
|
||||
}
|
||||
|
||||
jprobe_return();
|
||||
return 0;
|
||||
}
|
||||
|
||||
static struct jprobe dccp_send_probe = {
|
||||
.kp = {
|
||||
.symbol_name = "dccp_sendmsg",
|
||||
.symbol_name = "dccp_write_xmit",
|
||||
},
|
||||
.entry = jdccp_sendmsg,
|
||||
.entry = jdccp_write_xmit,
|
||||
};
|
||||
|
||||
static int dccpprobe_open(struct inode *inode, struct file *file)
|
||||
{
|
||||
kfifo_reset(dccpw.fifo);
|
||||
getnstimeofday(&dccpw.tstart);
|
||||
dccpw.start = ktime_get();
|
||||
return 0;
|
||||
}
|
||||
|
||||
|
|
Loading…
Reference in a new issue