[PATCH] Add winbind request profiling

Jeremy Allison jra at samba.org
Wed Jun 20 17:18:13 UTC 2018


On Wed, Jun 20, 2018 at 04:01:49PM +0200, Volker Lendecke via samba-technical wrote:
> Hi!
> 
> Attached find a patchset that allows profiling of tevent_req. The
> first application of this is in the winbind parent, see the last
> commit for a sample output.
> 
> Review appreciated!

Wow ! This looks great ! Will try and get to do a proper review
over the next few days.

> -- 
> SerNet GmbH, Bahnhofsallee 1b, 37081 Göttingen
> phone: +49-551-370000-0, fax: +49-551-370000-9
> AG Göttingen, HRB 2816, GF: Dr. Johannes Loxen
> http://www.sernet.de, mailto:kontakt at sernet.de

> From e0b74f6fd46668d6f0644b99e92d94775c1317ad Mon Sep 17 00:00:00 2001
> From: Volker Lendecke <vl at samba.org>
> Date: Wed, 2 May 2018 13:54:42 +0200
> Subject: [PATCH 1/7] lib: Multi-line a long line in wscript_build
> 
> Why? I'll add another file in a later commit
> 
> Signed-off-by: Volker Lendecke <vl at samba.org>
> ---
>  lib/util/wscript_build | 6 +++++-
>  1 file changed, 5 insertions(+), 1 deletion(-)
> 
> diff --git a/lib/util/wscript_build b/lib/util/wscript_build
> index ded91f67d9f..793e24669c9 100644
> --- a/lib/util/wscript_build
> +++ b/lib/util/wscript_build
> @@ -162,7 +162,11 @@ else:
>                        )
>  
>      bld.SAMBA_LIBRARY('tevent-util',
> -                      source='tevent_unix.c tevent_ntstatus.c tevent_werror.c',
> +                      source='''
> +                          tevent_unix.c
> +                          tevent_ntstatus.c
> +                          tevent_werror.c
> +                      ''',
>                        local_include=False,
>                        public_deps='tevent samba-errors',
>                        public_headers='tevent_ntstatus.h tevent_unix.h tevent_werror.h',
> -- 
> 2.11.0
> 
> 
> From 792399f15a8a430baa06dc2023c43cac150f282c Mon Sep 17 00:00:00 2001
> From: Volker Lendecke <vl at samba.org>
> Date: Wed, 2 May 2018 14:01:56 +0200
> Subject: [PATCH 2/7] tevent: Add tevent_req_profile
> 
> This allows detailed reporting where a tevent_req spends its time
> 
> Signed-off-by: Volker Lendecke <vl at samba.org>
> ---
>  lib/tevent/tevent.h          | 185 +++++++++++++++++++++++++++++++++++++++
>  lib/tevent/tevent_internal.h |  19 ++++
>  lib/tevent/tevent_req.c      | 202 +++++++++++++++++++++++++++++++++++++++++++
>  3 files changed, 406 insertions(+)
> 
> diff --git a/lib/tevent/tevent.h b/lib/tevent/tevent.h
> index 3ccac6a3600..b5b41919397 100644
> --- a/lib/tevent/tevent.h
> +++ b/lib/tevent/tevent.h
> @@ -1327,6 +1327,191 @@ bool tevent_req_is_error(struct tevent_req *req,
>  void tevent_req_received(struct tevent_req *req);
>  
>  /**
> + * @brief Mark a tevent_req for profiling
> + *
> + * This will turn on profiling for this tevent_req an all subreqs that
> + * are directly started as helper requests off this
> + * tevent_req. subreqs are chained by walking up the talloc_parent
> + * hierarchy at a subreq's tevent_req_create. This means to get the
> + * profiling chain right the subreq that needs to be profiled as part
> + * of this tevent_req's profile must be a talloc child of the requests
> + * state variable.
> + *
> + * @param[in] req The request to do tracing for
> + *
> + * @return        False if the profile could not be activated
> + */
> +bool tevent_req_set_profile(struct tevent_req *req);
> +
> +struct tevent_req_profile;
> +
> +/**
> + * @brief Get the a request's profile for inspection
> + *
> + * @param[in] req The request to get the profile from
> + *
> + * @return        The request's profile
> + */
> +const struct tevent_req_profile *tevent_req_get_profile(
> +	struct tevent_req *req);
> +
> +/**
> + * @brief Move the profile out of a request
> + *
> + * This function detaches the request's profile from the request, so
> + * that the profile can outlive the request in a _recv function.
> + *
> + * @param[in] req     The request to move the profile out of
> + * @param[in] mem_ctx The new talloc context for the profile
> + *
> + * @return            The moved profile
> + */
> +
> +struct tevent_req_profile *tevent_req_move_profile(struct tevent_req *req,
> +						   TALLOC_CTX *mem_ctx);
> +
> +/**
> + * @brief Get a profile description
> + *
> + * @param[in] profile  The profile to be queried
> + * @param[in] req_name The name of the request (state's name)
> + *
> + * "req_name" after this call is still in talloc-posession of "profile"
> + */
> +void tevent_req_profile_get_name(const struct tevent_req_profile *profile,
> +				 const char **req_name);
> +
> +/**
> + * @brief Get a profile's start event data
> + *
> + * @param[in] profile        The profile to be queried
> + * @param[in] start_location The location where this event started
> + * @param[in] start_time     The time this event started
> + *
> + * "start_location" after this call is still in talloc-posession of "profile"
> + */
> +void tevent_req_profile_get_start(const struct tevent_req_profile *profile,
> +				  const char **start_location,
> +				  struct timeval *start_time);
> +
> +/**
> + * @brief Get a profile's stop event data
> + *
> + * @param[in] profile        The profile to be queried
> + * @param[in] stop_location  The location where this event stopped
> + * @param[in] stop_time      The time this event stopped
> + *
> + * "stop_location" after this call is still in talloc-posession of "profile"
> + */
> +void tevent_req_profile_get_stop(const struct tevent_req_profile *profile,
> +				 const char **stop_location,
> +				 struct timeval *stop_time);
> +
> +/**
> + * @brief Get a profile's result data
> + *
> + * @param[in] pid        The process where this profile was taken
> + * @param[in] state      The status the profile's tevent_req finished with
> + * @param[in] user_error The user error of the profile's tevent_req
> + */
> +void tevent_req_profile_get_status(const struct tevent_req_profile *profile,
> +				   pid_t *pid,
> +				   enum tevent_req_state *state,
> +				   uint64_t *user_error);
> +
> +/**
> + * @brief Retrieve the first subreq's profile from a profile
> + *
> + * @param[in] profile The profile to query
> + *
> + * @return The first tevent subreq's profile
> + */
> +const struct tevent_req_profile *tevent_req_profile_get_subprofiles(
> +	const struct tevent_req_profile *profile);
> +
> +/**
> + * @brief Walk the chain of subreqs
> + *
> + * @param[in] profile The subreq's profile to walk
> + *
> + * @return The next subprofile in the list
> + */
> +const struct tevent_req_profile *tevent_req_profile_next(
> +	const struct tevent_req_profile *profile);
> +
> +/**
> + * @brief Create a fresh tevent_req_profile
> + *
> + * @param[in] mem_ctx The talloc context to hang the fresh struct off
> + *
> + * @return The fresh struct
> + */
> +struct tevent_req_profile *tevent_req_profile_create(TALLOC_CTX *mem_ctx);
> +
> +/**
> + * @brief Set a profile's name
> + *
> + * @param[in] profile The profile to set the name for
> + * @param[in] name    The new name for the profile
> + *
> + * @return True if the internal talloc_strdup succeeded
> + */
> +bool tevent_req_profile_set_name(struct tevent_req_profile *profile,
> +				 const char *name);
> +
> +/**
> + * @brief Set a profile's start event
> + *
> + * @param[in] profile        The profile to set the start data for
> + * @param[in] start_location The new start location
> + * @param[in] start_time     The new start time
> + *
> + * @return True if the internal talloc_strdup succeeded
> + */
> +bool tevent_req_profile_set_start(struct tevent_req_profile *profile,
> +				  const char *start_location,
> +				  struct timeval start_time);
> +
> +/**
> + * @brief Set a profile's stop event
> + *
> + * @param[in] profile        The profile to set the stop data for
> + * @param[in] stop_location  The new stop location
> + * @param[in] stop_time      The new stop time
> + *
> + * @return True if the internal talloc_strdup succeeded
> + */
> +bool tevent_req_profile_set_stop(struct tevent_req_profile *profile,
> +				 const char *stop_location,
> +				 struct timeval stop_time);
> +
> +/**
> + * @brief Set a profile's exit status
> + *
> + * @param[in] profile    The profile to set the exit status for
> + * @param[in] pid        The process where this profile was taken
> + * @param[in] state      The status the profile's tevent_req finished with
> + * @param[in] user_error The user error of the profile's tevent_req
> + */
> +void tevent_req_profile_set_status(struct tevent_req_profile *profile,
> +				   pid_t pid,
> +				   enum tevent_req_state state,
> +				   uint64_t user_error);
> +
> +/**
> + * @brief Add a subprofile to a profile
> + *
> + * @param[in] parent_profile The profile to be modified
> + * @param[in] sub_profile The subreqs profile profile to be added
> + *
> + * "subreq" is talloc_move'ed into "parent_profile", so the talloc
> + * ownership of "sub_profile" changes
> + */
> +
> +void tevent_req_profile_append_sub(struct tevent_req_profile *parent_profile,
> +				   struct tevent_req_profile **sub_profile);
> +
> +/**
>   * @brief Create a tevent subrequest at a given time.
>   *
>   * The idea is that always the same syntax for tevent requests.
> diff --git a/lib/tevent/tevent_internal.h b/lib/tevent/tevent_internal.h
> index ec3955e70a4..bb816a2518c 100644
> --- a/lib/tevent/tevent_internal.h
> +++ b/lib/tevent/tevent_internal.h
> @@ -164,9 +164,28 @@ struct tevent_req {
>  		 *
>  		 */
>  		struct tevent_timer *timer;
> +
> +		/**
> +		 * @brief The place where profiling data is kept
> +		 */
> +		struct tevent_req_profile *profile;
>  	} internal;
>  };
>  
> +struct tevent_req_profile {
> +	struct tevent_req_profile *prev, *next;
> +	struct tevent_req_profile *parent;
> +	const char *req_name;
> +	pid_t pid;
> +	const char *start_location;
> +	struct timeval start_time;
> +	const char *stop_location;
> +	struct timeval stop_time;
> +	enum tevent_req_state state;
> +	uint64_t user_error;
> +	struct tevent_req_profile *subprofiles;
> +};
> +
>  struct tevent_fd {
>  	struct tevent_fd *prev, *next;
>  	struct tevent_context *event_ctx;
> diff --git a/lib/tevent/tevent_req.c b/lib/tevent/tevent_req.c
> index 15754d361ae..5b57fea814e 100644
> --- a/lib/tevent/tevent_req.c
> +++ b/lib/tevent/tevent_req.c
> @@ -65,6 +65,7 @@ struct tevent_req *_tevent_req_create(TALLOC_CTX *mem_ctx,
>  				    const char *location)
>  {
>  	struct tevent_req *req;
> +	struct tevent_req *parent;
>  	void **ppdata = (void **)pdata;
>  	void *data;
>  	size_t payload;
> @@ -103,6 +104,19 @@ struct tevent_req *_tevent_req_create(TALLOC_CTX *mem_ctx,
>  
>  	talloc_set_destructor(req, tevent_req_destructor);
>  
> +	parent = talloc_get_type(talloc_parent(mem_ctx), struct tevent_req);
> +	if ((parent != NULL) && (parent->internal.profile != NULL)) {
> +		bool ok = tevent_req_set_profile(req);
> +
> +		if (!ok) {
> +			TALLOC_FREE(req);
> +			return NULL;
> +		}
> +		req->internal.profile->parent = parent->internal.profile;
> +		DLIST_ADD_END(parent->internal.profile->subprofiles,
> +			      req->internal.profile);
> +	}
> +
>  	*ppdata = data;
>  	return req;
>  }
> @@ -148,6 +162,7 @@ static void tevent_req_finish(struct tevent_req *req,
>  			      enum tevent_req_state state,
>  			      const char *location)
>  {
> +	struct tevent_req_profile *p;
>  	/*
>  	 * make sure we do not timeout after
>  	 * the request was already finished
> @@ -159,6 +174,20 @@ static void tevent_req_finish(struct tevent_req *req,
>  
>  	tevent_req_cleanup(req);
>  
> +	p = req->internal.profile;
> +
> +	if (p != NULL) {
> +		p->stop_location = location;
> +		p->stop_time = tevent_timeval_current();
> +		p->state = state;
> +		p->user_error = req->internal.error;
> +
> +		if (p->parent != NULL) {
> +			talloc_steal(p->parent, p);
> +			req->internal.profile = NULL;
> +		}
> +	}
> +
>  	_tevent_req_notify_callback(req, location);
>  }
>  
> @@ -363,3 +392,176 @@ void tevent_req_set_cleanup_fn(struct tevent_req *req, tevent_req_cleanup_fn fn)
>  	req->private_cleanup.state = req->internal.state;
>  	req->private_cleanup.fn = fn;
>  }
> +
> +static int tevent_req_profile_destructor(struct tevent_req_profile *p);
> +
> +bool tevent_req_set_profile(struct tevent_req *req)
> +{
> +	struct tevent_req_profile *p;
> +
> +	if (req->internal.profile != NULL) {
> +		return false;
> +	}
> +
> +	p = tevent_req_profile_create(req);
> +
> +	if (tevent_req_nomem(p, req)) {
> +		return false;
> +	}
> +
> +	p->req_name = talloc_get_name(req->data);
> +	p->start_location = req->internal.create_location;
> +	p->start_time = tevent_timeval_current();
> +
> +	req->internal.profile = p;
> +
> +	return true;
> +}
> +
> +static int tevent_req_profile_destructor(struct tevent_req_profile *p)
> +{
> +	if (p->parent != NULL) {
> +		DLIST_REMOVE(p->parent->subprofiles, p);
> +		p->parent = NULL;
> +	}
> +
> +	while (p->subprofiles != NULL) {
> +		p->subprofiles->parent = NULL;
> +		DLIST_REMOVE(p->subprofiles, p->subprofiles);
> +	}
> +
> +	return 0;
> +}
> +
> +struct tevent_req_profile *tevent_req_move_profile(struct tevent_req *req,
> +						   TALLOC_CTX *mem_ctx)
> +{
> +	return talloc_move(mem_ctx, &req->internal.profile);
> +}
> +
> +const struct tevent_req_profile *tevent_req_get_profile(
> +	struct tevent_req *req)
> +{
> +	return req->internal.profile;
> +}
> +
> +void tevent_req_profile_get_name(const struct tevent_req_profile *profile,
> +				 const char **req_name)
> +{
> +	if (req_name != NULL) {
> +		*req_name = profile->req_name;
> +	}
> +}
> +
> +void tevent_req_profile_get_start(const struct tevent_req_profile *profile,
> +				  const char **start_location,
> +				  struct timeval *start_time)
> +{
> +	if (start_location != NULL) {
> +		*start_location = profile->start_location;
> +	}
> +	if (start_time != NULL) {
> +		*start_time = profile->start_time;
> +	}
> +}
> +
> +void tevent_req_profile_get_stop(const struct tevent_req_profile *profile,
> +				 const char **stop_location,
> +				 struct timeval *stop_time)
> +{
> +	if (stop_location != NULL) {
> +		*stop_location = profile->stop_location;
> +	}
> +	if (stop_time != NULL) {
> +		*stop_time = profile->stop_time;
> +	}
> +}
> +
> +void tevent_req_profile_get_status(const struct tevent_req_profile *profile,
> +				   pid_t *pid,
> +				   enum tevent_req_state *state,
> +				   uint64_t *user_error)
> +{
> +	if (pid != NULL) {
> +		*pid = profile->pid;
> +	}
> +	if (state != NULL) {
> +		*state = profile->state;
> +	}
> +	if (user_error != NULL) {
> +		*user_error = profile->user_error;
> +	}
> +}
> +
> +const struct tevent_req_profile *tevent_req_profile_get_subprofiles(
> +	const struct tevent_req_profile *profile)
> +{
> +	return profile->subprofiles;
> +}
> +
> +const struct tevent_req_profile *tevent_req_profile_next(
> +	const struct tevent_req_profile *profile)
> +{
> +	return profile->next;
> +}
> +
> +struct tevent_req_profile *tevent_req_profile_create(TALLOC_CTX *mem_ctx)
> +{
> +	struct tevent_req_profile *result;
> +
> +	result = talloc_zero(mem_ctx, struct tevent_req_profile);
> +	if (result == NULL) {
> +		return NULL;
> +	}
> +	talloc_set_destructor(result, tevent_req_profile_destructor);
> +
> +	return result;
> +}
> +
> +bool tevent_req_profile_set_name(struct tevent_req_profile *profile,
> +				 const char *req_name)
> +{
> +	profile->req_name = talloc_strdup(profile, req_name);
> +	return (profile->req_name != NULL);
> +}
> +
> +bool tevent_req_profile_set_start(struct tevent_req_profile *profile,
> +				  const char *start_location,
> +				  struct timeval start_time)
> +{
> +	profile->start_time = start_time;
> +
> +	profile->start_location = talloc_strdup(profile, start_location);
> +	return (profile->start_location != NULL);
> +}
> +
> +bool tevent_req_profile_set_stop(struct tevent_req_profile *profile,
> +				 const char *stop_location,
> +				 struct timeval stop_time)
> +{
> +	profile->stop_time = stop_time;
> +
> +	profile->stop_location = talloc_strdup(profile, stop_location);
> +	return (profile->stop_location != NULL);
> +}
> +
> +void tevent_req_profile_set_status(struct tevent_req_profile *profile,
> +				   pid_t pid,
> +				   enum tevent_req_state state,
> +				   uint64_t user_error)
> +{
> +	profile->pid = pid;
> +	profile->state = state;
> +	profile->user_error = user_error;
> +}
> +
> +void tevent_req_profile_append_sub(struct tevent_req_profile *parent_profile,
> +				   struct tevent_req_profile **sub_profile)
> +{
> +	struct tevent_req_profile *sub;
> +
> +	sub = talloc_move(parent_profile, sub_profile);
> +
> +	sub->parent = parent_profile;
> +	DLIST_ADD_END(parent_profile->subprofiles, sub);
> +}
> -- 
> 2.11.0
> 
> 
> From aefb0b1d5ae5eaa4140d183cef3409caba48ce5d Mon Sep 17 00:00:00 2001
> From: Volker Lendecke <vl at samba.org>
> Date: Mon, 7 May 2018 13:42:24 +0200
> Subject: [PATCH 3/7] tevent 0.9.37
> 
> Added profiling
> 
> Signed-off-by: Volker Lendecke <vl at samba.org>
> ---
>  lib/tevent/ABI/tevent-0.9.37.sigs | 115 ++++++++++++++++++++++++++++++++++++++
>  lib/tevent/wscript                |   2 +-
>  2 files changed, 116 insertions(+), 1 deletion(-)
>  create mode 100644 lib/tevent/ABI/tevent-0.9.37.sigs
> 
> diff --git a/lib/tevent/ABI/tevent-0.9.37.sigs b/lib/tevent/ABI/tevent-0.9.37.sigs
> new file mode 100644
> index 00000000000..295668f60b6
> --- /dev/null
> +++ b/lib/tevent/ABI/tevent-0.9.37.sigs
> @@ -0,0 +1,115 @@
> +_tevent_add_fd: struct tevent_fd *(struct tevent_context *, TALLOC_CTX *, int, uint16_t, tevent_fd_handler_t, void *, const char *, const char *)
> +_tevent_add_signal: struct tevent_signal *(struct tevent_context *, TALLOC_CTX *, int, int, tevent_signal_handler_t, void *, const char *, const char *)
> +_tevent_add_timer: struct tevent_timer *(struct tevent_context *, TALLOC_CTX *, struct timeval, tevent_timer_handler_t, void *, const char *, const char *)
> +_tevent_create_immediate: struct tevent_immediate *(TALLOC_CTX *, const char *)
> +_tevent_loop_once: int (struct tevent_context *, const char *)
> +_tevent_loop_until: int (struct tevent_context *, bool (*)(void *), void *, const char *)
> +_tevent_loop_wait: int (struct tevent_context *, const char *)
> +_tevent_queue_create: struct tevent_queue *(TALLOC_CTX *, const char *, const char *)
> +_tevent_req_callback_data: void *(struct tevent_req *)
> +_tevent_req_cancel: bool (struct tevent_req *, const char *)
> +_tevent_req_create: struct tevent_req *(TALLOC_CTX *, void *, size_t, const char *, const char *)
> +_tevent_req_data: void *(struct tevent_req *)
> +_tevent_req_done: void (struct tevent_req *, const char *)
> +_tevent_req_error: bool (struct tevent_req *, uint64_t, const char *)
> +_tevent_req_nomem: bool (const void *, struct tevent_req *, const char *)
> +_tevent_req_notify_callback: void (struct tevent_req *, const char *)
> +_tevent_req_oom: void (struct tevent_req *, const char *)
> +_tevent_schedule_immediate: void (struct tevent_immediate *, struct tevent_context *, tevent_immediate_handler_t, void *, const char *, const char *)
> +_tevent_threaded_schedule_immediate: void (struct tevent_threaded_context *, struct tevent_immediate *, tevent_immediate_handler_t, void *, const char *, const char *)
> +tevent_backend_list: const char **(TALLOC_CTX *)
> +tevent_cleanup_pending_signal_handlers: void (struct tevent_signal *)
> +tevent_common_add_fd: struct tevent_fd *(struct tevent_context *, TALLOC_CTX *, int, uint16_t, tevent_fd_handler_t, void *, const char *, const char *)
> +tevent_common_add_signal: struct tevent_signal *(struct tevent_context *, TALLOC_CTX *, int, int, tevent_signal_handler_t, void *, const char *, const char *)
> +tevent_common_add_timer: struct tevent_timer *(struct tevent_context *, TALLOC_CTX *, struct timeval, tevent_timer_handler_t, void *, const char *, const char *)
> +tevent_common_add_timer_v2: struct tevent_timer *(struct tevent_context *, TALLOC_CTX *, struct timeval, tevent_timer_handler_t, void *, const char *, const char *)
> +tevent_common_check_signal: int (struct tevent_context *)
> +tevent_common_context_destructor: int (struct tevent_context *)
> +tevent_common_fd_destructor: int (struct tevent_fd *)
> +tevent_common_fd_get_flags: uint16_t (struct tevent_fd *)
> +tevent_common_fd_set_close_fn: void (struct tevent_fd *, tevent_fd_close_fn_t)
> +tevent_common_fd_set_flags: void (struct tevent_fd *, uint16_t)
> +tevent_common_have_events: bool (struct tevent_context *)
> +tevent_common_loop_immediate: bool (struct tevent_context *)
> +tevent_common_loop_timer_delay: struct timeval (struct tevent_context *)
> +tevent_common_loop_wait: int (struct tevent_context *, const char *)
> +tevent_common_schedule_immediate: void (struct tevent_immediate *, struct tevent_context *, tevent_immediate_handler_t, void *, const char *, const char *)
> +tevent_common_threaded_activate_immediate: void (struct tevent_context *)
> +tevent_common_wakeup: int (struct tevent_context *)
> +tevent_common_wakeup_fd: int (int)
> +tevent_common_wakeup_init: int (struct tevent_context *)
> +tevent_context_init: struct tevent_context *(TALLOC_CTX *)
> +tevent_context_init_byname: struct tevent_context *(TALLOC_CTX *, const char *)
> +tevent_context_init_ops: struct tevent_context *(TALLOC_CTX *, const struct tevent_ops *, void *)
> +tevent_debug: void (struct tevent_context *, enum tevent_debug_level, const char *, ...)
> +tevent_fd_get_flags: uint16_t (struct tevent_fd *)
> +tevent_fd_set_auto_close: void (struct tevent_fd *)
> +tevent_fd_set_close_fn: void (struct tevent_fd *, tevent_fd_close_fn_t)
> +tevent_fd_set_flags: void (struct tevent_fd *, uint16_t)
> +tevent_get_trace_callback: void (struct tevent_context *, tevent_trace_callback_t *, void *)
> +tevent_loop_allow_nesting: void (struct tevent_context *)
> +tevent_loop_set_nesting_hook: void (struct tevent_context *, tevent_nesting_hook, void *)
> +tevent_num_signals: size_t (void)
> +tevent_queue_add: bool (struct tevent_queue *, struct tevent_context *, struct tevent_req *, tevent_queue_trigger_fn_t, void *)
> +tevent_queue_add_entry: struct tevent_queue_entry *(struct tevent_queue *, struct tevent_context *, struct tevent_req *, tevent_queue_trigger_fn_t, void *)
> +tevent_queue_add_optimize_empty: struct tevent_queue_entry *(struct tevent_queue *, struct tevent_context *, struct tevent_req *, tevent_queue_trigger_fn_t, void *)
> +tevent_queue_entry_untrigger: void (struct tevent_queue_entry *)
> +tevent_queue_length: size_t (struct tevent_queue *)
> +tevent_queue_running: bool (struct tevent_queue *)
> +tevent_queue_start: void (struct tevent_queue *)
> +tevent_queue_stop: void (struct tevent_queue *)
> +tevent_queue_wait_recv: bool (struct tevent_req *)
> +tevent_queue_wait_send: struct tevent_req *(TALLOC_CTX *, struct tevent_context *, struct tevent_queue *)
> +tevent_re_initialise: int (struct tevent_context *)
> +tevent_register_backend: bool (const char *, const struct tevent_ops *)
> +tevent_req_default_print: char *(struct tevent_req *, TALLOC_CTX *)
> +tevent_req_defer_callback: void (struct tevent_req *, struct tevent_context *)
> +tevent_req_get_profile: const struct tevent_req_profile *(struct tevent_req *)
> +tevent_req_is_error: bool (struct tevent_req *, enum tevent_req_state *, uint64_t *)
> +tevent_req_is_in_progress: bool (struct tevent_req *)
> +tevent_req_move_profile: struct tevent_req_profile *(struct tevent_req *, TALLOC_CTX *)
> +tevent_req_poll: bool (struct tevent_req *, struct tevent_context *)
> +tevent_req_post: struct tevent_req *(struct tevent_req *, struct tevent_context *)
> +tevent_req_print: char *(TALLOC_CTX *, struct tevent_req *)
> +tevent_req_profile_append_sub: void (struct tevent_req_profile *, struct tevent_req_profile **)
> +tevent_req_profile_create: struct tevent_req_profile *(TALLOC_CTX *)
> +tevent_req_profile_get_name: void (const struct tevent_req_profile *, const char **)
> +tevent_req_profile_get_start: void (const struct tevent_req_profile *, const char **, struct timeval *)
> +tevent_req_profile_get_status: void (const struct tevent_req_profile *, pid_t *, enum tevent_req_state *, uint64_t *)
> +tevent_req_profile_get_stop: void (const struct tevent_req_profile *, const char **, struct timeval *)
> +tevent_req_profile_get_subprofiles: const struct tevent_req_profile *(const struct tevent_req_profile *)
> +tevent_req_profile_next: const struct tevent_req_profile *(const struct tevent_req_profile *)
> +tevent_req_profile_set_name: bool (struct tevent_req_profile *, const char *)
> +tevent_req_profile_set_start: bool (struct tevent_req_profile *, const char *, struct timeval)
> +tevent_req_profile_set_status: void (struct tevent_req_profile *, pid_t, enum tevent_req_state, uint64_t)
> +tevent_req_profile_set_stop: bool (struct tevent_req_profile *, const char *, struct timeval)
> +tevent_req_received: void (struct tevent_req *)
> +tevent_req_reset_endtime: void (struct tevent_req *)
> +tevent_req_set_callback: void (struct tevent_req *, tevent_req_fn, void *)
> +tevent_req_set_cancel_fn: void (struct tevent_req *, tevent_req_cancel_fn)
> +tevent_req_set_cleanup_fn: void (struct tevent_req *, tevent_req_cleanup_fn)
> +tevent_req_set_endtime: bool (struct tevent_req *, struct tevent_context *, struct timeval)
> +tevent_req_set_print_fn: void (struct tevent_req *, tevent_req_print_fn)
> +tevent_req_set_profile: bool (struct tevent_req *)
> +tevent_sa_info_queue_count: size_t (void)
> +tevent_set_abort_fn: void (void (*)(const char *))
> +tevent_set_debug: int (struct tevent_context *, void (*)(void *, enum tevent_debug_level, const char *, va_list), void *)
> +tevent_set_debug_stderr: int (struct tevent_context *)
> +tevent_set_default_backend: void (const char *)
> +tevent_set_trace_callback: void (struct tevent_context *, tevent_trace_callback_t, void *)
> +tevent_signal_support: bool (struct tevent_context *)
> +tevent_thread_proxy_create: struct tevent_thread_proxy *(struct tevent_context *)
> +tevent_thread_proxy_schedule: void (struct tevent_thread_proxy *, struct tevent_immediate **, tevent_immediate_handler_t, void *)
> +tevent_threaded_context_create: struct tevent_threaded_context *(TALLOC_CTX *, struct tevent_context *)
> +tevent_timeval_add: struct timeval (const struct timeval *, uint32_t, uint32_t)
> +tevent_timeval_compare: int (const struct timeval *, const struct timeval *)
> +tevent_timeval_current: struct timeval (void)
> +tevent_timeval_current_ofs: struct timeval (uint32_t, uint32_t)
> +tevent_timeval_is_zero: bool (const struct timeval *)
> +tevent_timeval_set: struct timeval (uint32_t, uint32_t)
> +tevent_timeval_until: struct timeval (const struct timeval *, const struct timeval *)
> +tevent_timeval_zero: struct timeval (void)
> +tevent_trace_point_callback: void (struct tevent_context *, enum tevent_trace_point)
> +tevent_update_timer: void (struct tevent_timer *, struct timeval)
> +tevent_wakeup_recv: bool (struct tevent_req *)
> +tevent_wakeup_send: struct tevent_req *(TALLOC_CTX *, struct tevent_context *, struct timeval)
> diff --git a/lib/tevent/wscript b/lib/tevent/wscript
> index 94d190f3b60..ce72557d90a 100644
> --- a/lib/tevent/wscript
> +++ b/lib/tevent/wscript
> @@ -1,7 +1,7 @@
>  #!/usr/bin/env python
>  
>  APPNAME = 'tevent'
> -VERSION = '0.9.36'
> +VERSION = '0.9.37'
>  
>  blddir = 'bin'
>  
> -- 
> 2.11.0
> 
> 
> From c5a04d6e68ed08f2d0777e36233adac3b9eb71e3 Mon Sep 17 00:00:00 2001
> From: Volker Lendecke <vl at samba.org>
> Date: Wed, 2 May 2018 13:59:57 +0200
> Subject: [PATCH 4/7] lib: Add tevent_req_profile helpers
> 
> Print and marshall/unmarshall tevent_req_profile structs
> 
> Signed-off-by: Volker Lendecke <vl at samba.org>
> ---
>  lib/util/tevent_req_profile.c | 519 ++++++++++++++++++++++++++++++++++++++++++
>  lib/util/tevent_req_profile.h |  50 ++++
>  lib/util/wscript_build        |   1 +
>  3 files changed, 570 insertions(+)
>  create mode 100644 lib/util/tevent_req_profile.c
>  create mode 100644 lib/util/tevent_req_profile.h
> 
> diff --git a/lib/util/tevent_req_profile.c b/lib/util/tevent_req_profile.c
> new file mode 100644
> index 00000000000..522741c5ede
> --- /dev/null
> +++ b/lib/util/tevent_req_profile.c
> @@ -0,0 +1,519 @@
> +/*
> + * Unix SMB/CIFS implementation.
> + *
> + * Helpers around tevent_req_profile
> + *
> + * Copyright (C) Volker Lendecke 2018
> + *
> + *   ** NOTE! The following LGPL license applies to the tevent
> + *   ** library. This does NOT imply that all of Samba is released
> + *   ** under the LGPL
> + *
> + * This library is free software; you can redistribute it and/or
> + * modify it under the terms of the GNU Lesser General Public
> + * License as published by the Free Software Foundation; either
> + * version 3 of the License, or (at your option) any later version.
> + *
> + * This library is distributed in the hope that it will be useful,
> + * but WITHOUT ANY WARRANTY; without even the implied warranty of
> + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
> + * Lesser General Public License for more details.
> + *
> + * You should have received a copy of the GNU Lesser General Public
> + * License along with this library; if not, see <http://www.gnu.org/licenses/>.
> + */
> +
> +#include "replace.h"
> +#include <tevent.h>
> +#include "lib/util/tevent_req_profile.h"
> +#include "lib/util/time_basic.h"
> +#include "lib/util/memory.h"
> +
> +int tevent_req_profile_print(const struct tevent_req_profile *profile,
> +			     FILE *fp,
> +			     unsigned indent,
> +			     unsigned max_indent)
> +{
> +	struct timeval start, stop, diff;
> +	struct timeval_buf start_buf, stop_buf;
> +	const char *req_name = NULL;
> +	const char *start_location = NULL;
> +	const char *stop_location = NULL;
> +	pid_t pid;
> +	enum tevent_req_state state;
> +	const char *state_buf = NULL;
> +	uint64_t user_error;
> +	const struct tevent_req_profile *sub = NULL;
> +	int ret;
> +
> +	tevent_req_profile_get_name(profile, &req_name);
> +
> +	tevent_req_profile_get_start(profile, &start_location, &start);
> +	timeval_str_buf(&start, false, true, &start_buf);
> +
> +	tevent_req_profile_get_stop(profile, &stop_location, &stop);
> +	timeval_str_buf(&stop, false, true, &stop_buf);
> +
> +	diff = tevent_timeval_until(&start, &stop);
> +
> +	tevent_req_profile_get_status(profile, &pid, &state, &user_error);
> +
> +	switch(state) {
> +	case TEVENT_REQ_INIT:
> +		state_buf = "TEVENT_REQ_INIT";
> +		break;
> +	case TEVENT_REQ_IN_PROGRESS:
> +		state_buf = "TEVENT_REQ_IN_PROGRESS";
> +		break;
> +	case TEVENT_REQ_DONE:
> +		state_buf = "TEVENT_REQ_DONE";
> +		break;
> +	case TEVENT_REQ_USER_ERROR:
> +		state_buf = "TEVENT_REQ_USER_ERROR";
> +		break;
> +	case TEVENT_REQ_TIMED_OUT:
> +		state_buf = "TEVENT_REQ_TIMED_OUT";
> +		break;
> +	case TEVENT_REQ_NO_MEMORY:
> +		state_buf = "TEVENT_REQ_NO_MEMORY";
> +		break;
> +	case TEVENT_REQ_RECEIVED:
> +		state_buf = "TEVENT_REQ_RECEIVED";
> +		break;
> +	default:
> +		state_buf = "unknown";
> +		break;
> +	}
> +
> +	ret = fprintf(
> +		fp,
> +		"%*s[%s] %s [%s] %s [%s] [%ju.%.6ju] -> %s (%d %"PRIu64"))\n",
> +		indent,
> +		"",
> +		req_name,
> +		start_location,
> +		start_buf.buf,
> +		stop_location,
> +		stop_buf.buf,
> +		(uintmax_t)diff.tv_sec,
> +		(uintmax_t)diff.tv_usec,
> +		state_buf,
> +		(int)state,
> +		user_error);
> +
> +	if (ret < 0) {
> +		return ret;
> +	}
> +
> +	indent += 1;
> +
> +	if (indent >= max_indent) {
> +		return ret;
> +	}
> +
> +	for (sub = tevent_req_profile_get_subprofiles(profile);
> +	     sub != NULL;
> +	     sub = tevent_req_profile_next(sub)) {
> +		int subret;
> +
> +		subret = tevent_req_profile_print(sub, fp, indent, max_indent);
> +		if (subret < 0) {
> +			return subret;
> +		}
> +
> +		ret += subret;
> +
> +		if (ret < subret) {
> +			/* overflow */
> +			return -1;
> +		}
> +	}
> +
> +	return ret;
> +}
> +
> +char *tevent_req_profile_string(const struct tevent_req_profile *profile,
> +				TALLOC_CTX *mem_ctx,
> +				unsigned indent,
> +				unsigned max_indent)
> +{
> +	FILE *fp = NULL;
> +	char *buf = NULL;
> +	size_t buflen = 0;
> +	char *result = NULL;
> +	int ret;
> +
> +	fp = open_memstream(&buf, &buflen);
> +	if (fp == NULL) {
> +		return NULL;
> +	}
> +
> +	ret = tevent_req_profile_print(profile, fp, 0, max_indent);
> +	if (ret < 0) {
> +		goto done;
> +	}
> +
> +	ret = fclose(fp);
> +	if (ret != 0) {
> +		goto done;
> +	}
> +
> +	/*
> +	 * A FILE* from open_memstream maintains the 0-byte at the end
> +	 * beyond the reported length.
> +	 */
> +	result = talloc_memdup(mem_ctx, buf, buflen+1);
> +
> +done:
> +	SAFE_FREE(buf);
> +	return result;
> +}
> +
> +static ssize_t tevent_req_profile_pack_one(
> +	const struct tevent_req_profile *profile,
> +	uint8_t *buf,
> +	size_t buflen)
> +{
> +	const char *req_name = NULL;
> +	const char *start_location = NULL;
> +	const char *stop_location = NULL;
> +	struct timeval start_time, stop_time;
> +	pid_t pid;
> +	enum tevent_req_state state;
> +	uint64_t user_error;
> +	size_t pack_len, len;
> +	int ret;
> +
> +	tevent_req_profile_get_name(profile, &req_name);
> +	tevent_req_profile_get_start(profile, &start_location, &start_time);
> +	tevent_req_profile_get_stop(profile, &stop_location, &stop_time);
> +	tevent_req_profile_get_status(profile, &pid, &state, &user_error);
> +
> +	len = strlen(req_name)+1;
> +	if (buflen >= len) {
> +		memcpy(buf, req_name, len);
> +		buf += len;
> +		buflen -= len;
> +	}
> +
> +	pack_len = len;
> +
> +	len = strlen(start_location)+1;
> +	pack_len += len;
> +	if (pack_len < len) {
> +		return -1;	/* overflow */
> +	}
> +
> +	if (buflen >= len) {
> +		memcpy(buf, start_location, len);
> +		buf += len;
> +		buflen -= len;
> +	}
> +
> +	len = strlen(stop_location)+1;
> +	pack_len += len;
> +	if (pack_len < len) {
> +		return -1;	/* overflow */
> +	}
> +
> +	if (buflen >= len) {
> +		memcpy(buf, stop_location, len);
> +		buf += len;
> +		buflen -= len;
> +	}
> +
> +	ret = snprintf((char *)buf,
> +		       buflen,
> +		       "%ju %ju %ju %ju %d %d %"PRIu64"",
> +		       (uintmax_t)start_time.tv_sec,
> +		       (uintmax_t)start_time.tv_usec,
> +		       (uintmax_t)stop_time.tv_sec,
> +		       (uintmax_t)stop_time.tv_usec,
> +		       (int)pid,
> +		       (int)state,
> +		       user_error);
> +	if (ret < 0) {
> +		return -1;
> +	}
> +
> +	/*
> +	 * Take care of the trailing 0. No overflow check, this would
> +	 * be a VERY small number of bits for "int".
> +	 */
> +	ret += 1;
> +
> +	pack_len += ret;
> +
> +	return pack_len;
> +}
> +
> +ssize_t tevent_req_profile_pack(
> +	const struct tevent_req_profile *profile,
> +	uint8_t *buf,
> +	size_t buflen)
> +{
> +	const struct tevent_req_profile *sub = NULL;
> +	size_t num_sub;
> +	ssize_t pack_len, profile_len;
> +	int ret;
> +
> +	num_sub = 0;
> +	pack_len = 0;
> +
> +	for (sub = tevent_req_profile_get_subprofiles(profile);
> +	     sub != NULL;
> +	     sub = tevent_req_profile_next(sub)) {
> +		num_sub += 1;
> +	}
> +
> +	ret = snprintf((char *)buf, buflen, "%zu ", num_sub);
> +	if (ret < 0) {
> +		return -1;
> +	}
> +
> +	if (buflen > (size_t)ret) {
> +		buf += ret;
> +		buflen -= ret;
> +	}
> +
> +	pack_len = ret;
> +
> +	profile_len = tevent_req_profile_pack_one(profile, buf, buflen);
> +	if (profile_len == -1) {
> +		return -1;
> +	}
> +
> +	if (buflen >= (size_t)profile_len) {
> +		buf += profile_len;
> +		buflen -= profile_len;
> +	}
> +
> +	pack_len += profile_len;
> +	if (pack_len < profile_len) {
> +		return -1;	/* overflow */
> +	}
> +
> +	for (sub = tevent_req_profile_get_subprofiles(profile);
> +	     sub != NULL;
> +	     sub = tevent_req_profile_next(sub)) {
> +
> +		profile_len = tevent_req_profile_pack(sub, buf, buflen);
> +		if (profile_len == -1) {
> +			return -1;
> +		}
> +
> +		if (buflen >= (size_t)profile_len) {
> +			buf += profile_len;
> +			buflen -= profile_len;
> +		}
> +
> +		pack_len += profile_len;
> +		if (pack_len < profile_len) {
> +			return -1;	/* overflow */
> +		}
> +	}
> +
> +	return pack_len;
> +}
> +
> +static bool parse_uintmax(const char *buf,
> +			  char delimiter,
> +			  uintmax_t *presult,
> +			  char **p_endptr)
> +{
> +	uintmax_t result;
> +	char *endptr;
> +
> +	result = strtoumax(buf, &endptr, 10);
> +	if ((result == UINTMAX_MAX) && (errno == ERANGE)) {
> +		return false;
> +	}
> +	if (*endptr != delimiter) {
> +		return false;
> +	}
> +
> +	*presult = result;
> +	*p_endptr = endptr+1;
> +
> +	return true;
> +}
> +
> +static ssize_t tevent_req_profile_unpack_one(
> +	const uint8_t *buf,
> +	size_t buflen,
> +	struct tevent_req_profile *profile)
> +{
> +	const char *orig_buf = (const char *)buf;
> +	const char *req_name = NULL;
> +	const char *start_location = NULL;
> +	const char *stop_location = NULL;
> +	uintmax_t start_sec, start_usec, stop_sec, stop_usec, pid, state;
> +	uintmax_t user_error;
> +	char *next = NULL;
> +	size_t len;
> +	bool ok;
> +
> +	if (buflen == 0) {
> +		return -1;
> +	}
> +	if (buf[buflen-1] != '\0') {
> +		return -1;
> +	}
> +
> +	req_name = (const char *)buf;
> +	len = strlen(req_name)+1;
> +
> +	buf += len;
> +	buflen -= len;
> +	if (buflen == 0) {
> +		return -1;
> +	}
> +
> +	start_location = (const char *)buf;
> +	len = strlen(start_location)+1;
> +
> +	buf += len;
> +	buflen -= len;
> +	if (buflen == 0) {
> +		return -1;
> +	}
> +
> +	stop_location = (const char *)buf;
> +	len = strlen(stop_location)+1;
> +
> +	buf += len;
> +	buflen -= len;
> +	if (buflen == 0) {
> +		return -1;
> +	}
> +
> +	ok = parse_uintmax((const char *)buf, ' ', &start_sec, &next);
> +	if (!ok) {
> +		return -1;
> +	}
> +
> +	ok = parse_uintmax(next, ' ', &start_usec, &next);
> +	if (!ok) {
> +		return -1;
> +	}
> +
> +	ok = parse_uintmax(next, ' ', &stop_sec, &next);
> +	if (!ok) {
> +		return -1;
> +	}
> +
> +	ok = parse_uintmax(next, ' ', &stop_usec, &next);
> +	if (!ok) {
> +		return -1;
> +	}
> +
> +	ok = parse_uintmax(next, ' ', &pid, &next);
> +	if (!ok) {
> +		return -1;
> +	}
> +
> +	ok = parse_uintmax(next, ' ', &state, &next);
> +	if (!ok) {
> +		return -1;
> +	}
> +
> +	ok = parse_uintmax(next, '\0', &user_error, &next);
> +	if (!ok) {
> +		return -1;
> +	}
> +
> +	ok = tevent_req_profile_set_name(profile, req_name);
> +	if (!ok) {
> +		return -1;
> +	}
> +
> +	ok = tevent_req_profile_set_start(
> +		profile,
> +		start_location,
> +		(struct timeval){ .tv_sec=start_sec, .tv_usec=start_usec });
> +	if (!ok) {
> +		return -1;
> +	}
> +
> +	ok = tevent_req_profile_set_stop(
> +		profile,
> +		stop_location,
> +		(struct timeval){ .tv_sec=stop_sec, .tv_usec=stop_usec });
> +	if (!ok) {
> +		return -1;
> +	}
> +
> +	tevent_req_profile_set_status(
> +		profile,
> +		pid,
> +		(enum tevent_req_state)state,
> +		user_error);
> +
> +	return next - orig_buf;
> +}
> +
> +ssize_t tevent_req_profile_unpack(
> +	const uint8_t *buf,
> +	size_t buflen,
> +	TALLOC_CTX *mem_ctx,
> +	struct tevent_req_profile **p_profile)
> +{
> +	const uint8_t *orig_buf = buf;
> +	struct tevent_req_profile *profile = NULL;
> +	uintmax_t i, num_subprofiles;
> +	char *next = NULL;
> +	bool ok;
> +	ssize_t len;
> +
> +	errno = 0;
> +
> +	if (buf[buflen-1] != '\0') {
> +		return -1;
> +	}
> +
> +	ok = parse_uintmax((const char *)buf, ' ', &num_subprofiles, &next);
> +	if (!ok) {
> +		return -1;
> +	}
> +
> +	len = (next - (const char *)buf);
> +
> +	buf += len;
> +	buflen -= len;
> +
> +	profile = tevent_req_profile_create(mem_ctx);
> +	if (profile == NULL) {
> +		return -1;
> +	}
> +
> +	len = tevent_req_profile_unpack_one(buf, buflen, profile);
> +	if (len == -1) {
> +		TALLOC_FREE(profile);
> +		return -1;
> +	}
> +
> +	buf += len;
> +	buflen -= len;
> +
> +	for (i=0; i<num_subprofiles; i++) {
> +		struct tevent_req_profile *subprofile;
> +
> +		len = tevent_req_profile_unpack(
> +			buf,
> +			buflen,
> +			profile,
> +			&subprofile);
> +		if (len == -1) {
> +			TALLOC_FREE(profile);
> +			return -1;
> +		}
> +		buf += len;
> +		buflen -= len;
> +
> +		tevent_req_profile_append_sub(profile, &subprofile);
> +	}
> +
> +	*p_profile = profile;
> +
> +	return buf - orig_buf;
> +}
> diff --git a/lib/util/tevent_req_profile.h b/lib/util/tevent_req_profile.h
> new file mode 100644
> index 00000000000..00dbc5a9cc2
> --- /dev/null
> +++ b/lib/util/tevent_req_profile.h
> @@ -0,0 +1,50 @@
> +/*
> + * Unix SMB/CIFS implementation.
> + *
> + * Helpers around tevent_req_profile
> + *
> + * Copyright (C) Volker Lendecke 2018
> + *
> + *   ** NOTE! The following LGPL license applies to the tevent
> + *   ** library. This does NOT imply that all of Samba is released
> + *   ** under the LGPL
> + *
> + * This library is free software; you can redistribute it and/or
> + * modify it under the terms of the GNU Lesser General Public
> + * License as published by the Free Software Foundation; either
> + * version 3 of the License, or (at your option) any later version.
> + *
> + * This library is distributed in the hope that it will be useful,
> + * but WITHOUT ANY WARRANTY; without even the implied warranty of
> + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
> + * Lesser General Public License for more details.
> + *
> + * You should have received a copy of the GNU Lesser General Public
> + * License along with this library; if not, see <http://www.gnu.org/licenses/>.
> + */
> +
> +#ifndef __LIB_UTIL_TEVENT_REQ_PROFILE_UNPACK
> +#define __LIB_UTIL_TEVENT_REQ_PROFILE_UNPACK
> +
> +#include "replace.h"
> +#include <tevent.h>
> +
> +int tevent_req_profile_print(const struct tevent_req_profile *profile,
> +			     FILE *fp,
> +			     unsigned indent,
> +			     unsigned max_indent);
> +char *tevent_req_profile_string(const struct tevent_req_profile *profile,
> +				TALLOC_CTX *mem_ctx,
> +				unsigned indent,
> +				unsigned max_indent);
> +ssize_t tevent_req_profile_pack(
> +	const struct tevent_req_profile *profile,
> +	uint8_t *buf,
> +	size_t buflen);
> +ssize_t tevent_req_profile_unpack(
> +	const uint8_t *buf,
> +	size_t buflen,
> +	TALLOC_CTX *mem_ctx,
> +	struct tevent_req_profile **p_profile);
> +
> +#endif
> diff --git a/lib/util/wscript_build b/lib/util/wscript_build
> index 793e24669c9..8fc402062fb 100644
> --- a/lib/util/wscript_build
> +++ b/lib/util/wscript_build
> @@ -166,6 +166,7 @@ else:
>                            tevent_unix.c
>                            tevent_ntstatus.c
>                            tevent_werror.c
> +                          tevent_req_profile.c
>                        ''',
>                        local_include=False,
>                        public_deps='tevent samba-errors',
> -- 
> 2.11.0
> 
> 
> From acd7956f52b9af5ac17890c7d300611dd7897fca Mon Sep 17 00:00:00 2001
> From: Volker Lendecke <vl at samba.org>
> Date: Wed, 2 May 2018 14:02:18 +0200
> Subject: [PATCH 5/7] torture: Test tevent_req_profile
> 
> Signed-off-by: Volker Lendecke <vl at samba.org>
> ---
>  lib/tevent/test_req.c               | 276 ++++++++++++++++++++++++++++++++++++
>  source4/torture/local/local.c       |   1 +
>  source4/torture/local/wscript_build |   1 +
>  3 files changed, 278 insertions(+)
>  create mode 100644 lib/tevent/test_req.c
> 
> diff --git a/lib/tevent/test_req.c b/lib/tevent/test_req.c
> new file mode 100644
> index 00000000000..888bd40bf2b
> --- /dev/null
> +++ b/lib/tevent/test_req.c
> @@ -0,0 +1,276 @@
> +/*
> + * Unix SMB/CIFS implementation.
> + *
> + * testing of some tevent_req aspects
> + *
> + * Copyright (C) Volker Lendecke 2018
> + *
> + *   ** NOTE! The following LGPL license applies to the tevent
> + *   ** library. This does NOT imply that all of Samba is released
> + *   ** under the LGPL
> + *
> + * This library is free software; you can redistribute it and/or
> + * modify it under the terms of the GNU Lesser General Public
> + * License as published by the Free Software Foundation; either
> + * version 3 of the License, or (at your option) any later version.
> + *
> + * This library is distributed in the hope that it will be useful,
> + * but WITHOUT ANY WARRANTY; without even the implied warranty of
> + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
> + * Lesser General Public License for more details.
> + *
> + * You should have received a copy of the GNU Lesser General Public
> + * License along with this library; if not, see <http://www.gnu.org/licenses/>.
> + */
> +
> +#include "includes.h"
> +#include "tevent.h"
> +#include "torture/torture.h"
> +#include "torture/local/proto.h"
> +#include "lib/util/tevent_unix.h"
> +#include "lib/util/tevent_req_profile.h"
> +#include "lib/util/time_basic.h"
> +
> +struct tevent_req_create_state {
> +	uint8_t val;
> +};
> +
> +static bool test_tevent_req_create(struct torture_context *tctx,
> +				   const void *test_data)
> +{
> +	struct tevent_req *req;
> +	struct tevent_req_create_state *state;
> +
> +	req = tevent_req_create(tctx, &state,
> +				struct tevent_req_create_state);
> +	torture_assert(tctx, req != NULL, "tevent_req_create failed\n");
> +	torture_assert(tctx, state->val == 0, "state not initialized\n");
> +
> +	TALLOC_FREE(req);
> +
> +	return true;
> +}
> +
> +struct profile1_state {
> +	uint8_t dummy;
> +};
> +
> +static bool test_tevent_req_profile1(struct torture_context *tctx,
> +				     const void *test_data)
> +{
> +	struct tevent_req *req;
> +	struct profile1_state *state;
> +	const struct tevent_req_profile *p1;
> +	struct tevent_req_profile *p2;
> +	struct timeval start, stop;
> +	bool ok;
> +	int cmp;
> +
> +	req = tevent_req_create(tctx, &state, struct profile1_state);
> +	torture_assert(tctx, req != NULL, "tevent_req_create failed\n");
> +
> +	p1 = tevent_req_get_profile(req);
> +	torture_assert(tctx, p1 == NULL, "profile not initialized to NULL\n");
> +
> +	ok = tevent_req_set_profile(req);
> +	torture_assert(tctx, ok, "set_profile failed\n");
> +
> +	tevent_req_done(req);
> +
> +	p2 = tevent_req_move_profile(req, tctx);
> +	torture_assert(tctx, p2 != NULL, "get_profile failed\n");
> +
> +	/* Demonstrate sure "p" outlives req */
> +	TALLOC_FREE(req);
> +
> +	tevent_req_profile_get_start(p2, NULL, &start);
> +	tevent_req_profile_get_stop(p2, NULL, &stop);
> +
> +	cmp = tevent_timeval_compare(&start, &stop);
> +	torture_assert(tctx, cmp <= 0, "stop before start\n");
> +
> +	TALLOC_FREE(p2);
> +
> +	return true;
> +}
> +
> +struct profile2_state {
> +	uint8_t dummy;
> +};
> +
> +static void profile2_done(struct tevent_req *subreq);
> +
> +static struct tevent_req *profile2_send(TALLOC_CTX *mem_ctx,
> +					struct tevent_context *ev)
> +{
> +	struct tevent_req *req, *subreq;
> +	struct profile2_state *state;
> +	bool ok;
> +
> +	req = tevent_req_create(mem_ctx, &state, struct profile2_state);
> +	if (req == NULL) {
> +		return NULL;
> +	}
> +
> +	ok = tevent_req_set_profile(req);
> +	if (!ok) {
> +		return tevent_req_post(req, ev);
> +	}
> +
> +	subreq = tevent_wakeup_send(
> +		state,
> +		ev,
> +		tevent_timeval_current_ofs(0, 1));
> +	if (tevent_req_nomem(subreq, req)) {
> +		return tevent_req_post(req, ev);
> +	}
> +	tevent_req_set_callback(subreq, profile2_done, req);
> +
> +	return req;
> +}
> +
> +static void profile2_done(struct tevent_req *subreq)
> +{
> +	struct tevent_req *req = tevent_req_callback_data(
> +		subreq, struct tevent_req);
> +	bool ok;
> +
> +	ok = tevent_wakeup_recv(subreq);
> +	if (!ok) {
> +		tevent_req_oom(req);
> +		return;
> +	}
> +	tevent_req_done(req);
> +}
> +
> +static int profile2_recv(struct tevent_req *req,
> +			  TALLOC_CTX *mem_ctx,
> +			  struct tevent_req_profile **profile)
> +{
> +	int err;
> +
> +	if (tevent_req_is_unix_error(req, &err)) {
> +		return err;
> +	}
> +
> +	*profile = tevent_req_move_profile(req, mem_ctx);
> +
> +	return 0;
> +}
> +
> +static bool test_tevent_req_profile2(struct torture_context *tctx,
> +				     const void *test_data)
> +{
> +	struct tevent_context *ev;
> +	struct tevent_req *req;
> +	struct tevent_req_profile *p1 = NULL;
> +	struct tevent_req_profile *p2 = NULL;
> +	const char *str1, *str2;
> +	struct timeval tv1, tv2;
> +	pid_t pid1, pid2;
> +	enum tevent_req_state state1, state2;
> +	uint64_t err1, err2;
> +	ssize_t pack_len;
> +	int err;
> +	bool ok;
> +
> +	ev = samba_tevent_context_init(tctx);
> +	torture_assert(tctx, ev != NULL, "samba_tevent_context_init failed\n");
> +
> +	req = profile2_send(tctx, ev);
> +	torture_assert(tctx, req != NULL, "profile2_send failed\n");
> +
> +	ok = tevent_req_poll_unix(req, ev, &err);
> +	torture_assert(tctx, ok, "tevent_req_poll_unix failed\n");
> +
> +	err = profile2_recv(req, tctx, &p1);
> +	torture_assert(tctx, err == 0, "profile2_recv failed\n");
> +
> +	TALLOC_FREE(req);
> +	TALLOC_FREE(ev);
> +
> +	tevent_req_profile_print(p1, stdout, 0, UINT_MAX);
> +
> +	pack_len = tevent_req_profile_pack(p1, NULL, 0);
> +	torture_assert(tctx, pack_len>0, "profile_pack failed\n");
> +
> +	{
> +		uint8_t buf[pack_len];
> +		ssize_t unpack_len;
> +
> +		tevent_req_profile_pack(p1, buf, sizeof(buf));
> +		dump_data(10, buf, sizeof(buf));
> +
> +		unpack_len = tevent_req_profile_unpack(
> +			buf,
> +			pack_len,
> +			tctx,
> +			&p2);
> +		torture_assert(tctx,
> +			       pack_len==unpack_len,
> +			       "profile_unpack failed\n");
> +	}
> +
> +	tevent_req_profile_print(p2, stdout, 0, UINT_MAX);
> +
> +	tevent_req_profile_get_name(p1, &str1);
> +	tevent_req_profile_get_name(p2, &str2);
> +	torture_assert(tctx, strcmp(str1,str2)==0, "names differ\n");
> +
> +	tevent_req_profile_get_start(p1, &str1, &tv1);
> +	tevent_req_profile_get_start(p2, &str2, &tv2);
> +	torture_assert(tctx, strcmp(str1,str2)==0, "start strings differ\n");
> +	torture_assert(tctx,
> +		       tevent_timeval_compare(&tv1, &tv2) == 0,
> +		       "start times differ\n");
> +
> +	tevent_req_profile_get_stop(p1, &str1, &tv1);
> +	tevent_req_profile_get_stop(p2, &str2, &tv2);
> +	torture_assert(tctx, strcmp(str1,str2)==0, "stop strings differ\n");
> +	torture_assert(tctx,
> +		       tevent_timeval_compare(&tv1, &tv2) == 0,
> +		       "stop times differ\n");
> +
> +	tevent_req_profile_get_status(p1, &pid1, &state1, &err1);
> +	tevent_req_profile_get_status(p2, &pid2, &state2, &err2);
> +	torture_assert(tctx, pid1==pid2, "pids differ\n");
> +	torture_assert(tctx, state1==state2, "states differ\n");
> +	torture_assert(tctx, err1==err2, "user errors differ\n");
> +
> +	str1 = tevent_req_profile_string(p1, p1, 0, UINT_MAX);
> +	torture_assert(tctx, str1!=NULL, "profile_string failed\n");
> +	str2 = tevent_req_profile_string(p2, p2, 0, UINT_MAX);
> +	torture_assert(tctx, str2!=NULL, "profile_string failed\n");
> +
> +	torture_assert(tctx, strcmp(str1,str2)==0, "result strings differ\n");
> +
> +	TALLOC_FREE(p1);
> +	TALLOC_FREE(p2);
> +
> +	return true;
> +}
> +
> +struct torture_suite *torture_local_tevent_req(TALLOC_CTX *mem_ctx)
> +{
> +	struct torture_suite *suite;
> +
> +	suite = torture_suite_create(mem_ctx, "tevent_req");
> +
> +	torture_suite_add_simple_tcase_const(
> +		suite,
> +		"create",
> +		test_tevent_req_create,
> +		NULL);
> +	torture_suite_add_simple_tcase_const(
> +		suite,
> +		"profile1",
> +		test_tevent_req_profile1,
> +		NULL);
> +	torture_suite_add_simple_tcase_const(
> +		suite,
> +		"profile2",
> +		test_tevent_req_profile2,
> +		NULL);
> +
> +	return suite;
> +}
> diff --git a/source4/torture/local/local.c b/source4/torture/local/local.c
> index d1c523bdc1f..69ecc6b6ec8 100644
> --- a/source4/torture/local/local.c
> +++ b/source4/torture/local/local.c
> @@ -64,6 +64,7 @@
>  	torture_local_string_case,
>  	torture_local_compression,
>  	torture_local_event, 
> +	torture_local_tevent_req,
>  	torture_local_torture,
>  	torture_local_dbspeed, 
>  	torture_local_credentials,
> diff --git a/source4/torture/local/wscript_build b/source4/torture/local/wscript_build
> index 6cbb14d86e4..2dd18193c94 100644
> --- a/source4/torture/local/wscript_build
> +++ b/source4/torture/local/wscript_build
> @@ -13,6 +13,7 @@ TORTURE_LOCAL_SOURCE = '''../../../lib/util/charset/tests/iconv.c
>          ../../../lib/util/charset/tests/convert_string.c
>  	../../libcli/security/tests/sddl.c ../../../lib/tdr/testsuite.c
>  	../../../lib/tevent/testsuite.c ../../param/tests/share.c
> +        ../../../lib/tevent/test_req.c
>  	../../param/tests/loadparm.c ../../../auth/credentials/tests/simple.c local.c
>  	dbspeed.c torture.c ../ldb/ldb.c ../../dsdb/common/tests/dsdb_dn.c
>  	../../dsdb/schema/tests/schema_syntax.c
> -- 
> 2.11.0
> 
> 
> From d3bd4d2865ebc44609bcda0fccffd3d6ca9cd5df Mon Sep 17 00:00:00 2001
> From: Volker Lendecke <vl at samba.org>
> Date: Thu, 3 May 2018 15:12:55 +0200
> Subject: [PATCH 6/7] winbind: Convert process_request() to tevent_req
> 
> Having a central tevent_req per winbind child request is prerequisite
> for request profiling
> 
> Signed-off-by: Volker Lendecke <vl at samba.org>
> ---
>  source3/winbindd/winbindd.c | 328 ++++++++++++++++++++++++--------------------
>  1 file changed, 181 insertions(+), 147 deletions(-)
> 
> diff --git a/source3/winbindd/winbindd.c b/source3/winbindd/winbindd.c
> index f0f0eef7bfc..56c5b6ed8e2 100644
> --- a/source3/winbindd/winbindd.c
> +++ b/source3/winbindd/winbindd.c
> @@ -54,8 +54,6 @@
>  static bool client_is_idle(struct winbindd_cli_state *state);
>  static void remove_client(struct winbindd_cli_state *state);
>  static void winbindd_setup_max_fds(void);
> -static void request_ok(struct winbindd_cli_state *state);
> -static void request_error(struct winbindd_cli_state *state);
>  
>  static bool opt_nocache = False;
>  static bool interactive = False;
> @@ -660,219 +658,222 @@ static struct winbindd_async_dispatch_table async_priv_table[] = {
>  	{ 0, NULL, NULL, NULL }
>  };
>  
> -static void wb_request_done(struct tevent_req *req);
> +struct process_request_state {
> +	struct winbindd_cli_state *cli_state;
> +	struct tevent_context *ev;
> +};
>  
> -static void process_request(struct winbindd_cli_state *state)
> +static void process_request_done(struct tevent_req *subreq);
> +static void process_request_written(struct tevent_req *subreq);
> +
> +static struct tevent_req *process_request_send(
> +	TALLOC_CTX *mem_ctx,
> +	struct tevent_context *ev,
> +	struct winbindd_cli_state *cli_state)
>  {
> +	struct tevent_req *req, *subreq;
> +	struct process_request_state *state;
>  	struct winbindd_async_dispatch_table *atable;
> +	enum winbindd_cmd cmd = cli_state->request->cmd;
>  	size_t i;
>  	bool ok;
>  
> -	state->mem_ctx = talloc_named(state, 0, "winbind request");
> -	if (state->mem_ctx == NULL)
> -		return;
> +	req = tevent_req_create(mem_ctx, &state,
> +				struct process_request_state);
> +	if (req == NULL) {
> +		return NULL;
> +	}
> +	state->cli_state = cli_state;
> +	state->ev = ev;
> +
> +	SMB_ASSERT(cli_state->mem_ctx == NULL);
> +	cli_state->mem_ctx = talloc_named(cli_state, 0, "winbind request");
> +	if (tevent_req_nomem(cli_state->mem_ctx, req)) {
> +		return tevent_req_post(req, ev);
> +	}
> +
> +	cli_state->response = talloc_zero(
> +		cli_state->mem_ctx,
> +		struct winbindd_response);
> +	if (tevent_req_nomem(cli_state->response, req)) {
> +		return tevent_req_post(req, ev);
> +	}
> +	cli_state->response->result = WINBINDD_PENDING;
> +	cli_state->response->length = sizeof(struct winbindd_response);
>  
>  	/* Remember who asked us. */
> -	state->pid = state->request->pid;
> +	cli_state->pid = cli_state->request->pid;
>  
> -	state->cmd_name = "unknown request";
> -	state->recv_fn = NULL;
> -	/* client is newest */
> -	winbindd_promote_client(state);
> +	cli_state->cmd_name = "unknown request";
> +	cli_state->recv_fn = NULL;
>  
> -	/* Process command */
> +	/* client is newest */
> +	winbindd_promote_client(cli_state);
>  
>  	for (atable = async_nonpriv_table; atable->send_req; atable += 1) {
> -		if (state->request->cmd == atable->cmd) {
> +		if (cmd == atable->cmd) {
>  			break;
>  		}
>  	}
>  
> -	if ((atable->send_req == NULL) && state->privileged) {
> +	if ((atable->send_req == NULL) && cli_state->privileged) {
>  		for (atable = async_priv_table; atable->send_req;
>  		     atable += 1) {
> -			if (state->request->cmd == atable->cmd) {
> +			if (cmd == atable->cmd) {
>  				break;
>  			}
>  		}
>  	}
>  
>  	if (atable->send_req != NULL) {
> -		struct tevent_req *req;
> -
> -		state->cmd_name = atable->cmd_name;
> -		state->recv_fn = atable->recv_req;
> +		cli_state->cmd_name = atable->cmd_name;
> +		cli_state->recv_fn = atable->recv_req;
>  
>  		DEBUG(10, ("process_request: Handling async request %d:%s\n",
> -			   (int)state->pid, state->cmd_name));
> -
> -		req = atable->send_req(state->mem_ctx, server_event_context(),
> -				       state, state->request);
> -		if (req == NULL) {
> -			DEBUG(0, ("process_request: atable->send failed for "
> -				  "%s\n", atable->cmd_name));
> -			request_error(state);
> -			return;
> +			   (int)cli_state->pid, cli_state->cmd_name));
> +
> +		subreq = atable->send_req(
> +			state,
> +			state->ev,
> +			cli_state,
> +			cli_state->request);
> +		if (tevent_req_nomem(subreq, req)) {
> +			return tevent_req_post(req, ev);
>  		}
> -		tevent_req_set_callback(req, wb_request_done, state);
> -		return;
> +		tevent_req_set_callback(subreq, process_request_done, req);
> +		return req;
>  	}
>  
> -	state->response = talloc_zero(state->mem_ctx,
> -				      struct winbindd_response);
> -	if (state->response == NULL) {
> -		DEBUG(10, ("talloc failed\n"));
> -		remove_client(state);
> -		return;
> -	}
> -	state->response->result = WINBINDD_PENDING;
> -	state->response->length = sizeof(struct winbindd_response);
> -
>  	for (i=0; i<ARRAY_SIZE(bool_dispatch_table); i++) {
> -		if (bool_dispatch_table[i].cmd == state->request->cmd) {
> +		if (cmd == bool_dispatch_table[i].cmd) {
>  			break;
>  		}
>  	}
>  
> -	if (i == ARRAY_SIZE(bool_dispatch_table)) {
> -		DEBUG(10,("process_request: unknown request fn number %d\n",
> -			  (int)state->request->cmd ));
> -		request_error(state);
> -		return;
> -	}
> -
> -	DBG_DEBUG("process_request: request fn %s\n",
> -		  bool_dispatch_table[i].cmd_name);
> -
> -	ok = bool_dispatch_table[i].fn(state);
> +	ok = false;
>  
> -	if (ok) {
> -		request_ok(state);
> -	} else {
> -		request_error(state);
> +	if (i < ARRAY_SIZE(bool_dispatch_table)) {
> +		DBG_DEBUG("process_request: request fn %s\n",
> +			  bool_dispatch_table[i].cmd_name);
> +		ok = bool_dispatch_table[i].fn(cli_state);
>  	}
> -}
>  
> -static void wb_request_done(struct tevent_req *req)
> -{
> -	struct winbindd_cli_state *state = tevent_req_callback_data(
> -		req, struct winbindd_cli_state);
> -	NTSTATUS status;
> +	cli_state->response->result = ok ? WINBINDD_OK : WINBINDD_ERROR;
>  
> -	state->response = talloc_zero(state->mem_ctx,
> -				      struct winbindd_response);
> -	if (state->response == NULL) {
> -		DEBUG(0, ("wb_request_done[%d:%s]: talloc_zero failed - removing client\n",
> -			  (int)state->pid, state->cmd_name));
> -		remove_client(state);
> -		return;
> -	}
> -	state->response->result = WINBINDD_PENDING;
> -	state->response->length = sizeof(struct winbindd_response);
> +	TALLOC_FREE(cli_state->io_req);
> +	TALLOC_FREE(cli_state->request);
>  
> -	status = state->recv_fn(req, state->response);
> -	TALLOC_FREE(req);
> +	subreq = wb_resp_write_send(
> +		state,
> +		state->ev,
> +		cli_state->out_queue,
> +		cli_state->sock,
> +		cli_state->response);
> +	if (tevent_req_nomem(subreq, req)) {
> +		return tevent_req_post(req, ev);
> +	}
> +	tevent_req_set_callback(subreq, process_request_written, req);
>  
> -	DEBUG(10,("wb_request_done[%d:%s]: %s\n",
> -		  (int)state->pid, state->cmd_name, nt_errstr(status)));
> +	cli_state->io_req = subreq;
>  
> -	if (!NT_STATUS_IS_OK(status)) {
> -		request_error(state);
> -		return;
> -	}
> -	request_ok(state);
> +	return req;
>  }
>  
> -/*
> - * This is the main event loop of winbind requests. It goes through a
> - * state-machine of 3 read/write requests, 4 if you have extra data to send.
> - *
> - * An idle winbind client has a read request of 4 bytes outstanding,
> - * finalizing function is request_len_recv, checking the length. request_recv
> - * then processes the packet. The processing function then at some point has
> - * to call request_finished which schedules sending the response.
> - */
> -
> -static void request_finished(struct winbindd_cli_state *state);
> +static void process_request_done(struct tevent_req *subreq)
> +{
> +	struct tevent_req *req = tevent_req_callback_data(
> +		subreq, struct tevent_req);
> +	struct process_request_state *state = tevent_req_data(
> +		req, struct process_request_state);
> +	struct winbindd_cli_state *cli_state = state->cli_state;
> +	NTSTATUS status;
> +	bool ok;
>  
> -static void winbind_client_request_read(struct tevent_req *req);
> -static void winbind_client_response_written(struct tevent_req *req);
> -static void winbind_client_activity(struct tevent_req *req);
> +	status = cli_state->recv_fn(subreq, cli_state->response);
> +	TALLOC_FREE(subreq);
>  
> -static void request_finished(struct winbindd_cli_state *state)
> -{
> -	struct tevent_req *req;
> +	DBG_DEBUG("[%d:%s]: %s\n",
> +		  (int)cli_state->pid,
> +		  cli_state->cmd_name,
> +		  nt_errstr(status));
>  
> -	/* free client socket monitoring request */
> -	TALLOC_FREE(state->io_req);
> +	ok = NT_STATUS_IS_OK(status);
> +	cli_state->response->result = ok ? WINBINDD_OK : WINBINDD_ERROR;
>  
> -	TALLOC_FREE(state->request);
> +	TALLOC_FREE(cli_state->io_req);
> +	TALLOC_FREE(cli_state->request);
>  
> -	req = wb_resp_write_send(state, server_event_context(),
> -				 state->out_queue, state->sock,
> -				 state->response);
> -	if (req == NULL) {
> -		DEBUG(10,("request_finished[%d:%s]: wb_resp_write_send() failed\n",
> -			  (int)state->pid, state->cmd_name));
> -		remove_client(state);
> +	subreq = wb_resp_write_send(
> +		state,
> +		state->ev,
> +		cli_state->out_queue,
> +		cli_state->sock,
> +		cli_state->response);
> +	if (tevent_req_nomem(subreq, req)) {
>  		return;
>  	}
> -	tevent_req_set_callback(req, winbind_client_response_written, state);
> -	state->io_req = req;
> +	tevent_req_set_callback(subreq, process_request_written, req);
> +
> +	cli_state->io_req = subreq;
>  }
>  
> -static void winbind_client_response_written(struct tevent_req *req)
> +static void process_request_written(struct tevent_req *subreq)
>  {
> -	struct winbindd_cli_state *state = tevent_req_callback_data(
> -		req, struct winbindd_cli_state);
> +	struct tevent_req *req = tevent_req_callback_data(
> +		subreq, struct tevent_req);
> +	struct process_request_state *state = tevent_req_data(
> +		req, struct process_request_state);
> +	struct winbindd_cli_state *cli_state = state->cli_state;
>  	ssize_t ret;
>  	int err;
>  
> -	state->io_req = NULL;
> +	cli_state->io_req = NULL;
>  
> -	ret = wb_resp_write_recv(req, &err);
> -	TALLOC_FREE(req);
> +	ret = wb_resp_write_recv(subreq, &err);
> +	TALLOC_FREE(subreq);
>  	if (ret == -1) {
> -		close(state->sock);
> -		state->sock = -1;
> -		DEBUG(2, ("Could not write response[%d:%s] to client: %s\n",
> -			  (int)state->pid, state->cmd_name, strerror(err)));
> -		remove_client(state);
> +		tevent_req_nterror(req, map_nt_error_from_unix(err));
>  		return;
>  	}
>  
> -	DEBUG(10,("winbind_client_response_written[%d:%s]: delivered response "
> -		  "to client\n", (int)state->pid, state->cmd_name));
> +	DBG_DEBUG("[%d:%s]: delivered response to client\n",
> +		  (int)cli_state->pid, cli_state->cmd_name);
>  
> -	TALLOC_FREE(state->mem_ctx);
> -	state->response = NULL;
> -	state->cmd_name = "no request";
> -	state->recv_fn = NULL;
> +	TALLOC_FREE(cli_state->mem_ctx);
> +	cli_state->response = NULL;
> +	cli_state->cmd_name = "no request";
> +	cli_state->recv_fn = NULL;
>  
> -	req = wb_req_read_send(state, server_event_context(), state->sock,
> -			       WINBINDD_MAX_EXTRA_DATA);
> -	if (req == NULL) {
> -		remove_client(state);
> -		return;
> -	}
> -	tevent_req_set_callback(req, winbind_client_request_read, state);
> -	state->io_req = req;
> +	tevent_req_done(req);
>  }
>  
> -static void request_error(struct winbindd_cli_state *state)
> +static NTSTATUS process_request_recv(struct tevent_req *req)
>  {
> -	SMB_ASSERT(state->response->result == WINBINDD_PENDING);
> -	state->response->result = WINBINDD_ERROR;
> -	request_finished(state);
> -}
> +	NTSTATUS status;
>  
> -static void request_ok(struct winbindd_cli_state *state)
> -{
> -	SMB_ASSERT(state->response->result == WINBINDD_PENDING);
> -	state->response->result = WINBINDD_OK;
> -	request_finished(state);
> +	if (tevent_req_is_nterror(req, &status)) {
> +		tevent_req_received(req);
> +		return status;
> +	}
> +
> +	tevent_req_received(req);
> +	return NT_STATUS_OK;
>  }
>  
> +/*
> + * This is the main event loop of winbind requests. It goes through a
> + * state-machine of 3 read/write requests, 4 if you have extra data to send.
> + *
> + * An idle winbind client has a read request of 4 bytes outstanding,
> + * finalizing function is request_len_recv, checking the length. request_recv
> + * then processes the packet. The processing function then at some point has
> + * to call request_finished which schedules sending the response.
> + */
> +
> +static void winbind_client_request_read(struct tevent_req *req);
> +static void winbind_client_activity(struct tevent_req *req);
> +static void winbind_client_processed(struct tevent_req *req);
> +
>  /* Process a new connection by adding it to the client connection list */
>  
>  static void new_connection(int listen_sock, bool privileged)
> @@ -970,7 +971,13 @@ static void winbind_client_request_read(struct tevent_req *req)
>  	tevent_req_set_callback(req, winbind_client_activity, state);
>  	state->io_req = req;
>  
> -	process_request(state);
> +	req = process_request_send(state, server_event_context(), state);
> +	if (req == NULL) {
> +		DBG_ERR("process_request_send failed\n");
> +		remove_client(state);
> +		return;
> +	}
> +	tevent_req_set_callback(req, winbind_client_processed, state);
>  }
>  
>  static void winbind_client_activity(struct tevent_req *req)
> @@ -1004,6 +1011,33 @@ static void winbind_client_activity(struct tevent_req *req)
>  	remove_client(state);
>  }
>  
> +static void winbind_client_processed(struct tevent_req *req)
> +{
> +	struct winbindd_cli_state *cli_state = tevent_req_callback_data(
> +		req, struct winbindd_cli_state);
> +	NTSTATUS status;
> +
> +	status = process_request_recv(req);
> +	TALLOC_FREE(req);
> +	if (!NT_STATUS_IS_OK(status)) {
> +		DBG_DEBUG("process_request failed: %s\n", nt_errstr(status));
> +		remove_client(cli_state);
> +		return;
> +	}
> +
> +	req = wb_req_read_send(
> +		cli_state,
> +		server_event_context(),
> +		cli_state->sock,
> +		WINBINDD_MAX_EXTRA_DATA);
> +	if (req == NULL) {
> +		remove_client(cli_state);
> +		return;
> +	}
> +	tevent_req_set_callback(req, winbind_client_request_read, cli_state);
> +	cli_state->io_req = req;
> +}
> +
>  /* Remove a client connection from client connection list */
>  
>  static void remove_client(struct winbindd_cli_state *state)
> -- 
> 2.11.0
> 
> 
> From 76992bddc69c90112228b1f36a90d65d146e68f1 Mon Sep 17 00:00:00 2001
> From: Volker Lendecke <vl at samba.org>
> Date: Tue, 19 Jun 2018 11:13:19 +0200
> Subject: [PATCH 7/7] winbindd: Do request profiling
> 
> By default we log a request that takes more than 60 seconds. This can be
> changed by setting
> 
> winbind:request profile threshold = <seconds>
> 
> Another parameter controls the depth of the request hierarchy printed:
> 
> winbind:request profile depth = <n>
> 
> The default request logged to syslog via DEBUG(0) looks like the
> following for a wbinfo -P:
> 
> [struct process_request_state] ../source3/winbindd/winbindd.c:683 [2018/06/19 13:33:14.190365] ../source3/winbindd/winbindd.c:853 [2018/06/19 13:33:14.192737] [0.002372] -> TEVENT_REQ_DONE (2 0))
>  [struct winbindd_ping_dc_state] ../source3/winbindd/winbindd_ping_dc.c:41 [2018/06/19 13:33:14.190369] ../source3/winbindd/winbindd_ping_dc.c:112 [2018/06/19 13:33:14.192681] [0.002312] -> TEVENT_REQ_DONE (2 0))
>   [struct dcerpc_wbint_PingDc_state] default/librpc/gen_ndr/ndr_winbind_c.c:4335 [2018/06/19 13:33:14.190383] default/librpc/gen_ndr/ndr_winbind_c.c:4396 [2018/06/19 13:33:14.192680] [0.002297] -> TEVENT_REQ_DONE (2 0))
>    [struct dcerpc_wbint_PingDc_r_state] default/librpc/gen_ndr/ndr_winbind_c.c:4251 [2018/06/19 13:33:14.190385] default/librpc/gen_ndr/ndr_winbind_c.c:4285 [2018/06/19 13:33:14.192678] [0.002293] -> TEVENT_REQ_DONE (2 0))
>     [struct dcerpc_binding_handle_call_state] ../librpc/rpc/binding_handle.c:371 [2018/06/19 13:33:14.190387] ../librpc/rpc/binding_handle.c:520 [2018/06/19 13:33:14.192675] [0.002288] -> TEVENT_REQ_DONE (2 0))
>      [struct dcerpc_binding_handle_raw_call_state] ../librpc/rpc/binding_handle.c:149 [2018/06/19 13:33:14.190400] ../librpc/rpc/binding_handle.c:203 [2018/06/19 13:33:14.192646] [0.002246] -> TEVENT_REQ_DONE (2 0))
>       [struct wbint_bh_raw_call_state] ../source3/winbindd/winbindd_dual_ndr.c:89 [2018/06/19 13:33:14.190402] ../source3/winbindd/winbindd_dual_ndr.c:204 [2018/06/19 13:33:14.192644] [0.002242] -> TEVENT_REQ_DONE (2 0))
>        [struct wb_domain_request_state] ../source3/winbindd/winbindd_dual.c:473 [2018/06/19 13:33:14.190404] ../source3/winbindd/winbindd_dual.c:708 [2018/06/19 13:33:14.192640] [0.002236] -> TEVENT_REQ_DONE (2 0))
>         [struct wb_child_request_state] ../source3/winbindd/winbindd_dual.c:198 [2018/06/19 13:33:14.190411] ../source3/winbindd/winbindd_dual.c:273 [2018/06/19 13:33:14.192638] [0.002227] -> TEVENT_REQ_DONE (2 0))
>          [struct tevent_queue_wait_state] ../lib/tevent/tevent_queue.c:336 [2018/06/19 13:33:14.190412] ../lib/tevent/tevent_queue.c:355 [2018/06/19 13:33:14.190415] [0.000003] -> TEVENT_REQ_DONE (2 0))
>          [struct wb_simple_trans_state] ../nsswitch/wb_reqtrans.c:375 [2018/06/19 13:33:14.190424] ../nsswitch/wb_reqtrans.c:432 [2018/06/19 13:33:14.192630] [0.002206] -> TEVENT_REQ_DONE (2 0))
>           [struct req_write_state] ../nsswitch/wb_reqtrans.c:158 [2018/06/19 13:33:14.190425] ../nsswitch/wb_reqtrans.c:194 [2018/06/19 13:33:14.190472] [0.000047] -> TEVENT_REQ_DONE (2 0))
>            [struct writev_state] ../lib/async_req/async_sock.c:263 [2018/06/19 13:33:14.190432] ../lib/async_req/async_sock.c:412 [2018/06/19 13:33:14.190470] [0.000038] -> TEVENT_REQ_DONE (2 0))
>           [struct resp_read_state] ../nsswitch/wb_reqtrans.c:222 [2018/06/19 13:33:14.190475] ../nsswitch/wb_reqtrans.c:275 [2018/06/19 13:33:14.192629] [0.002154] -> TEVENT_REQ_DONE (2 0))
>            [struct read_packet_state] ../lib/async_req/async_sock.c:458 [2018/06/19 13:33:14.190476] ../lib/async_req/async_sock.c:546 [2018/06/19 13:33:14.192626] [0.002150] -> TEVENT_REQ_DONE (2 0))
>  [struct resp_write_state] ../nsswitch/wb_reqtrans.c:307 [2018/06/19 13:33:14.192693] ../nsswitch/wb_reqtrans.c:344 [2018/06/19 13:33:14.192734] [0.000041] -> TEVENT_REQ_DONE (2 0))
>   [struct writev_state] ../lib/async_req/async_sock.c:263 [2018/06/19 13:33:14.192694] ../lib/async_req/async_sock.c:412 [2018/06/19 13:33:14.192732] [0.000038] -> TEVENT_REQ_DONE (2 0))
> 
> Signed-off-by: Volker Lendecke <vl at samba.org>
> ---
>  source3/winbindd/winbindd.c | 46 +++++++++++++++++++++++++++++++++++++++++++--
>  1 file changed, 44 insertions(+), 2 deletions(-)
> 
> diff --git a/source3/winbindd/winbindd.c b/source3/winbindd/winbindd.c
> index 56c5b6ed8e2..254d93b344d 100644
> --- a/source3/winbindd/winbindd.c
> +++ b/source3/winbindd/winbindd.c
> @@ -45,6 +45,7 @@
>  #include "libsmb/samlogon_cache.h"
>  #include "libcli/auth/netlogon_creds_cli.h"
>  #include "passdb.h"
> +#include "lib/util/tevent_req_profile.h"
>  
>  #undef DBGC_CLASS
>  #define DBGC_CLASS DBGC_WINBIND
> @@ -686,6 +687,11 @@ static struct tevent_req *process_request_send(
>  	state->cli_state = cli_state;
>  	state->ev = ev;
>  
> +	ok = tevent_req_set_profile(req);
> +	if (!ok) {
> +		return tevent_req_post(req, ev);
> +	}
> +
>  	SMB_ASSERT(cli_state->mem_ctx == NULL);
>  	cli_state->mem_ctx = talloc_named(cli_state, 0, "winbind request");
>  	if (tevent_req_nomem(cli_state->mem_ctx, req)) {
> @@ -847,7 +853,10 @@ static void process_request_written(struct tevent_req *subreq)
>  	tevent_req_done(req);
>  }
>  
> -static NTSTATUS process_request_recv(struct tevent_req *req)
> +static NTSTATUS process_request_recv(
> +	struct tevent_req *req,
> +	TALLOC_CTX *mem_ctx,
> +	struct tevent_req_profile **profile)
>  {
>  	NTSTATUS status;
>  
> @@ -856,6 +865,7 @@ static NTSTATUS process_request_recv(struct tevent_req *req)
>  		return status;
>  	}
>  
> +	*profile = tevent_req_move_profile(req, mem_ctx);
>  	tevent_req_received(req);
>  	return NT_STATUS_OK;
>  }
> @@ -1015,9 +1025,12 @@ static void winbind_client_processed(struct tevent_req *req)
>  {
>  	struct winbindd_cli_state *cli_state = tevent_req_callback_data(
>  		req, struct winbindd_cli_state);
> +	struct tevent_req_profile *profile = NULL;
> +	struct timeval start, stop, diff;
> +	int threshold;
>  	NTSTATUS status;
>  
> -	status = process_request_recv(req);
> +	status = process_request_recv(req, cli_state, &profile);
>  	TALLOC_FREE(req);
>  	if (!NT_STATUS_IS_OK(status)) {
>  		DBG_DEBUG("process_request failed: %s\n", nt_errstr(status));
> @@ -1025,6 +1038,35 @@ static void winbind_client_processed(struct tevent_req *req)
>  		return;
>  	}
>  
> +	tevent_req_profile_get_start(profile, NULL, &start);
> +	tevent_req_profile_get_stop(profile, NULL, &stop);
> +	diff = tevent_timeval_until(&start, &stop);
> +
> +	threshold = lp_parm_int(-1, "winbind", "request profile threshold", 60);
> +
> +	if (diff.tv_sec >= threshold) {
> +		int depth;
> +		char *str;
> +
> +		depth = lp_parm_int(
> +			-1,
> +			"winbind",
> +			"request profile depth",
> +			INT_MAX);
> +
> +		DBG_ERR("request took %u.%.6u seconds\n",
> +			(unsigned)diff.tv_sec, (unsigned)diff.tv_usec);
> +
> +		str = tevent_req_profile_string(profile, talloc_tos(), 0, depth);
> +		if (str != NULL) {
> +			/* No "\n", already contained in "str" */
> +			DEBUGADD(0, ("%s", str));
> +		}
> +		TALLOC_FREE(str);
> +	}
> +
> +	TALLOC_FREE(profile);
> +
>  	req = wb_req_read_send(
>  		cli_state,
>  		server_event_context(),
> -- 
> 2.11.0
> 




More information about the samba-technical mailing list