From dc522e703f6374839423a7eb0c2e510ee0389458 Mon Sep 17 00:00:00 2001 From: Alexandre Ratchov Date: Sun, 11 Nov 2012 01:46:38 +0100 Subject: [PATCH] cleanup debug traces --- sndiod/dev.c | 51 ++++----------------------- sndiod/dev.h | 3 -- sndiod/dsp.c | 86 +++++++++++++++++++++++++++++++++++++++++++++ sndiod/file.c | 3 +- sndiod/midi.c | 24 +++---------- sndiod/siofile.c | 91 ++++++++++++++++++++++++------------------------ sndiod/sock.c | 30 ++++++---------- 7 files changed, 154 insertions(+), 134 deletions(-) diff --git a/sndiod/dev.c b/sndiod/dev.c index bb5817c..2046517 100644 --- a/sndiod/dev.c +++ b/sndiod/dev.c @@ -161,9 +161,9 @@ zomb_mmcloc(void *arg, unsigned int pos) void zomb_exit(void *arg) { +#ifdef DEBUG struct slot *s = arg; -#ifdef DEBUG if (log_level >= 3) { slot_log(s); log_puts(": zomb_exit\n"); @@ -361,9 +361,9 @@ dev_midi_dump(struct dev *d) void dev_midi_imsg(void *arg, unsigned char *msg, int len) { +#ifdef DEBUG struct dev *d = arg; -#ifdef DEBUG dev_log(d); log_puts(": can't receive midi messages\n"); panic(); @@ -376,19 +376,7 @@ dev_midi_omsg(void *arg, unsigned char *msg, int len) struct dev *d = arg; struct sysex *x; unsigned int fps, chan; -#ifdef DEBUG - unsigned int i; - if (log_level >= 3) { - dev_log(d); - log_puts(": got msg:"); - for (i = 0; i < len; i++) { - log_puts(" "); - log_putx(msg[i]); - } - log_puts("\n"); - } -#endif if ((msg[0] & MIDI_CMDMASK) == MIDI_CTL && msg[1] == MIDI_CTL_VOL) { chan = msg[0] & MIDI_CHANMASK; if (chan >= DEV_NSLOT) @@ -470,9 +458,9 @@ dev_midi_omsg(void *arg, unsigned char *msg, int len) void dev_midi_fill(void *arg, int count) { +#ifdef DEBUG struct dev *d = arg; -#ifdef DEBUG dev_log(d); log_puts(": can't receive fill input\n"); panic(); @@ -596,15 +584,6 @@ dev_mix_badd(struct dev *d, struct slot *s) adata_t *idata, *odata; int icount; -#ifdef DEBUG - if (log_level >= 4) { - slot_log(s); - log_puts(": dev_mix_badd: drop = "); - log_puti(s->mix.drop); - log_puts("\n"); - } -#endif - odata = DEV_PBUF(d); idata = (adata_t *)abuf_rgetblk(&s->mix.buf, &icount); #ifdef DEBUG @@ -612,9 +591,7 @@ dev_mix_badd(struct dev *d, struct slot *s) slot_log(s); log_puts(": not enough data to mix ("); log_putu(icount); - log_puts(" of "); - log_putu(d->round * s->mix.bpf); - log_puts(")\n"); + log_puts("bytes)\n"); panic(); } #endif @@ -707,7 +684,6 @@ dev_mix_cycle(struct dev *d) continue; } #ifdef DEBUG - s->delay -= s->round; if (log_level >= 4) { slot_log(s); log_puts(": mixing, drop = "); @@ -826,14 +802,6 @@ dev_sub_bcopy(struct dev *d, struct slot *s) adata_t *idata, *odata; int ocount; -#ifdef DEBUG - if (log_level >= 4) { - slot_log(s); - log_puts(": dev_sub_bcopy: silence = "); - log_puti(s->sub.silence); - log_puts("\n"); - } -#endif idata = (s->mode & MODE_MON) ? DEV_PBUF(d) : d->rbuf; odata = (adata_t *)abuf_wgetblk(&s->sub.buf, &ocount); #ifdef DEBUG @@ -920,9 +888,6 @@ dev_onmove(struct dev *d, int delta) pos = (long long)delta * s->round + s->delta_rem; s->delta_rem = pos % d->round; s->delta += pos / (int)d->round; -#ifdef DEBUG - s->delay += pos / (int)d->round; -#endif if (s->delta >= 0) s->ops->onmove(s->arg, delta); } @@ -1633,8 +1598,6 @@ slot_setvol(struct slot *s, unsigned int vol) if (log_level >= 3) { slot_log(s); log_puts(": setting volume "); - log_putu(s->vol); - log_puts(" -> "); log_putu(vol); log_puts("\n"); } @@ -1666,7 +1629,6 @@ slot_attach(struct slot *s) s->delta_rem = 0; s->pstate = SLOT_RUN; #ifdef DEBUG - s->delay = 0; if (log_level >= 3) { slot_log(s); log_puts(": attached at "); @@ -1779,10 +1741,11 @@ slot_ready(struct slot *s) void slot_start(struct slot *s) { - struct dev *d = s->dev; unsigned int bufsz; - #ifdef DEBUG + struct dev *d = s->dev; + + if (s->pstate != SLOT_INIT) { slot_log(s); log_puts(": slot_start: wrong state\n"); diff --git a/sndiod/dev.h b/sndiod/dev.h index 0b2a866..ba9ab9d 100644 --- a/sndiod/dev.h +++ b/sndiod/dev.h @@ -44,9 +44,6 @@ struct slot { struct dev *dev; /* device this belongs to */ void *arg; /* user data for callbacks */ struct aparams par; /* socket side params */ -#ifdef DEBUG - int delay; -#endif struct { int weight; /* dynamic range */ int maxweight; /* max dynamic range allowed */ diff --git a/sndiod/dsp.c b/sndiod/dsp.c index 22ec2ad..f9dcde2 100644 --- a/sndiod/dsp.c +++ b/sndiod/dsp.c @@ -232,6 +232,15 @@ resamp_do(struct resamp *p, adata_t *in, adata_t *out, int todo) /* * Start conversion. */ +#ifdef DEBUG + if (log_level >= 4) { + log_puts("resamp: copying "); + log_puti(todo); + log_puts(" frames, diff = "); + log_putu(diff); + log_puts("\n"); + } +#endif for (;;) { if (diff < 0) { if (ifr == 0) @@ -295,6 +304,15 @@ resamp_init(struct resamp *p, unsigned int iblksz, unsigned int oblksz, int nch) p->ctx_start = 0; for (i = 0; i < NCHAN_MAX * RESAMP_NCTX; i++) p->ctx[i] = 0; +#ifdef DEBUG + if (log_level >= 3) { + log_puts("resamp: "); + log_putu(iblksz); + log_puts("/"); + log_putu(oblksz); + log_puts("\n"); + } +#endif } void @@ -311,6 +329,13 @@ enc_do(struct conv *p, unsigned char *in, unsigned char *out, int todo) int obnext; int osnext; +#ifdef DEBUG + if (log_level >= 4) { + log_puts("enc: copying "); + log_putu(todo); + log_puts(" frames\n"); + } +#endif /* * Partially copy structures into local variables, to avoid * unnecessary indirections; this also allows the compiler to @@ -354,6 +379,13 @@ enc_sil_do(struct conv *p, unsigned char *out, int todo) int obnext; int osnext; +#ifdef DEBUG + if (log_level >= 4) { + log_puts("enc: silence "); + log_putu(todo); + log_puts(" frames\n"); + } +#endif /* * Partially copy structures into local variables, to avoid * unnecessary indirections; this also allows the compiler to @@ -400,6 +432,15 @@ enc_init(struct conv *p, struct aparams *par, int nch) p->bnext = 1; p->snext = 0; } +#ifdef DEBUG + if (log_level >= 3) { + log_puts("enc: "); + aparams_log(par); + log_puts(", "); + log_puti(p->nch); + log_puts(" channels\n"); + } +#endif } void @@ -416,6 +457,13 @@ dec_do(struct conv *p, unsigned char *in, unsigned char *out, int todo) unsigned int ishift; adata_t *odata; +#ifdef DEBUG + if (log_level >= 4) { + log_puts("dec: copying "); + log_putu(todo); + log_puts(" frames\n"); + } +#endif /* * Partially copy structures into local variables, to avoid * unnecessary indirections; this also allows the compiler to @@ -467,6 +515,15 @@ dec_init(struct conv *p, struct aparams *par, int nch) p->bnext = 1; p->snext = 0; } +#ifdef DEBUG + if (log_level >= 3) { + log_puts("dec: "); + aparams_log(par); + log_puts(", "); + log_puti(p->nch); + log_puts(" channels\n"); + } +#endif } void @@ -475,6 +532,13 @@ cmap_add(struct cmap *p, void *in, void *out, int vol, int todo) adata_t *idata, *odata; int i, j, nch, istart, inext, onext, ostart, y, v; +#ifdef DEBUG + if (log_level >= 4) { + log_puts("cmap: adding "); + log_puti(todo); + log_puts(" frames\n"); + } +#endif idata = in; odata = out; ostart = p->ostart; @@ -511,6 +575,13 @@ cmap_copy(struct cmap *p, void *in, void *out, int vol, int todo) adata_t *idata, *odata; int i, j, nch, istart, inext, onext, ostart, v; +#ifdef DEBUG + if (log_level >= 4) { + log_puts("cmap: copying "); + log_puti(todo); + log_puts(" frames\n"); + } +#endif idata = in; odata = out; ostart = p->ostart; @@ -570,6 +641,21 @@ cmap_init(struct cmap *p, p->istart = cmin - imin; p->inext = imax - cmax; p->nch = cmax - cmin + 1; +#ifdef DEBUG + if (log_level >= 3) { + log_puts("cmap: nch = "); + log_puti(p->nch); + log_puts(", ostart = "); + log_puti(p->ostart); + log_puts(", onext = "); + log_puti(p->onext); + log_puts(", istart = "); + log_puti(p->istart); + log_puts(", inext= "); + log_puti(p->inext); + log_puts("\n"); + } +#endif } /* diff --git a/sndiod/file.c b/sndiod/file.c index 45fd4bd..dc64ac9 100644 --- a/sndiod/file.c +++ b/sndiod/file.c @@ -270,7 +270,7 @@ file_del(struct file *f) int file_poll(void) { - nfds_t nfds, i, n; + nfds_t nfds, n; struct pollfd pfds[MAXFDS]; struct file *f, **pf; struct timespec ts; @@ -278,6 +278,7 @@ file_poll(void) struct timespec sleepts; struct timespec ts0, ts1; long us; + int i; #endif long long delta_nsec; int revents, res; diff --git a/sndiod/midi.c b/sndiod/midi.c index dd6d464..cb68605 100644 --- a/sndiod/midi.c +++ b/sndiod/midi.c @@ -376,7 +376,7 @@ midi_out(struct midi *oep, unsigned char *idata, int icount) #ifdef DEBUG if (log_level >= 4) { midi_log(oep); - log_puts(":"); + log_puts(": out: "); for (i = 0; i < ocount; i++) { log_puts(" "); log_putx(odata[i]); @@ -411,19 +411,7 @@ void port_omsg(void *arg, unsigned char *msg, int size) { struct port *p = arg; - int i; -#ifdef DEBUG - if (log_level >= 4) { - port_log(p); - log_puts(": sending:"); - for (i = 0; i < size; i++) { - log_puts(" "); - log_putx(msg[i]); - } - log_puts("\n"); - } -#endif midi_out(p->midi, msg, size); } @@ -436,9 +424,9 @@ port_fill(void *arg, int count) void port_exit(void *arg) { +#ifdef DEBUG struct port *p = arg; -#ifdef DEBUG if (log_level >= 3) { port_log(p); log_puts(": exit\n"); @@ -475,7 +463,7 @@ port_del(struct port *c) for (p = &port_list; *p != c; p = &(*p)->next) { #ifdef DEBUG if (*p == NULL) { - log_puts("port to delete not on the list\n"); + log_puts("port to delete not on list\n"); panic(); } #endif @@ -501,8 +489,6 @@ port_open(struct port *c) { if (!port_mio_open(c)) { if (log_level >= 1) { - port_log(c); - log_puts(": "); log_puts(c->path); log_puts(": failed to open midi port\n"); } @@ -518,9 +504,7 @@ port_close(struct port *c) #ifdef DEBUG if (c->state == PORT_CFG) { port_log(c); - log_puts(": "); - log_puts(c->path); - log_puts(": failed to open midi port\n"); + log_puts(": can't close port (not opened)\n"); } #endif port_mio_close(c); diff --git a/sndiod/siofile.c b/sndiod/siofile.c index 6d66e73..e051d4e 100644 --- a/sndiod/siofile.c +++ b/sndiod/siofile.c @@ -51,13 +51,6 @@ dev_sio_onmove(void *arg, int delta) struct dev *d = arg; #ifdef DEBUG - if (delta < 0 || delta > (60 * RATE_MAX)) { - dev_log(d); - log_puts(": "); - log_puti(delta); - log_puts(": bogus sndio delta"); - panic(); - } if (log_level >= 4) { dev_log(d); log_puts(": tick, delta = "); @@ -229,9 +222,13 @@ int dev_sio_revents(void *arg, struct pollfd *pfd) { struct dev *d = arg; + int events; + events = sio_revents(d->sio.hdl, pfd); +#ifdef DEBUG d->sio.events = sio_revents(d->sio.hdl, pfd); - return d->sio.events; +#endif + return events; } void @@ -278,8 +275,7 @@ dev_sio_run(void *arg) #ifdef DEBUG if (n == 0 && data == base && !sio_eof(d->sio.hdl)) { dev_log(d); - log_puts(": read blocked at cycle start, sync error\n"); - /* don't panic since recording is slightly ahead of playback */ + log_puts(": read blocked at cycle start\n"); } if (log_level >= 4) { dev_log(d); @@ -296,23 +292,24 @@ dev_sio_run(void *arg) return; #ifdef DEBUG d->sio.rused -= d->round; - if (d->sio.rused >= d->round) { - dev_log(d); - log_puts(": rec hw xrun, rused = "); - log_puti(d->sio.rused); - log_puts("/"); - log_puti(d->bufsz); - log_puts("\n"); - } - if (d->sio.rused < 0 || d->sio.rused >= d->bufsz) { - /* device driver or libsndio bug */ - dev_log(d); - log_puts(": out of bounds rused = "); - log_puti(d->sio.rused); - log_puts("/"); - log_puti(d->bufsz); - log_puts("\n"); - //panic(); + if (log_level >= 2) { + if (d->sio.rused >= d->round) { + dev_log(d); + log_puts(": rec hw xrun, rused = "); + log_puti(d->sio.rused); + log_puts("/"); + log_puti(d->bufsz); + log_puts("\n"); + } + if (d->sio.rused < 0 || + d->sio.rused >= d->bufsz) { + dev_log(d); + log_puts(": out of bounds rused = "); + log_puti(d->sio.rused); + log_puts("/"); + log_puti(d->bufsz); + log_puts("\n"); + } } #endif d->sio.cstate = DEV_SIO_CYCLE; @@ -358,8 +355,7 @@ dev_sio_run(void *arg) #ifdef DEBUG if (n == 0 && data == base && !sio_eof(d->sio.hdl)) { dev_log(d); - log_puts(": write blocked at cycle start, sync error\n"); - /* don't panic since playback might be ahead of recording */ + log_puts(": write blocked at cycle start\n"); } if (log_level >= 4) { dev_log(d); @@ -376,23 +372,26 @@ dev_sio_run(void *arg) return; #ifdef DEBUG d->sio.pused += d->round; - if (d->prime == 0 && d->sio.pused <= d->bufsz - d->round) { - dev_log(d); - log_puts(": play hw xrun, pused = "); - log_puti(d->sio.pused); - log_puts("/"); - log_puti(d->bufsz); - log_puts("\n"); - } - if (d->sio.pused < 0 || d->sio.pused > d->bufsz) { - /* device driver or libsndio bug */ - dev_log(d); - log_puts(": out of bounds pused = "); - log_puti(d->sio.pused); - log_puts("/"); - log_puti(d->bufsz); - log_puts("\n"); - //panic(); + if (log_level >= 2) { + if (d->prime == 0 && + d->sio.pused <= d->bufsz - d->round) { + dev_log(d); + log_puts(": play hw xrun, pused = "); + log_puti(d->sio.pused); + log_puts("/"); + log_puti(d->bufsz); + log_puts("\n"); + } + if (d->sio.pused < 0 || + d->sio.pused > d->bufsz) { + /* device driver or libsndio bug */ + dev_log(d); + log_puts(": out of bounds pused = "); + log_puti(d->sio.pused); + log_puts("/"); + log_puti(d->bufsz); + log_puts("\n"); + } } #endif d->poffs += d->round; diff --git a/sndiod/sock.c b/sndiod/sock.c index a4d86cf..db83131 100644 --- a/sndiod/sock.c +++ b/sndiod/sock.c @@ -324,9 +324,9 @@ sock_new(int fd) void sock_slot_mmcstart(void *arg) { +#ifdef DEBUG struct sock *f = (struct sock *)arg; -#ifdef DEBUG if (log_level >= 3) { sock_log(f); log_puts(": ignored mmc start signal\n"); @@ -672,16 +672,6 @@ sock_setpar(struct sock *f) p->bps = APARAMS_BPS(p->bits); s->par.bits = p->bits; s->par.bps = p->bps; -#ifdef DEBUG - if (log_level >= 3) { - sock_log(f); - log_puts(": using "); - log_putu(p->bits); - log_puts("bits, "); - log_putu(p->bps); - log_puts(" bytes per sample\n"); - } -#endif } if (AMSG_ISSET(p->sig)) s->par.sig = p->sig ? 1 : 0; @@ -701,7 +691,7 @@ sock_setpar(struct sock *f) #ifdef DEBUG if (log_level >= 3) { sock_log(f); - log_puts(": using recording channels "); + log_puts(": recording channels "); log_putu(s->sub.slot_cmin); log_puts(":"); log_putu(s->sub.slot_cmax); @@ -725,7 +715,7 @@ sock_setpar(struct sock *f) #ifdef DEBUG if (log_level >= 3) { sock_log(f); - log_puts(": using playback channels "); + log_puts(": playback channels "); log_putu(s->mix.slot_cmin); log_puts(":"); log_putu(s->mix.slot_cmax); @@ -749,20 +739,20 @@ sock_setpar(struct sock *f) #ifdef DEBUG if (log_level >= 3) { sock_log(f); - log_puts(": using "); + log_puts(": "); log_putu(appbufsz); - log_puts(" fr app buffer size\n"); + log_puts(" frame buffer\n"); } #endif } #ifdef DEBUG if (log_level >= 3) { sock_log(f); - log_puts(": using "); + log_puts(": "); log_putu(rate); log_puts("Hz sample rate, "); log_putu(s->round); - log_puts(" fr block size\n"); + log_puts(" frame blocks\n"); } #endif } @@ -786,7 +776,7 @@ sock_setpar(struct sock *f) #ifdef DEBUG if (log_level >= 3) { sock_log(f); - log_puts(": using 0x"); + log_puts(": 0x"); log_putx(s->xrun); log_puts(" xrun policy\n"); } @@ -808,9 +798,9 @@ sock_setpar(struct sock *f) #ifdef DEBUG if (log_level >= 3) { sock_log(f); - log_puts(": using "); + log_puts(": "); log_putu(s->appbufsz); - log_puts(" buffer size\n"); + log_puts(" frame buffer\n"); } #endif }