improve error messages

Log an error when we send an error to the client so that we don't need
to log and error anymore.
Improve the error messages when we can
Move some warnings and errors to debug

src/modules/module-link-factory.c

@@ -285,36 +285,31 @@ static void *create_object(void *_data,
 
 error_properties:
 	res = -EINVAL;
-	pw_log_error(NAME" usage:" FACTORY_USAGE);
-	pw_resource_error(resource, res, "no properties");
+	pw_resource_error(resource, res, NAME": no properties. usage:"FACTORY_USAGE);
 	goto error_exit;
 error_output:
 	res = -EINVAL;
-	pw_log_error(NAME" unknown output node %u", output_node_id);
-	pw_resource_errorf(resource, res, "unknown output node %u", output_node_id);
+	pw_resource_errorf(resource, res, NAME": unknown output node %u", output_node_id);
 	goto error_exit;
 error_input:
 	res = -EINVAL;
-	pw_log_error(NAME" unknown input node %u", input_node_id);
-	pw_resource_errorf(resource, res, "unknown input node %u", input_node_id);
+	pw_resource_errorf(resource, res, NAME": unknown input node %u", input_node_id);
 	goto error_exit;
 error_output_port:
 	res = -EINVAL;
-	pw_log_error(NAME" unknown output port %u", output_port_id);
-	pw_resource_errorf(resource, res, "unknown output port %u", output_port_id);
+	pw_resource_errorf(resource, res, NAME": unknown output port %u", output_port_id);
 	goto error_exit;
 error_input_port:
 	res = -EINVAL;
-	pw_log_error(NAME" unknown input port %u", input_port_id);
-	pw_resource_errorf(resource, res, "unknown input port %u", input_port_id);
+	pw_resource_errorf(resource, res, NAME": unknown input port %u", input_port_id);
 	goto error_exit;
 error_create_link:
-	pw_log_error("can't create link: %s", spa_strerror(res));
-	pw_resource_errorf(resource, res, "can't create link: %s", spa_strerror(res));
+	pw_resource_errorf(resource, res, NAME": can't link ports %d and %d: %s",
+			pw_impl_port_get_id(outport), pw_impl_port_get_id(inport),
+			spa_strerror(res));
 	goto error_exit;
 error_link_register:
-	pw_log_error("can't register link: %s", spa_strerror(res));
-	pw_resource_errorf(resource, res, "can't register link: %s", spa_strerror(res));
+	pw_resource_errorf(resource, res, NAME": can't register link: %s", spa_strerror(res));
 	goto error_exit;
 error_exit:
 	if (properties)

src/modules/module-protocol-native.c

@@ -179,8 +179,6 @@ process_messages(struct client_data *data)
 
 		resource = pw_impl_client_find_resource(client, msg->id);
 		if (resource == NULL) {
-			pw_log_error(NAME" %p: unknown resource %u op:%u",
-				     client->protocol, msg->id, msg->opcode);
 			pw_resource_errorf(client->core_resource,
 					-EINVAL, "unknown resource %u op:%u", msg->id, msg->opcode);
 			continue;
@@ -202,10 +200,9 @@ process_messages(struct client_data *data)
 		required = demarshal[msg->opcode].permissions | PW_PERM_X;
 
 		if ((required & permissions) != required) {
-			pw_log_error(NAME" %p: method %u on %u requires %08x, have %08x",
-				     client->protocol, msg->opcode, msg->id, required, permissions);
 			pw_resource_errorf(resource,
-				-EACCES, "no permission to call method %u on %u", msg->opcode, msg->id);
+				-EACCES, "no permission to call method %u on %u (requires %08x, have %08x)",
+				msg->opcode, msg->id, required, permissions);
 			continue;
 		}
 
@@ -218,20 +215,17 @@ done:
 	return res;
 
 invalid_method:
-	pw_log_error(NAME" %p: invalid method id:%u op:%u",
-		     client->protocol, msg->id, msg->opcode);
 	pw_resource_errorf(resource, res, "invalid method id:%u op:%u",
 			msg->id, msg->opcode);
 	goto done;
 invalid_message:
-	pw_log_error(NAME" %p: invalid message received id:%u op:%u (%s)",
-		     client->protocol, msg->id, msg->opcode, spa_strerror(res));
 	pw_resource_errorf(resource, res, "invalid message received id:%u op:%u (%s)",
 			msg->id, msg->opcode, spa_strerror(res));
 	debug_msg("*invalid message*", msg, true);
 	goto done;
 error:
-	pw_log_error(NAME" %p: client error (%s)", client->protocol, spa_strerror(res));
+	pw_resource_errorf(client->core_resource, res, "client error %d (%s)",
+			res, spa_strerror(res));
 	goto done;
 }
 
@@ -358,7 +352,7 @@ static struct client_data *client_new(struct server *s, int fd)
 #ifndef __FreeBSD__
 	len = sizeof(ucred);
 	if (getsockopt(fd, SOL_SOCKET, SO_PEERCRED, &ucred, &len) < 0) {
-		pw_log_error("server %p: no peercred: %m", s);
+		pw_log_warn("server %p: no peercred: %m", s);
 	} else {
 		pw_properties_setf(props, PW_KEY_SEC_PID, "%d", ucred.pid);
 		pw_properties_setf(props, PW_KEY_SEC_UID, "%d", ucred.uid);
@@ -709,7 +703,7 @@ on_remote_data(void *data, int fd, uint32_t mask)
 	}
 	return;
 error:
-	pw_log_error(NAME" %p: got connection error %d (%s)", impl, res, spa_strerror(res));
+	pw_log_debug(NAME" %p: got connection error %d (%s)", impl, res, spa_strerror(res));
 	pw_proxy_notify((struct pw_proxy*)this,
 			struct pw_core_events, error, 0, 0,
 			this->recv_seq, res, "connection error");

src/modules/module-protocol-native/connection.c

@@ -118,7 +118,7 @@ uint32_t pw_protocol_native_connection_add_fd(struct pw_protocol_native_connecti
 
 	index = buf->msg.n_fds;
 	if (index + buf->n_fds >= MAX_FDS) {
-		pw_log_error("connection %p: too many fds", conn);
+		pw_log_error("connection %p: too many fds (%d)", conn, MAX_FDS);
 		return SPA_IDX_INVALID;
 	}
 
@@ -204,7 +204,7 @@ static int refill_buffer(struct pw_protocol_native_connection *conn, struct buff
 
 	/* ERRORS */
 recv_error:
-	pw_log_error("could not recvmsg on fd:%d: %s", conn->fd, strerror(errno));
+	pw_log_error("connection %p: could not recvmsg on fd:%d: %m", conn, conn->fd);
 	return -errno;
 }
 

src/modules/module-protocol-native/protocol-native.c

@@ -648,7 +648,7 @@ static int core_method_demarshal_destroy(void *object, const struct pw_protocol_
 	return pw_resource_notify(resource, struct pw_core_methods, destroy, 0, r);
 
       no_resource:
-	pw_log_error("client %p: unknown resouce %u op:%u", client, id, msg->opcode);
+	pw_log_debug("client %p: unknown resouce %u op:%u", client, id, msg->opcode);
 	pw_resource_errorf(resource, -EINVAL, "unknown resource %d op:%u", id, msg->opcode);
 	return 0;
 }

src/pipewire/core.c

@@ -66,10 +66,10 @@ static void core_event_error(void *data, uint32_t id, int seq, int res, const ch
 	struct pw_core *this = data;
 	struct pw_proxy *proxy;
 
-	pw_log_error(NAME" %p: object error %u: seq:%d %d (%s): %s", this, id, seq,
-			res, spa_strerror(res), message);
-
 	proxy = pw_map_lookup(&this->objects, id);
+
+	pw_log_error(NAME" %p: proxy %p id:%u: seq:%d res:%d (%s) msg:\"%s\"",
+			this, proxy, id, seq, res, spa_strerror(res), message);
 	if (proxy)
 		pw_proxy_emit_error(proxy, seq, res, message);
 }

src/pipewire/impl-core.c

@@ -69,11 +69,11 @@ static void * registry_bind(void *object, uint32_t id,
 
 error_no_id:
 	pw_log_debug("registry %p: no global with id %u to bind to %u", resource, id, new_id);
-	pw_resource_errorf(resource, -ENOENT, "no such global %u", id);
+	pw_resource_errorf(resource, -ENOENT, "no global %u", id);
 	goto error_exit_clean;
 error_wrong_interface:
 	pw_log_debug("registry %p: global with id %u has no interface %s", resource, id, type);
-	pw_resource_errorf(resource, -ENOENT, "no such interface %s", type);
+	pw_resource_errorf(resource, -ENOENT, "no interface %s", type);
 	goto error_exit_clean;
 error_exit_clean:
 	/* unmark the new_id the map, the client does not yet know about the failed
@@ -260,10 +260,10 @@ static struct pw_registry * core_get_registry(void *object, uint32_t version, si
 	return (struct pw_registry *)registry_resource;
 
 error_resource:
-	pw_log_error(NAME" %p: can't create registry resource: %m", context);
 	pw_core_resource_errorf(client->core_resource, new_id,
 			client->recv_seq, res,
-			"can't create registry resource: %s", spa_strerror(res));
+			"can't create registry resource: %d (%s)",
+			res, spa_strerror(res));
 	pw_map_insert_at(&client->objects, new_id, NULL);
 	pw_core_resource_remove_id(client->core_resource, new_id);
 	errno = -res;
@@ -316,18 +316,18 @@ core_create_object(void *object,
 
 error_no_factory:
 	res = -ENOENT;
-	pw_log_error(NAME" %p: can't find factory '%s'", context, factory_name);
+	pw_log_debug(NAME" %p: can't find factory '%s'", context, factory_name);
 	pw_resource_errorf(resource, res, "unknown factory name %s", factory_name);
 	goto error_exit;
 error_version:
 error_type:
 	res = -EPROTO;
-	pw_log_error(NAME" %p: invalid resource type/version", context);
+	pw_log_debug(NAME" %p: invalid resource type/version", context);
 	pw_resource_errorf(resource, res, "wrong resource type/version");
 	goto error_exit;
 error_properties:
 	res = -errno;
-	pw_log_error(NAME" %p: can't create properties: %m", context);
+	pw_log_debug(NAME" %p: can't create properties: %m", context);
 	pw_resource_errorf(resource, res, "can't create properties: %s", spa_strerror(res));
 	goto error_exit;
 error_create_failed:

src/pipewire/impl-device.c

@@ -305,8 +305,9 @@ static int device_enum_params(void *object, int seq, uint32_t id, uint32_t start
 				filter, reply_param, data);
 
 	if (res < 0) {
-		pw_core_resource_error(client->core_resource,
-				resource->id, seq, res, spa_strerror(res));
+		pw_resource_errorf(resource, res,
+				"enum params id:%d (%s) failed", id,
+				spa_debug_type_find_name(spa_type_param, id));
 	} else if (SPA_RESULT_IS_ASYNC(res)) {
 		pw_impl_client_set_busy(client, true);
 		data->data.data = data;
@@ -368,7 +369,9 @@ static int device_set_param(void *object, uint32_t id, uint32_t flags,
 	};
 
 	if ((res = spa_device_set_param(device->device, id, flags, param)) < 0) {
-		pw_resource_error(resource, res, spa_strerror(res));
+		pw_resource_errorf(resource, res,
+				"set param id:%d (%s) flags:%08x failed", id,
+				spa_debug_type_find_name(spa_type_param, id), flags);
 	} else if (SPA_RESULT_IS_ASYNC(res)) {
 		pw_impl_client_set_busy(client, true);
 		data->data.data = data;

src/pipewire/impl-link.c

@@ -375,8 +375,10 @@ static int port_set_io(struct pw_impl_link *this, struct pw_impl_port *port, uin
 		if (res == -ENOTSUP)
 			res = 0;
 		else
-			pw_log_warn(NAME" %p: port %p can't set io: %s", this,
-					port, spa_strerror(res));
+			pw_log_warn(NAME" %p: port %p can't set io:%d (%s): %s",
+					this, port, id,
+					spa_debug_type_find_name(spa_type_io, id),
+					spa_strerror(res));
 	}
 	return res;
 }
@@ -1131,26 +1133,26 @@ struct pw_impl_link *pw_context_create_link(struct pw_context *context,
 
 error_same_ports:
 	res = -EINVAL;
-	pw_log_error("can't link the same ports");
+	pw_log_debug("can't link the same ports");
 	goto error_exit;
 error_wrong_direction:
 	res = -EINVAL;
-	pw_log_error("ports have wrong direction");
+	pw_log_debug("ports have wrong direction");
 	goto error_exit;
 error_link_exists:
 	res = -EEXIST;
-	pw_log_error("link already exists");
+	pw_log_debug("link already exists");
 	goto error_exit;
 error_link_not_allowed:
 	res = -EPERM;
-	pw_log_error("link not allowed");
+	pw_log_debug("link not allowed");
 	goto error_exit;
 error_no_mem:
 	res = -errno;
-	pw_log_error("alloc failed: %m");
+	pw_log_debug("alloc failed: %m");
 	goto error_exit;
 error_no_io:
-	pw_log_error(NAME" %p: can't set io %d (%s)", this, res, spa_strerror(res));
+	pw_log_debug(NAME" %p: can't set io %d (%s)", this, res, spa_strerror(res));
 	goto error_free;
 error_free:
 	free(impl);

src/pipewire/impl-node.c

@@ -370,7 +370,6 @@ static int node_enum_params(void *object, int seq, uint32_t id,
 	struct resource_data *data = object;
 	struct pw_resource *resource = data->resource;
 	struct pw_impl_node *node = data->node;
-	struct pw_impl_client *client = resource->client;
 	int res;
 
 	pw_log_debug(NAME" %p: resource %p enum params seq:%d id:%d (%s) index:%u num:%u",
@@ -379,10 +378,7 @@ static int node_enum_params(void *object, int seq, uint32_t id,
 
 	if ((res = pw_impl_node_for_each_param(node, seq, id, index, num,
 				filter, reply_param, data)) < 0) {
-		pw_log_error(NAME" %p: resource %p %d error %d (%s)", node,
-				resource, resource->id, res, spa_strerror(res));
-		pw_core_resource_errorf(client->core_resource,
-				resource->id, seq, res,
+		pw_resource_errorf(resource, res,
 				"enum params id:%d (%s) failed", id,
 				spa_debug_type_find_name(spa_type_param, id));
 	}
@@ -439,9 +435,10 @@ static int node_set_param(void *object, uint32_t id, uint32_t flags,
 	res = spa_node_set_param(node->node, id, flags, param);
 
 	if (res < 0) {
-		pw_log_error(NAME" %p: resource %p %d error %d (%s)", node,
-				resource, resource->id, res, spa_strerror(res));
-		pw_resource_error(resource, res, spa_strerror(res));
+		pw_resource_errorf(resource, res,
+				"set param id:%d (%s) flags:%08x failed", id,
+				spa_debug_type_find_name(spa_type_param, id), flags);
+
 	} else if (SPA_RESULT_IS_ASYNC(res)) {
 		pw_impl_client_set_busy(client, true);
 		if (data->end == -1)

src/pipewire/impl-port.c

@@ -684,8 +684,9 @@ static int port_enum_params(void *object, int seq, uint32_t id, uint32_t index,
 
 	if ((res = pw_impl_port_for_each_param(port, seq, id, index, num, filter,
 			reply_param, data)) < 0)
-		pw_core_resource_error(resource->client->core_resource,
-				resource->id, seq, res, spa_strerror(res));
+		pw_resource_errorf(resource, res,
+				"enum params id:%d (%s) failed", id,
+				spa_debug_type_find_name(spa_type_param, id));
 	return res;
 }
 

src/pipewire/private.h

@@ -215,6 +215,8 @@ pw_core_resource_errorv(struct pw_resource *resource, uint32_t id, int seq,
 	char buffer[1024];
 	vsnprintf(buffer, sizeof(buffer), message, args);
 	buffer[1023] = '\0';
+	pw_log_error("resource %p: id:%d seq:%d res:%d (%s) msg:\"%s\"",
+			resource, id, seq, res, spa_strerror(res), buffer);
 	pw_core_resource_error(resource, id, seq, res, buffer);
 }
 

src/tools/pw-cat.c

@@ -630,7 +630,7 @@ static void on_core_error(void *userdata, uint32_t id, int seq, int res, const c
 {
 	struct data *data = userdata;
 
-	fprintf(stderr, "remote error: id=%"PRIu32" seq:%d res:%d (%s): %s",
+	fprintf(stderr, "remote error: id=%"PRIu32" seq:%d res:%d (%s): %s\n",
 			id, seq, res, spa_strerror(res), message);
 
 	pw_main_loop_quit(data->loop);