Difference in buffer behaviour between 8.89 and 8.9?
rapier
rapier at psc.edu
Thu May 26 05:08:51 AEST 2022
Thanks! This worked well.
I'm still trying to figure out exactly which buffer is causing the
problem but I can describe the behaviour a little better. There is some
buffer that is a function of CHAN_SES_WINDOW_DEFAULT. After digging
through the code I'm pretty sure it's c->output.
After an initial burst of transfer this buffer starts to grow up to some
maximum value. Each round of data it gets causes sshbuf_reserve to call
sshbuf_alloc which then reallocs the buffer and fires off memcpys. Until
the buffer reaches that maximum none/little of it ends up getting
consumed. I believe, and this mostly a guess, that it not getting
consumed clamps the advertised receive window. Once it reaches that
maximum consumption starts and throughput picks up again.
When CHAN_SES_WINDOW_DEFAULT is small (64*CSPD) this delay isn't
noticible outside of really looking for it in the sshbuf logs. When CSWD
is large the delay becomes noticable, especially at higher RTTs when it
needs to handle more outstanding data.
What I'm trying to figure out is how to tell sshbuf_reserve to
selectively accelerate the growth of that buffer but I'm at a loss. The
right place seems to be in channel_input_data but mucking about with
sshbuf_put is failing. If you have any ideas please let me know.
Chris
On 5/24/22 7:27 PM, Damien Miller wrote:
> diff --git a/sshbuf-getput-basic.c b/sshbuf-getput-basic.c
> index 15a56cb..f845ac6 100644
> --- a/sshbuf-getput-basic.c
> +++ b/sshbuf-getput-basic.c
> @@ -194,7 +194,7 @@ sshbuf_get_string(struct sshbuf *buf, u_char **valp, size_t *lenp)
> return r;
> if (valp != NULL) {
> if ((*valp = malloc(len + 1)) == NULL) {
> - SSHBUF_DBG(("SSH_ERR_ALLOC_FAIL"));
> + SSHBUF_DBG("SSH_ERR_ALLOC_FAIL");
> return SSH_ERR_ALLOC_FAIL;
> }
> if (len != 0)
> @@ -225,7 +225,7 @@ sshbuf_get_string_direct(struct sshbuf *buf, const u_char **valp, size_t *lenp)
> *lenp = len;
> if (sshbuf_consume(buf, len + 4) != 0) {
> /* Shouldn't happen */
> - SSHBUF_DBG(("SSH_ERR_INTERNAL_ERROR"));
> + SSHBUF_DBG("SSH_ERR_INTERNAL_ERROR");
> SSHBUF_ABORT();
> return SSH_ERR_INTERNAL_ERROR;
> }
> @@ -244,16 +244,16 @@ sshbuf_peek_string_direct(const struct sshbuf *buf, const u_char **valp,
> if (lenp != NULL)
> *lenp = 0;
> if (sshbuf_len(buf) < 4) {
> - SSHBUF_DBG(("SSH_ERR_MESSAGE_INCOMPLETE"));
> + SSHBUF_DBG("SSH_ERR_MESSAGE_INCOMPLETE");
> return SSH_ERR_MESSAGE_INCOMPLETE;
> }
> len = PEEK_U32(p);
> if (len > SSHBUF_SIZE_MAX - 4) {
> - SSHBUF_DBG(("SSH_ERR_STRING_TOO_LARGE"));
> + SSHBUF_DBG("SSH_ERR_STRING_TOO_LARGE");
> return SSH_ERR_STRING_TOO_LARGE;
> }
> if (sshbuf_len(buf) - 4 < len) {
> - SSHBUF_DBG(("SSH_ERR_MESSAGE_INCOMPLETE"));
> + SSHBUF_DBG("SSH_ERR_MESSAGE_INCOMPLETE");
> return SSH_ERR_MESSAGE_INCOMPLETE;
> }
> if (valp != NULL)
> @@ -279,14 +279,14 @@ sshbuf_get_cstring(struct sshbuf *buf, char **valp, size_t *lenp)
> /* Allow a \0 only at the end of the string */
> if (len > 0 &&
> (z = memchr(p , '\0', len)) != NULL && z < p + len - 1) {
> - SSHBUF_DBG(("SSH_ERR_INVALID_FORMAT"));
> + SSHBUF_DBG("SSH_ERR_INVALID_FORMAT");
> return SSH_ERR_INVALID_FORMAT;
> }
> if ((r = sshbuf_skip_string(buf)) != 0)
> return -1;
> if (valp != NULL) {
> if ((*valp = malloc(len + 1)) == NULL) {
> - SSHBUF_DBG(("SSH_ERR_ALLOC_FAIL"));
> + SSHBUF_DBG("SSH_ERR_ALLOC_FAIL");
> return SSH_ERR_ALLOC_FAIL;
> }
> if (len != 0)
> @@ -513,7 +513,7 @@ sshbuf_put_string(struct sshbuf *buf, const void *v, size_t len)
> int r;
>
> if (len > SSHBUF_SIZE_MAX - 4) {
> - SSHBUF_DBG(("SSH_ERR_NO_BUFFER_SPACE"));
> + SSHBUF_DBG("SSH_ERR_NO_BUFFER_SPACE");
> return SSH_ERR_NO_BUFFER_SPACE;
> }
> if ((r = sshbuf_reserve(buf, len + 4, &d)) < 0)
> @@ -571,7 +571,7 @@ sshbuf_put_bignum2_bytes(struct sshbuf *buf, const void *v, size_t len)
> int r, prepend;
>
> if (len > SSHBUF_SIZE_MAX - 5) {
> - SSHBUF_DBG(("SSH_ERR_NO_BUFFER_SPACE"));
> + SSHBUF_DBG("SSH_ERR_NO_BUFFER_SPACE");
> return SSH_ERR_NO_BUFFER_SPACE;
> }
> /* Skip leading zero bytes */
> @@ -621,7 +621,7 @@ sshbuf_get_bignum2_bytes_direct(struct sshbuf *buf,
> *lenp = len;
> if (sshbuf_consume(buf, olen + 4) != 0) {
> /* Shouldn't happen */
> - SSHBUF_DBG(("SSH_ERR_INTERNAL_ERROR"));
> + SSHBUF_DBG("SSH_ERR_INTERNAL_ERROR");
> SSHBUF_ABORT();
> return SSH_ERR_INTERNAL_ERROR;
> }
> diff --git a/sshbuf-getput-crypto.c b/sshbuf-getput-crypto.c
> index e3e71ba..b22c1f3 100644
> --- a/sshbuf-getput-crypto.c
> +++ b/sshbuf-getput-crypto.c
> @@ -78,7 +78,7 @@ sshbuf_get_ec(struct sshbuf *buf, EC_POINT *v, const EC_GROUP *g)
> /* Skip string */
> if (sshbuf_get_string_direct(buf, NULL, NULL) != 0) {
> /* Shouldn't happen */
> - SSHBUF_DBG(("SSH_ERR_INTERNAL_ERROR"));
> + SSHBUF_DBG("SSH_ERR_INTERNAL_ERROR");
> SSHBUF_ABORT();
> return SSH_ERR_INTERNAL_ERROR;
> }
> @@ -94,7 +94,7 @@ sshbuf_get_eckey(struct sshbuf *buf, EC_KEY *v)
> size_t len;
>
> if (pt == NULL) {
> - SSHBUF_DBG(("SSH_ERR_ALLOC_FAIL"));
> + SSHBUF_DBG("SSH_ERR_ALLOC_FAIL");
> return SSH_ERR_ALLOC_FAIL;
> }
> if ((r = sshbuf_peek_string_direct(buf, &d, &len)) < 0) {
> @@ -113,7 +113,7 @@ sshbuf_get_eckey(struct sshbuf *buf, EC_KEY *v)
> /* Skip string */
> if (sshbuf_get_string_direct(buf, NULL, NULL) != 0) {
> /* Shouldn't happen */
> - SSHBUF_DBG(("SSH_ERR_INTERNAL_ERROR"));
> + SSHBUF_DBG("SSH_ERR_INTERNAL_ERROR");
> SSHBUF_ABORT();
> return SSH_ERR_INTERNAL_ERROR;
> }
> diff --git a/sshbuf.c b/sshbuf.c
> index 8db22a0..685dbb8 100644
> --- a/sshbuf.c
> +++ b/sshbuf.c
> @@ -39,7 +39,7 @@ sshbuf_check_sanity(const struct sshbuf *buf)
> buf->size > buf->alloc ||
> buf->off > buf->size)) {
> /* Do not try to recover from corrupted buffer internals */
> - SSHBUF_DBG(("SSH_ERR_INTERNAL_ERROR"));
> + SSHBUF_DBG("SSH_ERR_INTERNAL_ERROR");
> ssh_signal(SIGSEGV, SIG_DFL);
> raise(SIGSEGV);
> return SSH_ERR_INTERNAL_ERROR;
> @@ -50,7 +50,7 @@ sshbuf_check_sanity(const struct sshbuf *buf)
> static void
> sshbuf_maybe_pack(struct sshbuf *buf, int force)
> {
> - SSHBUF_DBG(("force %d", force));
> + SSHBUF_DBG("force %d", force);
> SSHBUF_TELL("pre-pack");
> if (buf->off == 0 || buf->readonly || buf->refcount > 1)
> return;
> @@ -221,7 +221,7 @@ sshbuf_set_max_size(struct sshbuf *buf, size_t max_size)
> u_char *dp;
> int r;
>
> - SSHBUF_DBG(("set max buf = %p len = %zu", buf, max_size));
> + SSHBUF_DBG("set max buf = %p len = %zu", buf, max_size);
> if ((r = sshbuf_check_sanity(buf)) != 0)
> return r;
> if (max_size == buf->max_size)
> @@ -239,7 +239,7 @@ sshbuf_set_max_size(struct sshbuf *buf, size_t max_size)
> rlen = ROUNDUP(buf->size, SSHBUF_SIZE_INC);
> if (rlen > max_size)
> rlen = max_size;
> - SSHBUF_DBG(("new alloc = %zu", rlen));
> + SSHBUF_DBG("new alloc = %zu", rlen);
> if ((dp = recallocarray(buf->d, buf->alloc, rlen, 1)) == NULL)
> return SSH_ERR_ALLOC_FAIL;
> buf->cd = buf->d = dp;
> @@ -307,7 +307,7 @@ sshbuf_allocate(struct sshbuf *buf, size_t len)
> u_char *dp;
> int r;
>
> - SSHBUF_DBG(("allocate buf = %p len = %zu", buf, len));
> + SSHBUF_DBG("allocate buf = %p len = %zu", buf, len);
> if ((r = sshbuf_check_reserve(buf, len)) != 0)
> return r;
> /*
> @@ -325,12 +325,12 @@ sshbuf_allocate(struct sshbuf *buf, size_t len)
> */
> need = len + buf->size - buf->alloc;
> rlen = ROUNDUP(buf->alloc + need, SSHBUF_SIZE_INC);
> - SSHBUF_DBG(("need %zu initial rlen %zu", need, rlen));
> + SSHBUF_DBG("need %zu initial rlen %zu", need, rlen);
> if (rlen > buf->max_size)
> rlen = buf->alloc + need;
> - SSHBUF_DBG(("adjusted rlen %zu", rlen));
> + SSHBUF_DBG("adjusted rlen %zu", rlen);
> if ((dp = recallocarray(buf->d, buf->alloc, rlen, 1)) == NULL) {
> - SSHBUF_DBG(("realloc fail"));
> + SSHBUF_DBG("realloc fail");
> return SSH_ERR_ALLOC_FAIL;
> }
> buf->alloc = rlen;
> @@ -352,7 +352,7 @@ sshbuf_reserve(struct sshbuf *buf, size_t len, u_char **dpp)
> if (dpp != NULL)
> *dpp = NULL;
>
> - SSHBUF_DBG(("reserve buf = %p len = %zu", buf, len));
> + SSHBUF_DBG("reserve buf = %p len = %zu", buf, len);
> if ((r = sshbuf_allocate(buf, len)) != 0)
> return r;
>
> @@ -368,7 +368,7 @@ sshbuf_consume(struct sshbuf *buf, size_t len)
> {
> int r;
>
> - SSHBUF_DBG(("len = %zu", len));
> + SSHBUF_DBG("len = %zu", len);
> if ((r = sshbuf_check_sanity(buf)) != 0)
> return r;
> if (len == 0)
> @@ -388,7 +388,7 @@ sshbuf_consume_end(struct sshbuf *buf, size_t len)
> {
> int r;
>
> - SSHBUF_DBG(("len = %zu", len));
> + SSHBUF_DBG("len = %zu", len);
> if ((r = sshbuf_check_sanity(buf)) != 0)
> return r;
> if (len == 0)
> diff --git a/sshbuf.h b/sshbuf.h
> index 9624c43..cc3c34a 100644
> --- a/sshbuf.h
> +++ b/sshbuf.h
> @@ -396,16 +396,17 @@ u_int sshbuf_refcount(const struct sshbuf *buf);
>
> # ifdef SSHBUF_DEBUG
> # define SSHBUF_TELL(what) do { \
> - printf("%s:%d %s: %s size %zu alloc %zu off %zu max %zu\n", \
> + fprintf(stderr, \
> + "%s:%d %s: %s size %zu alloc %zu off %zu max %zu\n", \
> __FILE__, __LINE__, __func__, what, \
> buf->size, buf->alloc, buf->off, buf->max_size); \
> - fflush(stdout); \
> + fflush(stderr); \
> } while (0)
> -# define SSHBUF_DBG(x) do { \
> - printf("%s:%d %s: ", __FILE__, __LINE__, __func__); \
> - printf x; \
> - printf("\n"); \
> - fflush(stdout); \
> +# define SSHBUF_DBG(...) do { \
> + fprintf(stderr, "%s:%d %s: ", __FILE__, __LINE__, __func__); \
> + fprintf(stderr, __VA_ARGS__); \
> + fprintf(stderr, "\n"); \
> + fflush(stderr); \
> } while (0)
> # else
> # define SSHBUF_TELL(what)
More information about the openssh-unix-dev
mailing list