diff options
author | Wim Taymans <wtaymans@redhat.com> | 2020-04-22 12:47:18 +0200 |
---|---|---|
committer | Wim Taymans <wtaymans@redhat.com> | 2020-04-22 12:47:18 +0200 |
commit | aafd1e729807eb33b72983a0e39caa2010410341 (patch) | |
tree | 013a516b99a86bb5ffda006b43f5edd51ed94749 | |
parent | 8ab67c5fa0a941c7d6e1edd58538baa024f7f9dd (diff) |
improve debug
Improve log so that debug level 3 gives a reasonably readable overview
of what is going on.
33 files changed, 141 insertions, 125 deletions
diff --git a/pipewire-jack/src/metadata.c b/pipewire-jack/src/metadata.c index ae9bd7b3..668a2b5b 100644 --- a/pipewire-jack/src/metadata.c +++ b/pipewire-jack/src/metadata.c @@ -248,7 +248,7 @@ int jack_get_property(jack_uuid_t subject, *value = strdup(prop->data); *type = strdup(prop->type); - pw_log_info("subject:%"PRIu64" key:'%s' value:'%s' type:'%s'", + pw_log_debug("subject:%"PRIu64" key:'%s' value:'%s' type:'%s'", subject, key, *value, *type); return 0; diff --git a/pipewire-jack/src/pipewire-jack.c b/pipewire-jack/src/pipewire-jack.c index fcf8e31a..98e1d14c 100644 --- a/pipewire-jack/src/pipewire-jack.c +++ b/pipewire-jack/src/pipewire-jack.c @@ -4108,7 +4108,7 @@ void jack_set_error_function (void (*func)(const char *)) SPA_EXPORT void default_jack_info_callback(const char *desc) { - pw_log_info("pw jack info: %s",desc); + pw_log_info("pw jack info: %s", desc); } SPA_EXPORT @@ -4435,7 +4435,7 @@ int jack_client_create_thread (jack_client_t* client, if (globals.creator == NULL) globals.creator = pthread_create; - pw_log_info("client %p: create thread", client); + pw_log_debug("client %p: create thread", client); return globals.creator(thread, NULL, start_routine, arg); } diff --git a/pipewire-pulseaudio/src/stream.c b/pipewire-pulseaudio/src/stream.c index bfd07481..3acdfc28 100644 --- a/pipewire-pulseaudio/src/stream.c +++ b/pipewire-pulseaudio/src/stream.c @@ -152,11 +152,11 @@ static inline pa_channel_position_t channel_id2pa(pa_stream *s, uint32_t id) static void dump_buffer_attr(pa_stream *s, pa_buffer_attr *attr) { - pw_log_info("stream %p: maxlength: %u", s, attr->maxlength); - pw_log_info("stream %p: tlength: %u", s, attr->tlength); - pw_log_info("stream %p: minreq: %u", s, attr->minreq); - pw_log_info("stream %p: prebuf: %u", s, attr->prebuf); - pw_log_info("stream %p: fragsize: %u", s, attr->fragsize); + pw_log_debug("stream %p: maxlength: %u", s, attr->maxlength); + pw_log_debug("stream %p: tlength: %u", s, attr->tlength); + pw_log_debug("stream %p: minreq: %u", s, attr->minreq); + pw_log_debug("stream %p: prebuf: %u", s, attr->prebuf); + pw_log_debug("stream %p: fragsize: %u", s, attr->fragsize); } static void configure_buffers(pa_stream *s) @@ -271,7 +271,7 @@ static const struct spa_pod *get_buffers_param(pa_stream *s, pa_buffer_attr *att else buffers = SPA_CLAMP(attr->maxlength / (size * stride), 3u, MAX_BUFFERS); - pw_log_info("stream %p: stride %d maxsize %d size %u buffers %d", s, stride, maxsize, + pw_log_debug("stream %p: stride %d maxsize %d size %u buffers %d", s, stride, maxsize, size, buffers); param = spa_pod_builder_add_object(b, diff --git a/spa/plugins/alsa/alsa-pcm-device.c b/spa/plugins/alsa/alsa-pcm-device.c index ffef396c..47027da3 100644 --- a/spa/plugins/alsa/alsa-pcm-device.c +++ b/spa/plugins/alsa/alsa-pcm-device.c @@ -227,16 +227,16 @@ static int set_profile(struct impl *this, uint32_t id) snd_ctl_t *ctl_hndl; int err; - spa_log_info(this->log, "open card %s", this->props.device); - if ((err = snd_ctl_open(&ctl_hndl, this->props.device, 0)) < 0) { - spa_log_error(this->log, "can't open control for card %s: %s", - this->props.device, snd_strerror(err)); - return err; - } + spa_log_debug(this->log, "open card %s", this->props.device); + if ((err = snd_ctl_open(&ctl_hndl, this->props.device, 0)) < 0) { + spa_log_error(this->log, "can't open control for card %s: %s", + this->props.device, snd_strerror(err)); + return err; + } err = activate_profile(this, ctl_hndl, id); - spa_log_info(this->log, "close card %s", this->props.device); + spa_log_debug(this->log, "close card %s", this->props.device); snd_ctl_close(ctl_hndl); return err; @@ -253,12 +253,12 @@ static int emit_info(struct impl *this, bool full) struct spa_param_info params[2]; char path[128]; - spa_log_info(this->log, "open card %s", this->props.device); - if ((err = snd_ctl_open(&ctl_hndl, this->props.device, 0)) < 0) { - spa_log_error(this->log, "can't open control for card %s: %s", - this->props.device, snd_strerror(err)); - return err; - } + spa_log_debug(this->log, "open card %s", this->props.device); + if ((err = snd_ctl_open(&ctl_hndl, this->props.device, 0)) < 0) { + spa_log_error(this->log, "can't open control for card %s: %s", + this->props.device, snd_strerror(err)); + return err; + } snd_ctl_card_info_alloca(&info); if ((err = snd_ctl_card_info(ctl_hndl, info)) < 0) { @@ -294,7 +294,7 @@ static int emit_info(struct impl *this, bool full) spa_device_emit_info(&this->hooks, &dinfo); exit: - spa_log_info(this->log, "close card %s", this->props.device); + spa_log_debug(this->log, "close card %s", this->props.device); snd_ctl_close(ctl_hndl); return err; } diff --git a/spa/plugins/alsa/alsa-pcm.c b/spa/plugins/alsa/alsa-pcm.c index f1b8a08c..e122cd4f 100644 --- a/spa/plugins/alsa/alsa-pcm.c +++ b/spa/plugins/alsa/alsa-pcm.c @@ -28,7 +28,7 @@ static int spa_alsa_open(struct state *state) CHECK(snd_output_stdio_attach(&state->output, stderr, 0), "attach failed"); - spa_log_info(state->log, NAME" %p: ALSA device open '%s' %s", state, props->device, + spa_log_debug(state->log, NAME" %p: ALSA device open '%s' %s", state, props->device, state->stream == SND_PCM_STREAM_CAPTURE ? "capture" : "playback"); CHECK(snd_pcm_open(&state->hndl, props->device, @@ -71,7 +71,7 @@ int spa_alsa_close(struct state *state) if (!state->opened) return 0; - spa_log_info(state->log, NAME" %p: Device '%s' closing", state, state->props.device); + spa_log_debug(state->log, NAME" %p: Device '%s' closing", state, state->props.device); CHECK(snd_pcm_close(state->hndl), "close failed"); spa_system_close(state->data_system, state->timerfd); @@ -429,7 +429,7 @@ int spa_alsa_set_format(struct state *state, struct spa_audio_info *fmt, uint32_ return -EINVAL; } - spa_log_info(state->log, NAME" %p: Stream parameters are %iHz, %s, %i channels", + spa_log_debug(state->log, NAME" %p: Stream parameters are %iHz, %s, %i channels", state, info->rate, snd_pcm_format_name(format), info->channels); CHECK(snd_pcm_hw_params_set_format(hndl, params, format), "set_format"); @@ -470,9 +470,10 @@ int spa_alsa_set_format(struct state *state, struct spa_audio_info *fmt, uint32_ state->period_frames = period_size; periods = state->buffer_frames / state->period_frames; - spa_log_info(state->log, NAME" %p: buffer frames %lu, period frames %lu, periods %u, frame_size %zd", - state, state->buffer_frames, state->period_frames, - periods, state->frame_size); + spa_log_info(state->log, NAME" %p: format:%s rate:%d channels:%d " + "buffer frames %lu, period frames %lu, periods %u, frame_size %zd", + state, snd_pcm_format_name(state->format), state->rate, state->channels, + state->buffer_frames, state->period_frames, periods, state->frame_size); /* write the parameters to device */ CHECK(snd_pcm_hw_params(hndl, params), "set_hw_params"); diff --git a/spa/plugins/alsa/alsa-seq.c b/spa/plugins/alsa/alsa-seq.c index 6a1621ea..4b025a8a 100644 --- a/spa/plugins/alsa/alsa-seq.c +++ b/spa/plugins/alsa/alsa-seq.c @@ -50,7 +50,7 @@ static int seq_open(struct seq_state *state, struct seq_conn *conn) snd_seq_port_info_t *pinfo; int res; - spa_log_info(state->log, "%p: ALSA seq open '%s' duplex", state, props->device); + spa_log_debug(state->log, "%p: ALSA seq open '%s' duplex", state, props->device); if ((res = snd_seq_open(&conn->hndl, props->device, @@ -111,7 +111,7 @@ error_exit_close: static int seq_close(struct seq_state *state, struct seq_conn *conn) { int res; - spa_log_info(state->log, "%p: Device '%s' closing", state, state->props.device); + spa_log_debug(state->log, "%p: Device '%s' closing", state, state->props.device); if ((res = snd_seq_close(conn->hndl)) < 0) { spa_log_warn(state->log, "close failed: %s", snd_strerror(res)); } @@ -407,13 +407,14 @@ int spa_alsa_seq_activate_port(struct seq_state *state, struct seq_port *port, b port->addr.client, port->addr.port, snd_strerror(res)); active = false; } + spa_log_info(state->log, "subscribe: %d.%d", port->addr.client, port->addr.port); } else { if ((res = snd_seq_unsubscribe_port(state->event.hndl, sub)) < 0) { spa_log_warn(state->log, "can't unsubscribe from %d:%d - %s", port->addr.client, port->addr.port, snd_strerror(res)); } + spa_log_info(state->log, "unsubscribe: %d.%d", port->addr.client, port->addr.port); } - spa_log_info(state->log, "activate: %d.%d: %d", port->addr.client, port->addr.port, active); port->active = active; return res; } diff --git a/spa/plugins/alsa/alsa-udev.c b/spa/plugins/alsa/alsa-udev.c index 51b19c8b..aac39d8b 100644 --- a/spa/plugins/alsa/alsa-udev.c +++ b/spa/plugins/alsa/alsa-udev.c @@ -199,7 +199,7 @@ static int emit_object_info(struct impl *this, uint32_t id, struct udev_device * snprintf(path, sizeof(path), "hw:%d", atoi(str)); - spa_log_info(this->log, "open card %s", path); + spa_log_debug(this->log, "open card %s", path); if ((res = snd_ctl_open(&ctl_hndl, path, 0)) < 0) { spa_log_error(this->log, "can't open control for card %s: %s", @@ -210,7 +210,7 @@ static int emit_object_info(struct impl *this, uint32_t id, struct udev_device * pcm = -1; res = snd_ctl_pcm_next_device(ctl_hndl, &pcm); - spa_log_info(this->log, "close card %s", path); + spa_log_debug(this->log, "close card %s", path); snd_ctl_close(ctl_hndl); if (res < 0) { diff --git a/spa/plugins/audioconvert/fmtconvert.c b/spa/plugins/audioconvert/fmtconvert.c index 5c58b8df..2624a1fc 100644 --- a/spa/plugins/audioconvert/fmtconvert.c +++ b/spa/plugins/audioconvert/fmtconvert.c @@ -605,7 +605,7 @@ static int port_set_format(void *object, return -EINVAL; if (other->have_format) { - spa_log_info(this->log, NAME "%p: channels:%d<>%d rate:%d<>%d format:%d<>%d", this, + spa_log_debug(this->log, NAME "%p: channels:%d<>%d rate:%d<>%d format:%d<>%d", this, info.info.raw.channels, other->format.info.raw.channels, info.info.raw.rate, other->format.info.raw.rate, info.info.raw.format, other->format.info.raw.format); diff --git a/spa/plugins/audiomixer/audiomixer.c b/spa/plugins/audiomixer/audiomixer.c index efce5115..352dc087 100644 --- a/spa/plugins/audiomixer/audiomixer.c +++ b/spa/plugins/audiomixer/audiomixer.c @@ -260,7 +260,7 @@ static int impl_node_add_port(void *object, enum spa_direction direction, uint32 if (this->last_port <= port_id) this->last_port = port_id + 1; - spa_log_info(this->log, NAME " %p: add port %d", this, port_id); + spa_log_debug(this->log, NAME " %p: add port %d", this, port_id); emit_port_info(this, port, true); return 0; @@ -293,7 +293,7 @@ impl_node_remove_port(void *object, enum spa_direction direction, uint32_t port_ this->last_port = i + 1; } - spa_log_info(this->log, NAME " %p: remove port %d", this, port_id); + spa_log_debug(this->log, NAME " %p: remove port %d", this, port_id); spa_node_emit_port_info(&this->hooks, direction, port_id, NULL); return 0; @@ -437,7 +437,7 @@ impl_node_port_enum_params(void *object, int seq, static int clear_buffers(struct impl *this, struct port *port) { if (port->n_buffers > 0) { - spa_log_info(this->log, NAME " %p: clear buffers %p", this, port); + spa_log_debug(this->log, NAME " %p: clear buffers %p", this, port); port->n_buffers = 0; spa_list_init(&port->queue); } @@ -493,7 +493,7 @@ static int port_set_format(void *object, if (!port->have_format) { this->n_formats++; port->have_format = true; - spa_log_info(this->log, NAME " %p: set format on port %d", this, port_id); + spa_log_debug(this->log, NAME " %p: set format on port %d", this, port_id); } } port->info.change_mask |= SPA_PORT_CHANGE_MASK_PARAMS; @@ -547,7 +547,7 @@ impl_node_port_use_buffers(void *object, spa_return_val_if_fail(port->have_format, -EIO); - spa_log_info(this->log, NAME " %p: use buffers %d on port %d", this, n_buffers, port_id); + spa_log_debug(this->log, NAME " %p: use buffers %d on port %d", this, n_buffers, port_id); clear_buffers(this, port); diff --git a/spa/plugins/bluez5/a2dp-sink.c b/spa/plugins/bluez5/a2dp-sink.c index 34d45f37..2ef5317f 100644 --- a/spa/plugins/bluez5/a2dp-sink.c +++ b/spa/plugins/bluez5/a2dp-sink.c @@ -1167,7 +1167,7 @@ static int port_set_format(struct impl *this, struct port *port, int err; if (format == NULL) { - spa_log_info(this->log, "clear format"); + spa_log_debug(this->log, "clear format"); clear_buffers(this, port); port->have_format = false; } else { @@ -1245,7 +1245,7 @@ impl_node_port_use_buffers(void *object, spa_return_val_if_fail(CHECK_PORT(this, direction, port_id), -EINVAL); port = &this->port; - spa_log_info(this->log, "use buffers %d", n_buffers); + spa_log_debug(this->log, "use buffers %d", n_buffers); if (!port->have_format) return -EIO; diff --git a/spa/plugins/bluez5/a2dp-source.c b/spa/plugins/bluez5/a2dp-source.c index c36927b1..448012a4 100644 --- a/spa/plugins/bluez5/a2dp-source.c +++ b/spa/plugins/bluez5/a2dp-source.c @@ -811,7 +811,7 @@ static int port_set_format(struct impl *this, struct port *port, int err; if (format == NULL) { - spa_log_info(this->log, "clear format"); + spa_log_debug(this->log, "clear format"); clear_buffers(this, port); port->have_format = false; } else { @@ -890,7 +890,7 @@ impl_node_port_use_buffers(void *object, spa_return_val_if_fail(CHECK_PORT(this, direction, port_id), -EINVAL); port = &this->port; - spa_log_info(this->log, "use buffers %d", n_buffers); + spa_log_debug(this->log, "use buffers %d", n_buffers); if (!port->have_format) return -EIO; diff --git a/spa/plugins/bluez5/bluez5-dbus.c b/spa/plugins/bluez5/bluez5-dbus.c index 358824b8..8e3827a8 100644 --- a/spa/plugins/bluez5/bluez5-dbus.c +++ b/spa/plugins/bluez5/bluez5-dbus.c @@ -1449,7 +1449,7 @@ static int sco_do_accept(struct spa_bt_transport *t) memset(&addr, 0, sizeof(addr)); optlen = sizeof(addr); - spa_log_info(monitor->log, "transport %p: doing accept", t); + spa_log_debug(monitor->log, "transport %p: doing accept", t); sock = accept(td->sco.fd, (struct sockaddr *) &addr, &optlen); if (sock < 0) { if (errno != EAGAIN) @@ -1505,7 +1505,7 @@ static int sco_do_connect(struct spa_bt_transport *t) addr.sco_family = AF_BLUETOOTH; bacpy(&addr.sco_bdaddr, &dst); - spa_log_info(monitor->log, "transport %p: doing connect", t); + spa_log_debug(monitor->log, "transport %p: doing connect", t); err = connect(sock, (struct sockaddr *) &addr, len); if (err < 0 && !(errno == EAGAIN || errno == EINPROGRESS)) { spa_log_error(monitor->log, "connect(): %s", strerror(errno)); @@ -1621,7 +1621,7 @@ static int sco_listen(struct spa_bt_transport *t) goto fail_close; } - spa_log_info(monitor->log, "transport %p: doing listen", t); + spa_log_debug(monitor->log, "transport %p: doing listen", t); if (listen(sock, 1) < 0) { spa_log_error(monitor->log, "listen(): %m"); goto fail_close; diff --git a/spa/plugins/bluez5/sco-sink.c b/spa/plugins/bluez5/sco-sink.c index 5dd22fbd..aa0d8f30 100644 --- a/spa/plugins/bluez5/sco-sink.c +++ b/spa/plugins/bluez5/sco-sink.c @@ -841,7 +841,7 @@ static int port_set_format(struct impl *this, struct port *port, int err; if (format == NULL) { - spa_log_info(this->log, "clear format"); + spa_log_debug(this->log, "clear format"); clear_buffers(this, port); port->have_format = false; } else { @@ -919,7 +919,7 @@ impl_node_port_use_buffers(void *object, spa_return_val_if_fail(CHECK_PORT(this, direction, port_id), -EINVAL); port = &this->port; - spa_log_info(this->log, "use buffers %d", n_buffers); + spa_log_debug(this->log, "use buffers %d", n_buffers); if (!port->have_format) return -EIO; diff --git a/spa/plugins/bluez5/sco-source.c b/spa/plugins/bluez5/sco-source.c index b9e803a3..569dca17 100644 --- a/spa/plugins/bluez5/sco-source.c +++ b/spa/plugins/bluez5/sco-source.c @@ -738,7 +738,7 @@ static int port_set_format(struct impl *this, struct port *port, int err; if (format == NULL) { - spa_log_info(this->log, "clear format"); + spa_log_debug(this->log, "clear format"); clear_buffers(this, port); port->have_format = false; } else { @@ -817,7 +817,7 @@ impl_node_port_use_buffers(void *object, spa_return_val_if_fail(CHECK_PORT(this, direction, port_id), -EINVAL); port = &this->port; - spa_log_info(this->log, "use buffers %d", n_buffers); + spa_log_debug(this->log, "use buffers %d", n_buffers); if (!port->have_format) return -EIO; diff --git a/spa/plugins/jack/jack-sink.c b/spa/plugins/jack/jack-sink.c index 9d97112f..acebdcb7 100644 --- a/spa/plugins/jack/jack-sink.c +++ b/spa/plugins/jack/jack-sink.c @@ -599,7 +599,7 @@ impl_node_port_enum_params(void *object, int seq, static int clear_buffers(struct impl *this, struct port *port) { if (port->n_buffers > 0) { - spa_log_info(this->log, NAME " %p: clear buffers", this); + spa_log_debug(this->log, NAME " %p: clear buffers", this); port->n_buffers = 0; this->started = false; } @@ -876,8 +876,6 @@ impl_init(const struct spa_handle_factory *factory, init_ports(this); - spa_log_info(this->log, NAME " %p: initialized", this); - return 0; } diff --git a/spa/plugins/jack/jack-source.c b/spa/plugins/jack/jack-source.c index 83af98df..2d7d619b 100644 --- a/spa/plugins/jack/jack-source.c +++ b/spa/plugins/jack/jack-source.c @@ -598,7 +598,7 @@ impl_node_port_enum_params(void *object, int seq, static int clear_buffers(struct impl *this, struct port *port) { if (port->n_buffers > 0) { - spa_log_info(this->log, NAME " %p: clear buffers", this); + spa_log_debug(this->log, NAME " %p: clear buffers", this); port->n_buffers = 0; spa_list_init(&port->empty); this->started = false; @@ -898,8 +898,6 @@ impl_init(const struct spa_handle_factory *factory, init_ports(this); - spa_log_info(this->log, NAME " %p: initialized", this); - return 0; } diff --git a/spa/plugins/test/fakesink.c b/spa/plugins/test/fakesink.c index 8c0030cf..4b420354 100644 --- a/spa/plugins/test/fakesink.c +++ b/spa/plugins/test/fakesink.c @@ -512,7 +512,7 @@ impl_node_port_enum_params(void *object, int seq, static int clear_buffers(struct impl *this, struct port *port) { if (port->n_buffers > 0) { - spa_log_info(this->log, NAME " %p: clear buffers", this); + spa_log_debug(this->log, NAME " %p: clear buffers", this); port->n_buffers = 0; spa_list_init(&port->ready); this->started = false; @@ -788,8 +788,6 @@ impl_init(const struct spa_handle_factory *factory, spa_list_init(&port->ready); - spa_log_info(this->log, NAME " %p: initialized", this); - return 0; } diff --git a/spa/plugins/test/fakesrc.c b/spa/plugins/test/fakesrc.c index 8f29efc2..9ab27554 100644 --- a/spa/plugins/test/fakesrc.c +++ b/spa/plugins/test/fakesrc.c @@ -528,7 +528,7 @@ impl_node_port_enum_params(void *object, int seq, static int clear_buffers(struct impl *this, struct port *port) { if (port->n_buffers > 0) { - spa_log_info(this->log, NAME " %p: clear buffers", this); + spa_log_debug(this->log, NAME " %p: clear buffers", this); port->n_buffers = 0; spa_list_init(&port->empty); this->started = false; @@ -820,8 +820,6 @@ impl_init(const struct spa_handle_factory *factory, spa_list_init(&port->empty); - spa_log_info(this->log, NAME " %p: initialized", this); - return 0; } diff --git a/spa/plugins/v4l2/v4l2-utils.c b/spa/plugins/v4l2/v4l2-utils.c index 4bbc2725..1f3937d5 100644 --- a/spa/plugins/v4l2/v4l2-utils.c +++ b/spa/plugins/v4l2/v4l2-utils.c @@ -57,7 +57,7 @@ int spa_v4l2_open(struct spa_v4l2_device *dev, const char *path) return -EIO; } - spa_log_info(dev->log, "v4l2: Playback device is '%s'", path); + spa_log_debug(dev->log, "v4l2: Playback device is '%s'", path); if (stat(path, &st) < 0) { err = errno; @@ -111,7 +111,7 @@ int spa_v4l2_close(struct spa_v4l2_device *dev) if (dev->active || dev->have_format) return 0; - spa_log_info(dev->log, "v4l2: close"); + spa_log_debug(dev->log, "v4l2: close"); if (close(dev->fd)) spa_log_warn(dev->log, "close: %m"); @@ -159,7 +159,7 @@ static int spa_v4l2_clear_buffers(struct impl *this) d = b->outbuf->datas; if (SPA_FLAG_IS_SET(b->flags, BUFFER_FLAG_OUTSTANDING)) { - spa_log_info(this->log, "v4l2: queueing outstanding buffer %p", b); + spa_log_debug(this->log, "v4l2: queueing outstanding buffer %p", b); spa_v4l2_buffer_recycle(this, i); } if (SPA_FLAG_IS_SET(b->flags, BUFFER_FLAG_MAPPED)) { @@ -881,7 +881,7 @@ static int spa_v4l2_set_format(struct impl *this, struct spa_video_info *format, streamparm.parm.capture.timeperframe.numerator = framerate->denom; streamparm.parm.capture.timeperframe.denominator = framerate->num; - spa_log_info(this->log, "v4l2: set %.4s %dx%d %d/%d", (char *)&fmt.fmt.pix.pixelformat, + spa_log_debug(this->log, "v4l2: set %.4s %dx%d %d/%d", (char *)&fmt.fmt.pix.pixelformat, fmt.fmt.pix.width, fmt.fmt.pix.height, streamparm.parm.capture.timeperframe.denominator, streamparm.parm.capture.timeperframe.numerator); @@ -1286,7 +1286,7 @@ static int spa_v4l2_use_buffers(struct impl *this, struct spa_buffer **buffers, spa_log_error(this->log, "v4l2: VIDIOC_REQBUFS %m"); return -errno; } - spa_log_info(this->log, "v4l2: got %d buffers", reqbuf.count); + spa_log_debug(this->log, "v4l2: got %d buffers", reqbuf.count); if (reqbuf.count < n_buffers) { spa_log_error(this->log, "v4l2: can't allocate enough buffers"); return -ENOMEM; @@ -1301,7 +1301,7 @@ static int spa_v4l2_use_buffers(struct impl *this, struct spa_buffer **buffers, b->flags = BUFFER_FLAG_OUTSTANDING; b->h = spa_buffer_find_meta_data(buffers[i], SPA_META_Header, sizeof(*b->h)); - spa_log_info(this->log, "v4l2: import buffer %p", buffers[i]); + spa_log_debug(this->log, "v4l2: import buffer %p", buffers[i]); if (buffers[i]->n_datas < 1) { spa_log_error(this->log, "v4l2: invalid memory on buffer %p", buffers[i]); @@ -1369,7 +1369,7 @@ mmap_init(struct impl *this, return -errno; } - spa_log_info(this->log, "v4l2: got %d buffers", reqbuf.count); + spa_log_debug(this->log, "v4l2: got %d buffers", reqbuf.count); n_buffers = reqbuf.count; if (reqbuf.count < 2) { @@ -1377,7 +1377,7 @@ mmap_init(struct impl *this, return -ENOMEM; } if (port->export_buf) - spa_log_info(this->log, "v4l2: using EXPBUF"); + spa_log_debug(this->log, "v4l2: using EXPBUF"); for (i = 0; i < reqbuf.count; i++) { struct buffer *b; diff --git a/spa/plugins/videotestsrc/videotestsrc.c b/spa/plugins/videotestsrc/videotestsrc.c index 758e058b..ff1df883 100644 --- a/spa/plugins/videotestsrc/videotestsrc.c +++ b/spa/plugins/videotestsrc/videotestsrc.c @@ -602,7 +602,7 @@ impl_node_port_enum_params(void *object, int seq, static int clear_buffers(struct impl *this, struct port *port) { if (port->n_buffers > 0) { - spa_log_info(this->log, NAME " %p: clear buffers", this); + spa_log_debug(this->log, NAME " %p: clear buffers", this); port->n_buffers = 0; spa_list_init(&port->empty); this->started = false; @@ -928,8 +928,6 @@ impl_init(const struct spa_handle_factory *factory, port->info.n_params = 5; spa_list_init(&port->empty); - spa_log_info(this->log, NAME " %p: initialized", this); - return 0; } diff --git a/spa/plugins/volume/volume.c b/spa/plugins/volume/volume.c index 27f23b5d..fb5fadb1 100644 --- a/spa/plugins/volume/volume.c +++ b/spa/plugins/volume/volume.c @@ -431,7 +431,7 @@ impl_node_port_enum_params(void *object, int seq, static int clear_buffers(struct impl *this, struct port *port) { if (port->n_buffers > 0) { - spa_log_info(this->log, NAME " %p: clear buffers", this); + spa_log_debug(this->log, NAME " %p: clear buffers", this); port->n_buffers = 0; spa_list_init(&port->empty); } diff --git a/spa/plugins/vulkan/vulkan-compute-source.c b/spa/plugins/vulkan/vulkan-compute-source.c index 82fd3e1f..bc3389bf 100644 --- a/spa/plugins/vulkan/vulkan-compute-source.c +++ b/spa/plugins/vulkan/vulkan-compute-source.c @@ -632,7 +632,7 @@ impl_node_port_enum_params(void *object, int seq, static int clear_buffers(struct impl *this, struct port *port) { if (port->n_buffers > 0) { - spa_log_info(this->log, NAME " %p: clear buffers", this); + spa_log_debug(this->log, NAME " %p: clear buffers", this); spa_vulkan_use_buffers(&this->state, 0, 0, NULL); port->n_buffers = 0; spa_list_init(&port->empty); @@ -948,8 +948,6 @@ impl_init(const struct spa_handle_factory *factory, this->state.log = this->log; - spa_log_info(this->log, NAME " %p: initialized", this); - return 0; } diff --git a/src/examples/export-source.c b/src/examples/export-source.c index 6e53c012..087f5725 100644 --- a/src/examples/export-source.c +++ b/src/examples/export-source.c @@ -339,7 +339,7 @@ static int impl_port_use_buffers(void *object, } b->id = i; b->buffer = buffers[i]; - pw_log_info("got buffer %d size %d", i, datas[0].maxsize); + pw_log_debug("got buffer %d size %d", i, datas[0].maxsize); spa_list_append(&d->empty, &b->link); } d->n_buffers = n_buffers; diff --git a/src/examples/media-session/policy-ep.c b/src/examples/media-session/policy-ep.c index b6743012..dbb9bd78 100644 --- a/src/examples/media-session/policy-ep.c +++ b/src/examples/media-session/policy-ep.c @@ -419,14 +419,14 @@ static int rescan_endpoint(struct impl *impl, struct endpoint *ep) find.ep = ep; find.exclusive = exclusive; - pw_log_info(NAME " %p: exclusive:%d", impl, exclusive); + pw_log_debug(NAME " %p: exclusive:%d", impl, exclusive); str = spa_dict_lookup(props, PW_KEY_ENDPOINT_TARGET); if (str == NULL) str = spa_dict_lookup(props, PW_KEY_NODE_TARGET); if (str != NULL) { uint32_t path_id = atoi(str); - pw_log_info(NAME " %p: target:%d", impl, path_id); + pw_log_debug(NAME " %p: target:%d", impl, path_id); if ((obj = sm_media_session_find_object(impl->session, path_id)) != NULL) { if (strcmp(obj->type, PW_TYPE_INTERFACE_Endpoint) == 0) { diff --git a/src/examples/media-session/policy-node.c b/src/examples/media-session/policy-node.c index 28a3c9a4..82696eb0 100644 --- a/src/examples/media-session/policy-node.c +++ b/src/examples/media-session/policy-node.c @@ -460,12 +460,12 @@ static int rescan_node(struct impl *impl, struct node *n) find.target = n; find.exclusive = exclusive; - pw_log_info(NAME " %p: exclusive:%d", impl, exclusive); + pw_log_debug(NAME " %p: exclusive:%d", impl, exclusive); str = spa_dict_lookup(props, PW_KEY_NODE_TARGET); if (str != NULL) { uint32_t path_id = atoi(str); - pw_log_info(NAME " %p: target:%d", impl, path_id); + pw_log_debug(NAME " %p: target:%d", impl, path_id); if ((obj = sm_media_session_find_object(impl->session, path_id)) != NULL) { if (strcmp(obj->type, PW_TYPE_INTERFACE_Node) == 0) { diff --git a/src/modules/module-client-node/v0/client-node.c b/src/modules/module-client-node/v0/client-node.c index d6369017..4d3c8e07 100644 --- a/src/modules/module-client-node/v0/client-node.c +++ b/src/modules/module-client-node/v0/client-node.c @@ -437,7 +437,7 @@ do_update_port(struct node *this, port = GET_PORT(this, direction, port_id); if (!port->valid) { - spa_log_info(this->log, "node %p: adding port %d", this, port_id); + spa_log_debug(this->log, "node %p: adding port %d", this, port_id); port->id = port_id; port->direction = direction; port->have_format = false; @@ -454,7 +454,7 @@ do_update_port(struct node *this, port->have_format = false; - spa_log_info(this->log, "node %p: port %u update %d params", this, port_id, n_params); + spa_log_debug(this->log, "node %p: port %u update %d params", this, port_id, n_params); for (i = 0; i < port->n_params; i++) free(port->params[i]); port->n_params = n_params; @@ -504,7 +504,7 @@ static void do_uninit_port(struct node *this, enum spa_direction direction, uint { struct port *port; - spa_log_info(this->log, "node %p: removing port %d", this, port_id); + spa_log_debug(this->log, "node %p: removing port %d", this, port_id); if (direction == SPA_DIRECTION_INPUT) { port = GET_IN_PORT(this, port_id); @@ -637,7 +637,7 @@ impl_node_port_set_io(void *object, impl = this->impl; - spa_log_info(this->log, "node %p: port %d.%d set io %d %p", this, + spa_log_debug(this->log, "node %p: port %d.%d set io %d %p", this, direction, port_id, id, data); if (id == SPA_IO_Buffers) { @@ -694,7 +694,7 @@ impl_node_port_use_buffers(void *object, spa_return_val_if_fail(CHECK_PORT(this, direction, port_id), -EINVAL); impl = this->impl; - spa_log_info(this->log, "node %p: use buffers %p %u", this, buffers, n_buffers); + spa_log_debug(this->log, "node %p: use buffers %p %u", this, buffers, n_buffers); port = GET_PORT(this, direction, port_id); @@ -1010,7 +1010,7 @@ client_node0_update(void *data, this->info.max_output_ports = max_output_ports; if (change_mask & PW_CLIENT_NODE0_UPDATE_PARAMS) { uint32_t i; - spa_log_info(this->log, "node %p: update %d params", this, n_params); + spa_log_debug(this->log, "node %p: update %d params", this, n_params); for (i = 0; i < this->n_params; i++) free(this->params[i]); @@ -1024,7 +1024,7 @@ client_node0_update(void *data, spa_node_emit_info(&this->hooks, &this->info); } - spa_log_info(this->log, "node %p: got node update max_in %u, max_out %u", this, + spa_log_debug(this->log, "node %p: got node update max_in %u, max_out %u", this, this->info.max_input_ports, this->info.max_output_ports); } @@ -1041,7 +1041,7 @@ client_node0_port_update(void *data, struct node *this = &impl->node; bool remove; - spa_log_info(this->log, "node %p: got port update", this); + spa_log_debug(this->log, "node %p: got port update", this); if (!CHECK_PORT_ID(this, direction, port_id)) return; diff --git a/src/modules/module-protocol-native.c b/src/modules/module-protocol-native.c index f9fa3e11..9b78c25c 100644 --- a/src/modules/module-protocol-native.c +++ b/src/modules/module-protocol-native.c @@ -1012,7 +1012,7 @@ create_server(struct pw_protocol *protocol, pw_loop_add_hook(pw_context_get_main_loop(context), &s->hook, &impl_hooks, s); - pw_log_info(NAME" %p: created server %p", protocol, this); + pw_log_debug(NAME" %p: created server %p", protocol, this); return s; } diff --git a/src/modules/spa/spa-node.c b/src/modules/spa/spa-node.c index 15ed04c1..f13c2757 100644 --- a/src/modules/spa/spa-node.c +++ b/src/modules/spa/spa-node.c @@ -187,7 +187,7 @@ setup_props(struct pw_context *context, struct spa_node *spa_node, struct pw_pro if ((prop = spa_pod_find_prop(props, prop, type))) { const char *value = pw_properties_get(pw_props, key); - pw_log_info("configure prop %s to %s", key, value); + pw_log_debug("configure prop %s to %s", key, value); switch(prop->value.type) { case SPA_TYPE_Bool: diff --git a/src/pipewire/context.c b/src/pipewire/context.c index d645fba5..1c1693bf 100644 --- a/src/pipewire/context.c +++ b/src/pipewire/context.c @@ -876,8 +876,8 @@ int pw_context_recalc_graph(struct pw_context *context) if (n->rt.position && n->quantum_current != n->rt.position->clock.duration) { n->rt.position->clock.duration = n->quantum_current; - pw_log_info(NAME" %p: new quantum %u for master '%s'", context, - n->quantum_current, n->name); + pw_log_info("(%s-%u) new quantum:%u", + n->name, n->info.id, n->quantum_current); } pw_log_debug(NAME" %p: master %p quantum:%u '%s'", context, n, diff --git a/src/pipewire/impl-device.c b/src/pipewire/impl-device.c index f9e6c682..01e89cd0 100644 --- a/src/pipewire/impl-device.c +++ b/src/pipewire/impl-device.c @@ -116,10 +116,11 @@ static void check_properties(struct pw_impl_device *device) { const char *str; - if ((str = pw_properties_get(device->properties, PW_KEY_DEVICE_NAME))) { + if ((str = pw_properties_get(device->properties, PW_KEY_DEVICE_NAME)) && + (device->name == NULL || strcmp(str, device->name) != 0)) { free(device->name); device->name = strdup(str); - pw_log_info(NAME" %p: name '%s'", device, device->name); + pw_log_debug(NAME" %p: name '%s'", device, device->name); } } diff --git a/src/pipewire/impl-link.c b/src/pipewire/impl-link.c index c4c40a92..6bb3fd3d 100644 --- a/src/pipewire/impl-link.c +++ b/src/pipewire/impl-link.c @@ -114,12 +114,17 @@ static void pw_impl_link_update_state(struct pw_impl_link *link, enum pw_link_st if (state == old) return; + pw_log_debug(NAME" %p: %s -> %s (%s)", link, + pw_link_state_as_string(old), + pw_link_state_as_string(state), error); + if (state == PW_LINK_STATE_ERROR) { - pw_log_error(NAME" %p: update state %s -> error (%s)", link, - pw_link_state_as_string(old), error); + pw_log_error("(%s) %s -> error (%s)", link->name, + pw_link_state_as_string(old), error); } else { - pw_log_debug(NAME" %p: update state %s -> %s", link, - pw_link_state_as_string(old), pw_link_state_as_string(state)); + pw_log_info("(%s) %s -> %s", link->name, + pw_link_state_as_string(old), + pw_link_state_as_string(state)); } link->info.state = state; @@ -1139,6 +1144,11 @@ struct pw_impl_link *pw_context_create_link(struct pw_context *context, output_node, output->port_id, this->rt.out_mix.port.port_id, input_node, input->port_id, this->rt.in_mix.port.port_id); + asprintf(&this->name, "%d.%d -> %d.%d", + output_node->info.id, output->port_id, + input_node->info.id, input->port_id); + pw_log_info("(%s) (%s) -> (%s)", this->name, output_node->name, input_node->name); + pw_impl_port_emit_link_added(output, this); pw_impl_port_emit_link_added(input, this); @@ -1272,6 +1282,7 @@ void pw_impl_link_destroy(struct pw_impl_link *link) struct impl *impl = SPA_CONTAINER_OF(link, struct impl, this); pw_log_debug(NAME" %p: destroy", impl); + pw_log_info("(%s) destroy", link->name); pw_impl_link_emit_destroy(link); pw_impl_link_deactivate(link); @@ -1300,6 +1311,7 @@ void pw_impl_link_destroy(struct pw_impl_link *link) pw_context_recalc_graph(link->context); + free(link->name); free(link->info.format); free(impl); } diff --git a/src/pipewire/impl-node.c b/src/pipewire/impl-node.c index 13473850..8ee90d60 100644 --- a/src/pipewire/impl-node.c +++ b/src/pipewire/impl-node.c @@ -195,8 +195,8 @@ static int start_node(struct pw_impl_node *this) &SPA_NODE_COMMAND_INIT(SPA_NODE_COMMAND_Start)); if (res < 0) - pw_log_error(NAME" %p: start node error %d: %s", - this, res, spa_strerror(res)); + pw_log_error("(%s-%u) start node error %d: %s", this->name, this->info.id, + res, spa_strerror(res)); return res; } @@ -296,11 +296,14 @@ static void node_update_state(struct pw_impl_node *node, enum pw_node_state stat if (old == state) return; + pw_log_debug(NAME" %p: (%s) %s -> %s (%s)", node, node->name, + pw_node_state_as_string(old), pw_node_state_as_string(state), error); + if (state == PW_NODE_STATE_ERROR) { - pw_log_error(NAME" %p: update state from %s -> error (%s)", node, + pw_log_error("(%s-%u) %s -> error (%s)", node->name, node->info.id, pw_node_state_as_string(old), error); } else { - pw_log_debug(NAME" %p: update state from %s -> %s", node, + pw_log_info("(%s-%u) %s -> %s", node->name, node->info.id, pw_node_state_as_string(old), pw_node_state_as_string(state)); } @@ -673,8 +676,11 @@ int pw_impl_node_set_driver(struct pw_impl_node *node, struct pw_impl_node *driv remove_segment_master(old, node->info.id); node->master = node->driver && driver == node; - pw_log_info(NAME" %p: driver %p (%s) quantum:%u master:%u", node, - driver, driver->name, driver->quantum_current, node->master); + pw_log_debug(NAME" %p: driver %p quantum:%u master:%u", node, + driver, driver->quantum_current, node->master); + pw_log_info("(%s-%u) -> driver (%s-%d) quantum:%u", + node->name, node->info.id, driver->name, + driver->info.id, driver->quantum_current); node->driver_node = driver; @@ -715,14 +721,14 @@ static void check_properties(struct pw_impl_node *node) if ((str = pw_properties_get(node->properties, PW_KEY_PRIORITY_MASTER))) { node->priority_master = pw_properties_parse_int(str); - pw_log_info(NAME" %p: priority master %d", node, node->priority_master); + pw_log_debug(NAME" %p: priority master %d", node, node->priority_master); } if ((str = pw_properties_get(node->properties, PW_KEY_NODE_NAME)) && - (node->name == NULL || strcmp(str, node->name) != 0)) { + (node->name == NULL || strcmp(node->name, str) != 0)) { free(node->name); node->name = strdup(str); - pw_log_info(NAME" %p: name '%s'", node, node->name); + pw_log_debug(NAME" %p: name '%s'", node, node->name); } if ((str = pw_properties_get(node->properties, PW_KEY_NODE_PAUSE_ON_IDLE))) @@ -741,7 +747,7 @@ static void check_properties(struct pw_impl_node *node) node->want_driver = false; if (node->driver != driver) { - pw_log_info(NAME" %p: driver %d -> %d", node, node->driver, driver); + pw_log_debug(NAME" %p: driver %d -> %d", node, node->driver, driver); node->driver = driver; if (node->registered) { if (driver) @@ -759,8 +765,10 @@ static void check_properties(struct pw_impl_node *node) quantum_size = flp2((num * context->defaults.clock_rate / denom)); if (quantum_size != node->quantum_size) { - pw_log_info(NAME" %p: latency '%s' quantum %u/%u", + pw_log_debug(NAME" %p: latency '%s' quantum %u/%u", node, str, quantum_size, context->defaults.clock_rate); + pw_log_info("(%s-%u) quantum %u/%u", node->name, node->info.id, + quantum_size, context->defaults.clock_rate); node->quantum_size = quantum_size; do_recalc |= node->active; } @@ -796,9 +804,9 @@ static void dump_states(struct pw_impl_node *driver) struct pw_node_activation_state *state = &a->state[0]; if (t->node == NULL) continue; - pw_log_warn(NAME" %p (%s): state:%p pending:%d/%d s:%"PRIu64" a:%"PRIu64" f:%"PRIu64 + pw_log_warn("(%s-%u) state:%p pending:%d/%d s:%"PRIu64" a:%"PRIu64" f:%"PRIu64 " waiting:%"PRIu64" process:%"PRIu64" status:%s sync:%d", - t->node, t->node->name, state, + t->node->name, t->node->info.id, state, state->pending, state->required, a->signal_time, a->awake_time, @@ -1318,7 +1326,8 @@ static void update_position(struct pw_impl_node *node, int all_ready) if (a->position.state == SPA_IO_POSITION_STATE_STARTING) { if (!all_ready && --a->sync_left == 0) { - pw_log_warn(NAME" %p: sync timeout, going to RUNNING", node); + pw_log_warn("(%s-%u) sync timeout, going to RUNNING", + node->name, node->info.id); pw_context_driver_emit_timeout(node->context, node); dump_states(node); all_ready = true; @@ -1348,8 +1357,9 @@ static int node_ready(void *data, int status) uint64_t min_timeout = UINT64_MAX; if (SPA_UNLIKELY(state->pending > 0)) { - pw_log_warn(NAME" %p: graph not finished: state:%p pending %d/%d", - node, state, state->pending, state->required); + pw_log_warn("(%s-%u) graph not finished: state:%p pending %d/%d", + node->name, node->info.id, state, state->pending, + state->required); pw_context_driver_emit_incomplete(node->context, node); dump_states(node); node->rt.target.signal(node->rt.target.data); @@ -1517,6 +1527,7 @@ void pw_impl_node_destroy(struct pw_impl_node *node) node->active = false; pw_log_debug(NAME" %p: destroy", impl); + pw_log_info("(%s-%u) destroy", node->name, node->info.id); pw_impl_node_emit_destroy(node); suspend_node(node); diff --git a/src/pipewire/private.h b/src/pipewire/private.h index a59698b2..629ae3ca 100644 --- a/src/pipewire/private.h +++ b/src/pipewire/private.h @@ -704,19 +704,21 @@ struct pw_control_link { struct pw_impl_link { struct pw_context *context; /**< context object */ - struct spa_list link; /**< link in context link_list */ - struct pw_global *global; /**< global for this link */ + struct spa_list link; /**< link in context link_list */ + struct pw_global *global; /**< global for this link */ struct spa_hook global_listener; - struct pw_link_info info; /**< introspectable link info */ + char *name; + + struct pw_link_info info; /**< introspectable link info */ struct pw_properties *properties; /**< extra link properties */ - struct spa_io_buffers *io; /**< link io area */ + struct spa_io_buffers *io; /**< link io area */ struct pw_impl_port *output; /**< output port */ - struct spa_list output_link; /**< link in output port links */ + struct spa_list output_link; /**< link in output port links */ struct pw_impl_port *input; /**< input port */ - struct spa_list input_link; /**< link in input port links */ + struct spa_list input_link; /**< link in input port links */ struct spa_hook_list listener_list; @@ -725,8 +727,8 @@ struct pw_impl_link { struct { struct pw_impl_port_mix out_mix; /**< port added to the output mixer */ - struct pw_impl_port_mix in_mix; /**< port added to the input mixer */ - struct pw_node_target target; /**< target to trigger the input node */ + struct pw_impl_port_mix in_mix; /**< port added to the input mixer */ + struct pw_node_target target; /**< target to trigger the input node */ } rt; void *user_data; |