[PATCH trace-cmd 0/2] better error handling during copy

[PATCH trace-cmd 0/2] better error handling during copy

[Peter Xu]

CCing lkml this time. Hope it's the right way...

For patch 1, it only drops one printf(), which is optional.

For patch 2, it tries to dump more information when we got errors,
and also catches some silence ones.

Peter Xu (2):
  trace-cmd-listen: remove useless printf
  trace-recorder: better error handling during copy

 trace-listen.c   |  1 -
 trace-recorder.c | 34 ++++++++++++++++++++++++----------
 2 files changed, 24 insertions(+), 11 deletions(-)

-- 
2.4.3

[PATCH trace-cmd 1/2] trace-cmd-listen: remove useless printf

[Peter Xu]

This line is useless since we will get more verbose info in
do_connection(). Another problem is, we will get this "connected!" line
everytime after we hit "ctrl-c" for "trace-cmd listen". We possibly do
not want that.

Signed-off-by: Peter Xu <peterx@redhat.com>
---
 trace-listen.c | 1 -
 1 file changed, 1 deletion(-)

diff --git a/trace-listen.c b/trace-listen.c
index 1e38eda..12cc9c5 100644
--- a/trace-listen.c
+++ b/trace-listen.c
@@ -721,7 +721,6 @@ static void do_accept_loop(int sfd)
 	do {
 		cfd = accept(sfd, (struct sockaddr *)&peer_addr,
 			     &peer_addr_len);
-		printf("connected!\n");
 		if (cfd < 0 && errno == EINTR)
 			continue;
 		if (cfd < 0)
-- 
2.4.3

[PATCH trace-cmd 2/2] trace-recorder: better error handling during copy

[Peter Xu]

Currently we have two ways to copy data, one is splice, one is read +
write. For both, dump more information when we got errors during the
copy. Also, when we update_fd(), we should make sure all bytes written,
and update written bytes only.

These information might be important to better diagnose when the copy
got wrong, like no space error, or connection error when copying data to
remote sockets. In the past, we just got silence errors without notice.

Signed-off-by: Peter Xu <peterx@redhat.com>
---
 trace-recorder.c | 34 ++++++++++++++++++++++++----------
 1 file changed, 24 insertions(+), 10 deletions(-)

diff --git a/trace-recorder.c b/trace-recorder.c
index 49b04ea..7d6feb0 100644
--- a/trace-recorder.c
+++ b/trace-recorder.c
@@ -334,13 +334,14 @@ static inline void update_fd(struct tracecmd_recorder *recorder, int size)
  */
 static long splice_data(struct tracecmd_recorder *recorder)
 {
-	long ret;
+	long ret, written;
 
 	ret = splice(recorder->trace_fd, NULL, recorder->brass[1], NULL,
 		     recorder->page_size, 1 /* SPLICE_F_MOVE */);
 	if (ret < 0) {
 		if (errno != EAGAIN && errno != EINTR) {
-			warning("recorder error in splice input");
+			warning("recorder error in splice input: %s",
+				strerror(errno));
 			return -1;
 		}
 		if (errno == EINTR)
@@ -348,16 +349,23 @@ static long splice_data(struct tracecmd_recorder *recorder)
 	} else if (ret == 0)
 		return 0;
 
-	ret = splice(recorder->brass[0], NULL, recorder->fd, NULL,
-		     recorder->page_size, recorder->fd_flags);
-	if (ret < 0) {
+	written = splice(recorder->brass[0], NULL, recorder->fd, NULL,
+			 recorder->page_size, recorder->fd_flags);
+	if (written < 0) {
 		if (errno != EAGAIN && errno != EINTR) {
-			warning("recorder error in splice output");
+			warning("recorder error in splice output: %s",
+				strerror(errno));
 			return -1;
 		}
 		ret = 0;
-	} else
+	} else {
+		if (written != ret) {
+			warning("recorder written %ld to write %d: %s",
+				written, ret, strerror(errno));
+			return -1;
+		}
 		update_fd(recorder, ret);
+	}
 
 	return ret;
 }
@@ -369,18 +377,24 @@ static long splice_data(struct tracecmd_recorder *recorder)
 static long read_data(struct tracecmd_recorder *recorder)
 {
 	char buf[recorder->page_size];
-	long ret;
+	ssize_t ret, written;
 
 	ret = read(recorder->trace_fd, buf, recorder->page_size);
 	if (ret < 0) {
 		if (errno != EAGAIN && errno != EINTR) {
-			warning("recorder error in read output");
+			warning("recorder error in read output: %s",
+				strerror(errno));
 			return -1;
 		}
 		ret = 0;
 	}
 	if (ret > 0) {
-		write(recorder->fd, buf, ret);
+		written = write(recorder->fd, buf, ret);
+		if (written != ret) {
+			warning("recorder written %ld to write %d: %s",
+				written, ret, strerror(errno));
+			return -1;
+		}
 		update_fd(recorder, ret);
 	}
 
-- 
2.4.3

Re: [PATCH trace-cmd 1/2] trace-cmd-listen: remove useless printf

[Steven Rostedt]

On Tue, 22 Mar 2016 09:14:14 -0400
Peter Xu <peterx@redhat.com> wrote:

> This line is useless since we will get more verbose info in
> do_connection(). Another problem is, we will get this "connected!" line
> everytime after we hit "ctrl-c" for "trace-cmd listen". We possibly do
> not want that.
> 
> Signed-off-by: Peter Xu <peterx@redhat.com>
> ---
>  trace-listen.c | 1 -
>  1 file changed, 1 deletion(-)
> 
> diff --git a/trace-listen.c b/trace-listen.c
> index 1e38eda..12cc9c5 100644
> --- a/trace-listen.c
> +++ b/trace-listen.c
> @@ -721,7 +721,6 @@ static void do_accept_loop(int sfd)
>  	do {
>  		cfd = accept(sfd, (struct sockaddr *)&peer_addr,
>  			     &peer_addr_len);
> -		printf("connected!\n");

I probably kept this in for debugging. But I still think there should
be some kind of logging here. If anything, change this to a debug
print. I'm working on passing in --debug into the command line here, so
I'm not going to take this patch. It should be converted to the debug
coed.

-- Steve

>  		if (cfd < 0 && errno == EINTR)
>  			continue;
>  		if (cfd < 0)

Re: [PATCH trace-cmd 2/2] trace-recorder: better error handling during copy

[Steven Rostedt]

On Tue, 22 Mar 2016 09:14:33 -0400
Peter Xu <peterx@redhat.com> wrote:

> Currently we have two ways to copy data, one is splice, one is read +
> write. For both, dump more information when we got errors during the
> copy. Also, when we update_fd(), we should make sure all bytes written,
> and update written bytes only.
> 
> These information might be important to better diagnose when the copy
> got wrong, like no space error, or connection error when copying data to
> remote sockets. In the past, we just got silence errors without notice.
> 
> Signed-off-by: Peter Xu <peterx@redhat.com>
> ---
>  trace-recorder.c | 34 ++++++++++++++++++++++++----------
>  1 file changed, 24 insertions(+), 10 deletions(-)
> 
> diff --git a/trace-recorder.c b/trace-recorder.c
> index 49b04ea..7d6feb0 100644
> --- a/trace-recorder.c
> +++ b/trace-recorder.c
> @@ -334,13 +334,14 @@ static inline void update_fd(struct tracecmd_recorder *recorder, int size)
>   */
>  static long splice_data(struct tracecmd_recorder *recorder)
>  {
> -	long ret;
> +	long ret, written;
>  
>  	ret = splice(recorder->trace_fd, NULL, recorder->brass[1], NULL,
>  		     recorder->page_size, 1 /* SPLICE_F_MOVE */);
>  	if (ret < 0) {
>  		if (errno != EAGAIN && errno != EINTR) {
> -			warning("recorder error in splice input");
> +			warning("recorder error in splice input: %s",
> +				strerror(errno));

I'm wondering if we should add a "pwarning()" helper function that will
do the stderror(error) for us.

-- Steve

>  			return -1;
>  		}

Re: [PATCH trace-cmd 1/2] trace-cmd-listen: remove useless printf

[Peter Xu]

On Tue, Mar 22, 2016 at 09:18:11AM -0400, Steven Rostedt wrote:
> > diff --git a/trace-listen.c b/trace-listen.c
> > index 1e38eda..12cc9c5 100644
> > --- a/trace-listen.c
> > +++ b/trace-listen.c
> > @@ -721,7 +721,6 @@ static void do_accept_loop(int sfd)
> >  	do {
> >  		cfd = accept(sfd, (struct sockaddr *)&peer_addr,
> >  			     &peer_addr_len);
> > -		printf("connected!\n");
> 
> I probably kept this in for debugging. But I still think there should
> be some kind of logging here. If anything, change this to a debug
> print. I'm working on passing in --debug into the command line here, so
> I'm not going to take this patch. It should be converted to the debug
> coed.

Sure. This is trivial. Please just drop it.

-- peterx

Re: [PATCH trace-cmd 2/2] trace-recorder: better error handling during copy

[Peter Xu]

On Tue, Mar 22, 2016 at 09:19:56AM -0400, Steven Rostedt wrote:
> On Tue, 22 Mar 2016 09:14:33 -0400
> Peter Xu <peterx@redhat.com> wrote:
> 
> > Currently we have two ways to copy data, one is splice, one is read +
> > write. For both, dump more information when we got errors during the
> > copy. Also, when we update_fd(), we should make sure all bytes written,
> > and update written bytes only.
> > 
> > These information might be important to better diagnose when the copy
> > got wrong, like no space error, or connection error when copying data to
> > remote sockets. In the past, we just got silence errors without notice.
> > 
> > Signed-off-by: Peter Xu <peterx@redhat.com>
> > ---
> >  trace-recorder.c | 34 ++++++++++++++++++++++++----------
> >  1 file changed, 24 insertions(+), 10 deletions(-)
> > 
> > diff --git a/trace-recorder.c b/trace-recorder.c
> > index 49b04ea..7d6feb0 100644
> > --- a/trace-recorder.c
> > +++ b/trace-recorder.c
> > @@ -334,13 +334,14 @@ static inline void update_fd(struct tracecmd_recorder *recorder, int size)
> >   */
> >  static long splice_data(struct tracecmd_recorder *recorder)
> >  {
> > -	long ret;
> > +	long ret, written;
> >  
> >  	ret = splice(recorder->trace_fd, NULL, recorder->brass[1], NULL,
> >  		     recorder->page_size, 1 /* SPLICE_F_MOVE */);
> >  	if (ret < 0) {
> >  		if (errno != EAGAIN && errno != EINTR) {
> > -			warning("recorder error in splice input");
> > +			warning("recorder error in splice input: %s",
> > +				strerror(errno));
> 
> I'm wondering if we should add a "pwarning()" helper function that will
> do the stderror(error) for us.

Ah, I just found that __vwarning() will dump errno string, and
warning() is calling that. So it explained why I got one more line
when got errors... ;)

How about remove all the strerror() things, and just keep capturing
the written size? Let me send a v2 for this patch.

Thanks.

-- peterx

[PATCH trace-cmd v2] trace-recorder: better error handling during copy

[Peter Xu]

Currently we have two ways to copy data, one is splice, one is read +
write. For both, we should make sure all bytes written, and update
written bytes only. It might happen when we got, e.g., no space error,
or connection error when copying data to remote sockets. In the past, we
just got silence errors without notice.

Signed-off-by: Peter Xu <peterx@redhat.com>
---
 trace-recorder.c | 25 ++++++++++++++++++-------
 1 file changed, 18 insertions(+), 7 deletions(-)

diff --git a/trace-recorder.c b/trace-recorder.c
index 49b04ea..ac319d8 100644
--- a/trace-recorder.c
+++ b/trace-recorder.c
@@ -334,7 +334,7 @@ static inline void update_fd(struct tracecmd_recorder *recorder, int size)
  */
 static long splice_data(struct tracecmd_recorder *recorder)
 {
-	long ret;
+	long ret, written;
 
 	ret = splice(recorder->trace_fd, NULL, recorder->brass[1], NULL,
 		     recorder->page_size, 1 /* SPLICE_F_MOVE */);
@@ -348,16 +348,22 @@ static long splice_data(struct tracecmd_recorder *recorder)
 	} else if (ret == 0)
 		return 0;
 
-	ret = splice(recorder->brass[0], NULL, recorder->fd, NULL,
-		     recorder->page_size, recorder->fd_flags);
-	if (ret < 0) {
+	written = splice(recorder->brass[0], NULL, recorder->fd, NULL,
+			 recorder->page_size, recorder->fd_flags);
+	if (written < 0) {
 		if (errno != EAGAIN && errno != EINTR) {
 			warning("recorder error in splice output");
 			return -1;
 		}
 		ret = 0;
-	} else
+	} else {
+		if (written != ret) {
+			warning("recorder written %ld to write %d",
+				written, ret);
+			return -1;
+		}
 		update_fd(recorder, ret);
+	}
 
 	return ret;
 }
@@ -369,7 +375,7 @@ static long splice_data(struct tracecmd_recorder *recorder)
 static long read_data(struct tracecmd_recorder *recorder)
 {
 	char buf[recorder->page_size];
-	long ret;
+	ssize_t ret, written;
 
 	ret = read(recorder->trace_fd, buf, recorder->page_size);
 	if (ret < 0) {
@@ -380,7 +386,12 @@ static long read_data(struct tracecmd_recorder *recorder)
 		ret = 0;
 	}
 	if (ret > 0) {
-		write(recorder->fd, buf, ret);
+		written = write(recorder->fd, buf, ret);
+		if (written != ret) {
+			warning("recorder written %ld to write %d",
+				written, ret);
+			return -1;
+		}
 		update_fd(recorder, ret);
 	}
 
-- 
2.4.3