Re: [PATCH BlueZ] mesh: Log D-Bus method call errors

["Gix, Brian" <brian.gix@intel.com>]

Hi Michał,


On Tue, 2019-08-20 at 09:56 +0200, Michał Lowas-Rzechonek wrote:
> If a system is misconfigured, mesh daemon might not have permissions to
> call application methods.
> 
> This patch causes mesh daemon to log such errors, instead of failing
> silently.

Some of these Replies for error checking are waurented, I think...  Particularily when there is required
information that needs to be sent to the Application during Provisioning, for instance.

But sometimes we expect the application to be "away" for normal reasons (it is intended as a forground app, for
instance) where I am not sure we want to require the response... For instance the method calls in model.c that
occur when a remote node has sent a message.

The Non-Reply version of send (towards the apps) was actually a design decision, since we don't want the
*daemon* to exhast d-bus resources, depending on replies from Apps that are ignoring the messages we are
sending.  This could negatively impact the daemon's ability to interact with perhaps better behaved
applications.  I think every reply required message persists for up to 30 seconds.

I think our rule of thumb should be requiring a response when the daemon needs to know that the App has
successfully handled critical information so for instance YES for:

AddNodeComplete()   // Provisioner App *must* know when the remote node has accepted Prov 
			Data, and the remote Device Keys should perhaps be discarded if
			they are for nodes the Prov App doesn't know about.

JoinComplete()      // Token *must* be successfully delivered, and perhaps Node deleted if
			no App knows the accessing token

RequestProvData()   // Obviously here, the provisioning cannot procede without the data

But I don't think any of the others is it critical for the daemon to know the message has been processed. And a
prime assumption in mesh is "Any discrete OTA message might be lost".

> ---
>  mesh/dbus.c    | 19 +++++++++++++++++++
>  mesh/dbus.h    |  1 +
>  mesh/manager.c | 18 ++++++++++--------
>  mesh/mesh.c    |  4 ++--
>  mesh/model.c   |  8 ++++----
>  5 files changed, 36 insertions(+), 14 deletions(-)
> 
> diff --git a/mesh/dbus.c b/mesh/dbus.c
> index 6b9694ab7..453f11a68 100644
> --- a/mesh/dbus.c
> +++ b/mesh/dbus.c
> @@ -143,3 +143,22 @@ void dbus_append_dict_entry_basic(struct l_dbus_message_builder *builder,
>  	l_dbus_message_builder_leave_variant(builder);
>  	l_dbus_message_builder_leave_dict(builder);
>  }
> +
> +void dbus_call_reply(struct l_dbus_message *reply, void *user_data)
> +{
> +	struct l_dbus_message *msg = user_data;
> +
> +	if (l_dbus_message_is_error(reply)) {
> +		const char *name = NULL;
> +		const char *desc = NULL;
> +
> +		l_dbus_message_get_error(reply, &name, &desc);
> +
> +		l_error("Failed to call %s.%s on (%s)%s: %s %s",
> +					l_dbus_message_get_interface(msg),
> +					l_dbus_message_get_member(msg),
> +					l_dbus_message_get_destination(msg),
> +					l_dbus_message_get_path(msg),
> +					name, desc);
> +	}
> +}
> diff --git a/mesh/dbus.h b/mesh/dbus.h
> index e7643a59d..fecc800a9 100644
> --- a/mesh/dbus.h
> +++ b/mesh/dbus.h
> @@ -31,3 +31,4 @@ bool dbus_match_interface(struct l_dbus_message_iter *interfaces,
>  							const char *match);
>  struct l_dbus_message *dbus_error(struct l_dbus_message *msg, int err,
>  						const char *description);
> +void dbus_call_reply(struct l_dbus_message *reply, void *user_data);
> diff --git a/mesh/manager.c b/mesh/manager.c
> index cf4782c45..2a2e06780 100644
> --- a/mesh/manager.c
> +++ b/mesh/manager.c
> @@ -114,7 +114,7 @@ static void send_add_failed(const char *owner, const char *path,
>  						mesh_prov_status_str(status));
>  	l_dbus_message_builder_finalize(builder);
>  	l_dbus_message_builder_destroy(builder);
> -	l_dbus_send(dbus, msg);
> +	l_dbus_send_with_reply(dbus, msg, dbus_call_reply, msg, NULL);
>  
>  	free_pending_add_call();
>  }
> @@ -159,7 +159,7 @@ static bool add_cmplt(void *user_data, uint8_t status,
>  	l_dbus_message_builder_finalize(builder);
>  	l_dbus_message_builder_destroy(builder);
>  
> -	l_dbus_send(dbus, msg);
> +	l_dbus_send_with_reply(dbus, msg, dbus_call_reply, msg, NULL);
>  
>  	free_pending_add_call();
>  
> @@ -175,8 +175,10 @@ static void mgr_prov_data (struct l_dbus_message *reply, void *user_data)
>  	if (pending != add_pending)
>  		return;
>  
> -	if (l_dbus_message_is_error(reply))
> +	if (l_dbus_message_is_error(reply)) {
> +		dbus_call_reply(reply, pending->msg);
>  		return;
> +	}
>  
>  	if (!l_dbus_message_get_arguments(reply, "qq", &net_idx, &primary))
>  		return;
> @@ -189,7 +191,6 @@ static void mgr_prov_data (struct l_dbus_message *reply, void *user_data)
>  static bool add_data_get(void *user_data, uint8_t num_ele)
>  {
>  	struct add_data *pending = user_data;
> -	struct l_dbus_message *msg;
>  	struct l_dbus *dbus;
>  	const char *app_path;
>  	const char *sender;
> @@ -201,12 +202,13 @@ static bool add_data_get(void *user_data, uint8_t num_ele)
>  	app_path = node_get_app_path(add_pending->node);
>  	sender = node_get_owner(add_pending->node);
>  
> -	msg = l_dbus_message_new_method_call(dbus, sender, app_path,
> +	pending->msg = l_dbus_message_new_method_call(dbus, sender, app_path,
>  						MESH_PROVISIONER_INTERFACE,
>  						"RequestProvData");
>  
> -	l_dbus_message_set_arguments(msg, "y", num_ele);
> -	l_dbus_send_with_reply(dbus, msg, mgr_prov_data, add_pending, NULL);
> +	l_dbus_message_set_arguments(pending->msg, "y", num_ele);
> +	l_dbus_send_with_reply(dbus, pending->msg, mgr_prov_data, add_pending,
> +									NULL);
>  
>  	add_pending->num_ele = num_ele;
>  
> @@ -362,7 +364,7 @@ static void prov_beacon_recv(void *user_data, struct mesh_io_recv_info *info,
>  	l_dbus_message_builder_finalize(builder);
>  	l_dbus_message_builder_destroy(builder);
>  
> -	l_dbus_send(dbus, msg);
> +	l_dbus_send_with_reply(dbus, msg, dbus_call_reply, msg, NULL);
>  }
>  
>  static struct l_dbus_message *start_scan_call(struct l_dbus *dbus,
> diff --git a/mesh/mesh.c b/mesh/mesh.c
> index b660a7ef2..9bd644cab 100644
> --- a/mesh/mesh.c
> +++ b/mesh/mesh.c
> @@ -303,7 +303,7 @@ static void send_join_failed(const char *owner, const char *path,
>  						"JoinFailed");
>  
>  	l_dbus_message_set_arguments(msg, "s", mesh_prov_status_str(status));
> -	l_dbus_send(dbus_get_bus(), msg);
> +	l_dbus_send_with_reply(dbus_get_bus(), msg, dbus_call_reply, msg, NULL);
>  
>  	free_pending_join_call(true);
>  }
> @@ -343,7 +343,7 @@ static bool prov_complete_cb(void *user_data, uint8_t status,
>  
>  	l_dbus_message_set_arguments(msg, "t", l_get_be64(token));
>  
> -	l_dbus_send(dbus, msg);
> +	l_dbus_send_with_reply(dbus, msg, dbus_call_reply, msg, NULL);
>  
>  	free_pending_join_call(false);
>  
> diff --git a/mesh/model.c b/mesh/model.c
> index 8f3d67ecf..328a0756d 100644
> --- a/mesh/model.c
> +++ b/mesh/model.c
> @@ -251,7 +251,7 @@ static void config_update_model_pub_period(struct mesh_node *node,
>  	l_dbus_message_builder_leave_array(builder);
>  	l_dbus_message_builder_finalize(builder);
>  	l_dbus_message_builder_destroy(builder);
> -	l_dbus_send(dbus, msg);
> +	l_dbus_send_with_reply(dbus, msg, dbus_call_reply, msg, NULL);
>  }
>  
>  static void append_dict_uint16_array(struct l_dbus_message_builder *builder,
> @@ -292,7 +292,7 @@ static void config_update_model_bindings(struct mesh_node *node,
>  	l_dbus_message_builder_leave_array(builder);
>  	l_dbus_message_builder_finalize(builder);
>  	l_dbus_message_builder_destroy(builder);
> -	l_dbus_send(dbus, msg);
> +	l_dbus_send_with_reply(dbus, msg, dbus_call_reply, msg, NULL);
>  }
>  
>  static void forward_model(void *a, void *b)
> @@ -764,7 +764,7 @@ static void send_dev_key_msg_rcvd(struct mesh_node *node, uint8_t ele_idx,
>  	l_dbus_message_builder_finalize(builder);
>  	l_dbus_message_builder_destroy(builder);
>  
> -	l_dbus_send(dbus, msg);
> +	l_dbus_send_with_reply(dbus, msg, dbus_call_reply, msg, NULL);
>  }
>  
>  static void send_msg_rcvd(struct mesh_node *node, uint8_t ele_idx, bool is_sub,
> @@ -797,7 +797,7 @@ static void send_msg_rcvd(struct mesh_node *node, uint8_t ele_idx, bool is_sub,
>  
>  	l_dbus_message_builder_finalize(builder);
>  	l_dbus_message_builder_destroy(builder);
> -	l_dbus_send(dbus, msg);
> +	l_dbus_send_with_reply(dbus, msg, dbus_call_reply, msg, NULL);
>  }
>  
>  bool mesh_model_rx(struct mesh_node *node, bool szmict, uint32_t seq0,