From d8bac82e72f2f32d04b3074a31e8ed4f91735197 Mon Sep 17 00:00:00 2001 From: Wim Taymans Date: Fri, 21 Feb 2020 11:09:34 +0100 Subject: [PATCH] improve logging Remove some harmless warnings from the log Remove some excessive info logging --- spa/plugins/alsa/alsa-pcm.c | 4 ++-- spa/plugins/alsa/alsa-seq-source.c | 1 + spa/plugins/audioconvert/channelmix.c | 2 +- spa/plugins/audioconvert/fmtconvert.c | 2 +- spa/plugins/audioconvert/merger.c | 2 +- spa/plugins/audioconvert/splitter.c | 2 +- src/modules/module-access.c | 4 ++-- src/modules/module-client-node/client-node.c | 13 ++++++------- src/modules/module-protocol-native/connection.c | 2 +- src/pipewire/context.c | 5 ++--- src/pipewire/impl-node.c | 12 ++++++------ 11 files changed, 24 insertions(+), 25 deletions(-) diff --git a/spa/plugins/alsa/alsa-pcm.c b/spa/plugins/alsa/alsa-pcm.c index a0a831656..2684ad2d4 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_info(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_info(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); diff --git a/spa/plugins/alsa/alsa-seq-source.c b/spa/plugins/alsa/alsa-seq-source.c index 36da7d704..299f5e3de 100644 --- a/spa/plugins/alsa/alsa-seq-source.c +++ b/spa/plugins/alsa/alsa-seq-source.c @@ -195,6 +195,7 @@ static int impl_node_send_command(void *object, const struct spa_command *comman return res; break; case SPA_NODE_COMMAND_Pause: + case SPA_NODE_COMMAND_Suspend: if ((res = spa_alsa_seq_pause(this)) < 0) return res; break; diff --git a/spa/plugins/audioconvert/channelmix.c b/spa/plugins/audioconvert/channelmix.c index 9e6d0cd1e..e68ec5e44 100644 --- a/spa/plugins/audioconvert/channelmix.c +++ b/spa/plugins/audioconvert/channelmix.c @@ -245,7 +245,7 @@ static int setup_convert(struct impl *this, emit_params_changed(this); - spa_log_info(this->log, NAME " %p: got channelmix features %08x:%08x identity:%d", + spa_log_debug(this->log, NAME " %p: got channelmix features %08x:%08x identity:%d", this, this->cpu_flags, this->mix.cpu_flags, this->mix.identity); diff --git a/spa/plugins/audioconvert/fmtconvert.c b/spa/plugins/audioconvert/fmtconvert.c index 425aa23dd..3e0f0884f 100644 --- a/spa/plugins/audioconvert/fmtconvert.c +++ b/spa/plugins/audioconvert/fmtconvert.c @@ -194,7 +194,7 @@ static int setup_convert(struct impl *this) if ((res = convert_init(&this->conv)) < 0) return res; - spa_log_info(this->log, NAME " %p: got converter features %08x:%08x", this, + spa_log_debug(this->log, NAME " %p: got converter features %08x:%08x", this, this->cpu_flags, this->conv.cpu_flags); this->is_passthrough = this->conv.is_passthrough; diff --git a/spa/plugins/audioconvert/merger.c b/spa/plugins/audioconvert/merger.c index ea8fe233a..e3d917892 100644 --- a/spa/plugins/audioconvert/merger.c +++ b/spa/plugins/audioconvert/merger.c @@ -594,7 +594,7 @@ static int setup_convert(struct impl *this) if ((res = convert_init(&this->conv)) < 0) return res; - spa_log_info(this->log, NAME " %p: got converter features %08x:%08x", this, + spa_log_debug(this->log, NAME " %p: got converter features %08x:%08x", this, this->cpu_flags, this->conv.cpu_flags); this->is_passthrough = src_fmt == dst_fmt; diff --git a/spa/plugins/audioconvert/splitter.c b/spa/plugins/audioconvert/splitter.c index 56c94df6c..ba1f5af3c 100644 --- a/spa/plugins/audioconvert/splitter.c +++ b/spa/plugins/audioconvert/splitter.c @@ -582,7 +582,7 @@ static int setup_convert(struct impl *this) if ((res = convert_init(&this->conv)) < 0) return res; - spa_log_info(this->log, NAME " %p: got converter features %08x:%08x", this, + spa_log_debug(this->log, NAME " %p: got converter features %08x:%08x", this, this->cpu_flags, this->conv.cpu_flags); this->is_passthrough &= this->conv.is_passthrough; diff --git a/src/modules/module-access.c b/src/modules/module-access.c index 0cd9bf2f7..c31ce709e 100644 --- a/src/modules/module-access.c +++ b/src/modules/module-access.c @@ -128,10 +128,10 @@ context_check_access(void *data, struct pw_impl_client *client) } if (pid < 0) { - pw_log_info("no trusted pid found, assuming not sandboxed\n"); + pw_log_info("client %p: no trusted pid found, assuming not sandboxed", client); goto granted; } else { - pw_log_info("client has trusted pid %d", pid); + pw_log_info("client %p has trusted pid %d", client, pid); } if (impl->properties && (str = pw_properties_get(impl->properties, "blacklisted")) != NULL) { diff --git a/src/modules/module-client-node/client-node.c b/src/modules/module-client-node/client-node.c index dc8ff94d7..a2e1e6d35 100644 --- a/src/modules/module-client-node/client-node.c +++ b/src/modules/module-client-node/client-node.c @@ -322,7 +322,7 @@ static int impl_node_set_param(void *object, uint32_t id, uint32_t flags, spa_return_val_if_fail(this != NULL, -EINVAL); if (this->resource == NULL) - return -EIO; + return param == NULL ? 0 : -EIO; return pw_client_node_resource_set_param(this->resource, id, flags, param); } @@ -357,7 +357,7 @@ static int impl_node_set_io(void *object, uint32_t id, void *data, size_t size) } if (this->resource == NULL) - return -EIO; + return data == NULL ? 0 : -EIO; return pw_client_node_resource_set_io(this->resource, id, @@ -626,8 +626,7 @@ impl_node_port_set_param(void *object, } } if (this->resource == NULL) - return -EIO; - + return param == NULL ? 0 : -EIO; return pw_client_node_resource_port_set_param(this->resource, direction, port_id, @@ -677,7 +676,7 @@ static int do_port_set_io(struct impl *impl, } if (this->resource == NULL) - return -EIO; + return data == NULL ? 0 : -EIO; return pw_client_node_resource_port_set_io(this->resource, direction, port_id, @@ -740,7 +739,7 @@ do_port_use_buffers(struct impl *impl, mix->n_buffers = n_buffers; if (this->resource == NULL) - return -EIO; + return n_buffers == 0 ? 0 : -EIO; for (i = 0; i < n_buffers; i++) { struct buffer *b = &mix->buffers[i]; @@ -1404,7 +1403,7 @@ static int impl_mix_port_set_io(void *object, mix = pw_map_lookup(&port->mix_port_map, mix_id); if (mix == NULL) - return -EIO; + return -EINVAL; if (id == SPA_IO_Buffers) { if (data && size >= sizeof(struct spa_io_buffers)) diff --git a/src/modules/module-protocol-native/connection.c b/src/modules/module-protocol-native/connection.c index 4465c2cef..4ab330ef4 100644 --- a/src/modules/module-protocol-native/connection.c +++ b/src/modules/module-protocol-native/connection.c @@ -145,7 +145,7 @@ static void *connection_ensure_size(struct pw_protocol_native_connection *conn, errno = -res; return NULL; } - pw_log_warn("connection %p: resize buffer to %zd %zd %zd", + pw_log_debug("connection %p: resize buffer to %zd %zd %zd", conn, buf->buffer_size, size, buf->buffer_maxsize); } return (uint8_t *) buf->buffer_data + buf->buffer_size; diff --git a/src/pipewire/context.c b/src/pipewire/context.c index 164ff864a..09f8dc1fd 100644 --- a/src/pipewire/context.c +++ b/src/pipewire/context.c @@ -829,7 +829,6 @@ int pw_context_recalc_graph(struct pw_context *context) * to an active master */ spa_list_for_each(n, &context->node_list, link) { if (!n->visited) { - pw_log_debug(NAME" %p: unassigned node %p: '%s' %d %d", context, n, n->name, n->active, n->want_driver); @@ -856,11 +855,11 @@ 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: master %p quantum:%u '%s'", context, n, + pw_log_debug(NAME" %p: master %p quantum:%u '%s'", context, n, n->quantum_current, n->name); spa_list_for_each(s, &n->follower_list, follower_link) - pw_log_info(NAME" %p: follower %p: active:%d '%s'", + pw_log_debug(NAME" %p: follower %p: active:%d '%s'", context, s, s->active, s->name); } return 0; diff --git a/src/pipewire/impl-node.c b/src/pipewire/impl-node.c index b1b5c7498..1e34cdf49 100644 --- a/src/pipewire/impl-node.c +++ b/src/pipewire/impl-node.c @@ -340,7 +340,7 @@ static int suspend_node(struct pw_impl_node *this) res = spa_node_send_command(this->node, &SPA_NODE_COMMAND_INIT(SPA_NODE_COMMAND_Suspend)); - if (res < 0) + if (res < 0 && res != -EIO) pw_log_warn(NAME" %p: suspend node error %s", this, spa_strerror(res)); node_update_state(this, PW_NODE_STATE_SUSPENDED, NULL); @@ -666,7 +666,7 @@ 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 master:%u", node, driver, node->master); + pw_log_info(NAME" %p: driver %p (%s) master:%u", node, driver, driver->name, node->master); node->driver_node = driver; @@ -709,7 +709,8 @@ static void check_properties(struct pw_impl_node *node) pw_log_info(NAME" %p: priority master %d", node, node->priority_master); } - if ((str = pw_properties_get(node->properties, PW_KEY_NODE_NAME))) { + if ((str = pw_properties_get(node->properties, PW_KEY_NODE_NAME)) && + (node->name == NULL || strcmp(str, node->name) != 0)) { free(node->name); node->name = strdup(str); pw_log_info(NAME" %p: name '%s'", node, node->name); @@ -743,14 +744,13 @@ static void check_properties(struct pw_impl_node *node) if ((str = pw_properties_get(node->properties, PW_KEY_NODE_LATENCY))) { uint32_t num, denom; - pw_log_info(NAME" %p: latency '%s'", node, str); if (sscanf(str, "%u/%u", &num, &denom) == 2 && denom != 0) { uint32_t quantum_size; - quantum_size = flp2((num * 48000 / denom)); - pw_log_info(NAME" %p: quantum %d", node, quantum_size); + quantum_size = flp2((num * node->context->defaults.clock_rate / denom)); if (quantum_size != node->quantum_size) { + pw_log_info(NAME" %p: latency '%s' quantum %d", node, str, quantum_size); node->quantum_size = quantum_size; do_recalc |= node->active; }