From 7d73f4a1d0d02bbf130f46ec8f632763b2217e52 Mon Sep 17 00:00:00 2001 From: Dmitry Simonenko Date: Wed, 5 Apr 2017 15:21:43 +0300 Subject: [PATCH] odissey: add extra log details for every io error --- core/od_auth.c | 36 +++++++++++++++++++++++++------ core/od_be.c | 33 ++++++++++++++++++++++------ core/od_cancel.c | 6 +++++- core/od_fe.c | 42 +++++++++++++++++++++++++++++------- core/od_io.h | 4 ++-- core/od_router.c | 12 +++++++---- core/od_router_transaction.c | 1 - 7 files changed, 106 insertions(+), 28 deletions(-) diff --git a/core/od_auth.c b/core/od_auth.c index e2f2784d..5176a58c 100644 --- a/core/od_auth.c +++ b/core/od_auth.c @@ -50,14 +50,20 @@ od_authfe_cleartext(od_client_t *client) if (rc == -1) return -1; rc = od_write(client->io, stream); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, client->io, "C (auth): write error: %s", + machine_error(client->io)); return -1; + } /* wait for password response */ while (1) { rc = od_read(client->io, stream, 0); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, client->io, "C (auth): read error: %s", + machine_error(client->io)); return -1; + } uint8_t type = *stream->s; od_debug(&pooler->od->log, client->io, "C (auth): %c", *stream->s); /* PasswordMessage */ @@ -111,15 +117,21 @@ od_authfe_md5(od_client_t *client) if (rc == -1) return -1; rc = od_write(client->io, stream); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, client->io, "C (auth): write error: %s", + machine_error(client->io)); return -1; + } /* wait for password response */ while (1) { int rc; rc = od_read(client->io, stream, 0); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, client->io, "C (auth): read error: %s", + machine_error(client->io)); return -1; + } uint8_t type = *stream->s; od_debug(&pooler->od->log, client->io, "C (auth): %c", *stream->s); @@ -224,7 +236,12 @@ int od_authfe(od_client_t *client) if (rc == -1) return -1; rc = od_write(client->io, stream); - return rc; + if (rc == -1) { + od_error(&pooler->od->log, client->io, "C (auth): write error: %s", + machine_error(client->io)); + return -1; + } + return 0; } static inline int @@ -258,6 +275,8 @@ od_authbe_cleartext(od_server_t *server) } rc = od_write(server->io, stream); if (rc == -1) { + od_error(&pooler->od->log, server->io, "S (auth): write error: %s", + machine_error(server->io)); return -1; } return 0; @@ -311,6 +330,8 @@ od_authbe_md5(od_server_t *server, uint8_t salt[4]) } rc = od_write(server->io, stream); if (rc == -1) { + od_error(&pooler->od->log, server->io, "S (auth): write error: %s", + machine_error(server->io)); return -1; } return 0; @@ -360,8 +381,11 @@ int od_authbe(od_server_t *server) while (1) { int rc; rc = od_read(server->io, &server->stream, 0); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, server->io, "S (auth): read error: %s", + machine_error(server->io)); return -1; + } char type = *server->stream.s; od_debug(&pooler->od->log, server->io, "S (auth): %c", type); diff --git a/core/od_be.c b/core/od_be.c index 7df59533..78b8d614 100644 --- a/core/od_be.c +++ b/core/od_be.c @@ -76,6 +76,7 @@ int od_beclose(od_server_t *server) static int od_bestartup(od_server_t *server) { + od_pooler_t *pooler = server->pooler; od_route_t *route = server->route; so_stream_t *stream = &server->stream; so_stream_reset(stream); @@ -88,8 +89,11 @@ od_bestartup(od_server_t *server) if (rc == -1) return -1; rc = od_write(server->io, stream); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, server->io, "S (startup): write error: %s", + machine_error(server->io)); return -1; + } server->count_request++; return 0; } @@ -102,8 +106,11 @@ od_besetup(od_server_t *server) while (1) { int rc; rc = od_read(server->io, &server->stream, 0); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, server->io, "S (setup): write error: %s", + machine_error(server->io)); return -1; + } char type = *server->stream.s; od_debug(&pooler->od->log, server->io, "S (setup): %c", type); switch (type) { @@ -162,14 +169,21 @@ od_beconnect_tls(od_pooler_t *pooler, od_server_t *server, if (rc == -1) return -1; rc = od_write(server->io, stream); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, server->io, "S (tls): write error: %s", + machine_error(server->io)); return -1; + } /* read server reply */ so_stream_reset(stream); rc = machine_read(server->io, (char*)stream->p, 1, 0); - if (rc < 0) + if (rc < 0) { + od_error(&pooler->od->log, server->io, + "S (tls): read error: %s", + machine_error(server->io)); return -1; + } switch (*stream->p) { case 'S': /* supported */ @@ -436,8 +450,11 @@ od_beready_wait(od_server_t *server, char *procedure, int time_ms) while (1) { int rc; rc = od_read(server->io, stream, time_ms); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, server->io, "S (%s): write error: %s", + procedure, machine_error(server->io)); return -1; + } uint8_t type = *stream->s; od_debug(&pooler->od->log, server->io, "S (%s): %c", procedure, type); @@ -452,6 +469,7 @@ od_beready_wait(od_server_t *server, char *procedure, int time_ms) static inline int od_bequery(od_server_t *server, char *procedure, char *query, int len) { + od_pooler_t *pooler = server->pooler; int rc; so_stream_t *stream = &server->stream; so_stream_reset(stream); @@ -459,8 +477,11 @@ od_bequery(od_server_t *server, char *procedure, char *query, int len) if (rc == -1) return -1; rc = od_write(server->io, stream); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, server->io, "S (%s): write error: %s", + procedure, machine_error(server->io)); return -1; + } server->count_request++; rc = od_beready_wait(server, procedure, 0); if (rc == -1) diff --git a/core/od_cancel.c b/core/od_cancel.c index 07edcc38..dcfb72cd 100644 --- a/core/od_cancel.c +++ b/core/od_cancel.c @@ -98,7 +98,11 @@ int od_cancel_of(od_pooler_t *pooler, so_stream_free(&stream); return -1; } - od_write(io, &stream); + rc = od_write(io, &stream); + if (rc == -1) { + od_error(&pooler->od->log, io, "(cancel): write error: %s", + machine_error(io)); + } machine_close(io); so_stream_free(&stream); return 0; diff --git a/core/od_fe.c b/core/od_fe.c index 34db569d..af4433e6 100644 --- a/core/od_fe.c +++ b/core/od_fe.c @@ -78,6 +78,7 @@ int od_feerror(od_client_t *client, char *fmt, ...) static int od_festartup_read(od_client_t *client) { + od_pooler_t *pooler = client->pooler; so_stream_t *stream = &client->stream; so_stream_reset(stream); for (;;) { @@ -88,14 +89,21 @@ od_festartup_read(od_client_t *client) to_read = so_read_startup(&len, &pos_data, &pos_size); if (to_read == 0) break; - if (to_read == -1) + if (to_read == -1) { + od_error(&pooler->od->log, client->io, + "C (startup): bad startup packet"); return -1; + } int rc = so_stream_ensure(stream, to_read); if (rc == -1) return -1; rc = machine_read(client->io, (char*)stream->p, to_read, 0); - if (rc < 0) + if (rc < 0) { + od_error(&pooler->od->log, client->io, + "C (startup): read error: %s", + machine_error(client->io)); return -1; + } so_stream_advance(stream, to_read); } return 0; @@ -124,8 +132,11 @@ int od_festartup(od_client_t *client) /* not supported 'N' */ so_stream_write8(stream, 'N'); rc = od_write(client->io, stream); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, client->io, "C (tls): write error: %s", + machine_error(client->io)); return -1; + } od_log(&pooler->od->log, client->io, "C (tls): disabled, closing"); return -1; @@ -133,12 +144,15 @@ int od_festartup(od_client_t *client) /* supported 'S' */ so_stream_write8(stream, 'S'); rc = od_write(client->io, stream); - if (rc == -1) + if (rc == -1) { + od_error(&pooler->od->log, client->io, "C (tls): write error: %s", + machine_error(client->io)); return -1; + } rc = machine_set_tls(client->io, pooler->tls); if (rc == -1) { - od_log(&pooler->od->log, client->io, - "C (tls): error: %s", machine_error(client->io)); + od_error(&pooler->od->log, client->io, + "C (tls): error: %s", machine_error(client->io)); return -1; } od_debug(&pooler->od->log, client->io, "C (tls): ok"); @@ -179,6 +193,7 @@ int od_fekey(od_client_t *client) int od_fesetup(od_client_t *client) { + od_pooler_t *pooler = client->pooler; so_stream_t *stream = &client->stream; so_stream_reset(stream); int rc; @@ -190,11 +205,17 @@ int od_fesetup(od_client_t *client) if (rc == -1) return -1; rc = od_write(client->io, stream); - return rc; + if (rc == -1) { + od_error(&pooler->od->log, client->io, "C (setup): write error: %s", + machine_error(client->io)); + return -1; + } + return 0; } int od_feready(od_client_t *client) { + od_pooler_t *pooler = client->pooler; so_stream_t *stream = &client->stream; so_stream_reset(stream); int rc; @@ -202,5 +223,10 @@ int od_feready(od_client_t *client) if (rc == -1) return -1; rc = od_write(client->io, stream); - return rc; + if (rc == -1) { + od_error(&pooler->od->log, client->io, "C: write error: %s", + machine_error(client->io)); + return -1; + } + return 0; } diff --git a/core/od_io.h b/core/od_io.h index d9d1c057..2b9eabe1 100644 --- a/core/od_io.h +++ b/core/od_io.h @@ -7,8 +7,8 @@ * PostgreSQL connection pooler and request router. */ -int od_read(machine_io_t, so_stream_t*, int); -int od_write(machine_io_t, so_stream_t*); +int od_read(machine_io_t, so_stream_t*, int); +int od_write(machine_io_t, so_stream_t*); char *od_getpeername(machine_io_t); diff --git a/core/od_router.c b/core/od_router.c index 7c6638f8..5488b7f7 100644 --- a/core/od_router.c +++ b/core/od_router.c @@ -170,10 +170,12 @@ void od_router(void *arg) case OD_RS_ECLIENT_WRITE: if (status == OD_RS_OK) od_log(&pooler->od->log, client->io, - "C: disconnected"); + "C: disconnected: %s", + machine_error(client->io)); else od_log(&pooler->od->log, client->io, - "C: disconnected (read/write error)"); + "C: disconnected (read/write error): %s", + machine_error(client->io)); /* close client connection and reuse server * link in case of client errors and * graceful shutdown */ @@ -183,7 +185,8 @@ void od_router(void *arg) break; case OD_RS_ESERVER_CONFIGURE: od_log(&pooler->od->log, server->io, - "S: disconnected (server configure error)"); + "S: disconnected (server configure error): %s", + machine_error(server->io)); od_feclose(client); if (server) od_beclose(server); @@ -191,7 +194,8 @@ void od_router(void *arg) case OD_RS_ESERVER_READ: case OD_RS_ESERVER_WRITE: od_log(&pooler->od->log, server->io, - "S: disconnected (read/write error)"); + "S: disconnected (read/write error): %s", + machine_error(server->io)); /* close client connection and close server * connection in case of server errors */ od_feclose(client); diff --git a/core/od_router_transaction.c b/core/od_router_transaction.c index 1a3ad5c2..359f2dcc 100644 --- a/core/od_router_transaction.c +++ b/core/od_router_transaction.c @@ -81,7 +81,6 @@ od_router_transaction(od_client_t *client) rc = od_read(client->io, stream, 0); if (rc == -1) return OD_RS_ECLIENT_READ; - type = *stream->s; od_debug(&pooler->od->log, client->io, "C: %c", *stream->s);