Skip to content

Commit

Permalink
refactor: use snprintf and add errors.h module
Browse files Browse the repository at this point in the history
  • Loading branch information
steve-chavez committed Dec 6, 2024
1 parent acfdd76 commit 60a1efa
Show file tree
Hide file tree
Showing 7 changed files with 159 additions and 148 deletions.
3 changes: 2 additions & 1 deletion Makefile
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,8 @@ REGRESS = $(patsubst test/sql/%.sql,%,$(TESTS))
REGRESS_OPTS = --use-existing --inputdir=test

MODULE_big = $(EXTENSION)
OBJS = src/worker.o src/util.o src/core.o src/event.o
SRC = $(wildcard src/*.c)
OBJS = $(patsubst src/%.c, src/%.o, $(SRC))

all: sql/$(EXTENSION)--$(EXTVERSION).sql $(EXTENSION).control

Expand Down
107 changes: 24 additions & 83 deletions src/core.c
Original file line number Diff line number Diff line change
Expand Up @@ -28,9 +28,9 @@
#include <string.h>
#include <inttypes.h>

#include "util.h"
#include "core.h"
#include "event.h"
#include "errors.h"

typedef struct {
int64 id;
Expand All @@ -39,10 +39,6 @@ typedef struct {
int32 timeout_milliseconds;
} CurlData;

typedef struct {
char msg[256];
} curl_timeout_msg;

static size_t
body_cb(void *contents, size_t size, size_t nmemb, void *userp)
{
Expand All @@ -52,6 +48,29 @@ body_cb(void *contents, size_t size, size_t nmemb, void *userp)
return realsize;
}

static struct curl_slist *pg_text_array_to_slist(ArrayType *array,
struct curl_slist *headers) {
ArrayIterator iterator;
Datum value;
bool isnull;
char *hdr;

iterator = array_create_iterator(array, 0, NULL);

while (array_iterate(iterator, &value, &isnull)) {
if (isnull) {
continue;
}

hdr = TextDatumGetCString(value);
CURL_SLIST_APPEND(headers, hdr);
pfree(hdr);
}
array_free_iterator(iterator);

return headers;
}

// We need a different memory context here, as the parent function will have an SPI memory context, which has a shorter lifetime.
static void init_curl_handle(CURLM *curl_mhandle, MemoryContext curl_memctx, int64 id, Datum urlBin, NullableDatum bodyBin, NullableDatum headersBin, Datum methodBin, int32 timeout_milliseconds){
MemoryContext old_ctx = MemoryContextSwitchTo(curl_memctx);
Expand Down Expand Up @@ -171,84 +190,6 @@ void delete_expired_responses(char *ttl, int batch_size){
CommitTransactionCommand();
}


/*
* Show a more detailed error message when a timeout happens, which includes the DNS, TCP/SSL handshake and HTTP request/response time. An example message is like:
*
* "Timeout of 800 ms reached. Total time: 801.159000 ms (DNS time: 73.407000 ms, TCP/SSL handshake time: 677.256000 ms, HTTP Request/Respose time: 50.103000 ms)"
*
* Curl allows to calculate the above by applying substractions on some internal timings. Refer to https://blog.cloudflare.com/a-question-of-timing/ for an explanation of these timings.
*
* There are extra considerations:
*
* - If a step surpasses the request timeout, say the TCP handshake (CURLINFO_CONNECT_TIME), its given timing is 0.
* However the TCP handshake duration can still be determined by using the total time (CURLINFO_TOTAL_TIME).
* We want to show at which phase the timeout occurred.
*
* - If a step is omitted, say an SSL handshake (CURLINFO_APPCONNECT_TIME) on non-HTTPS requests, its given timing is 0.
*
* - The pretransfer time (CURLINFO_PRETRANSFER_TIME) is greater than 0 when the HTTP request step starts.
*/
static curl_timeout_msg detailed_timeout_strerror(CURL *ez_handle, int32 timeout_milliseconds){
double namelookup; CURL_EZ_GETINFO(ez_handle, CURLINFO_NAMELOOKUP_TIME, &namelookup);
double appconnect; CURL_EZ_GETINFO(ez_handle, CURLINFO_APPCONNECT_TIME, &appconnect);
double connect; CURL_EZ_GETINFO(ez_handle, CURLINFO_CONNECT_TIME, &connect);
double pretransfer; CURL_EZ_GETINFO(ez_handle, CURLINFO_PRETRANSFER_TIME, &pretransfer);
double starttransfer; CURL_EZ_GETINFO(ez_handle, CURLINFO_STARTTRANSFER_TIME, &starttransfer);
double total; CURL_EZ_GETINFO(ez_handle, CURLINFO_TOTAL_TIME, &total);

elog(DEBUG2, "The curl timings are time_namelookup: %f, time_connect: %f, time_appconnect: %f, time_pretransfer: %f, time_starttransfer: %f, time_total: %f",
namelookup, connect, appconnect, pretransfer, starttransfer, total);

// Steps at which the request timed out
bool timedout_at_dns = namelookup == 0 && connect == 0; // if DNS time is 0 and no TCP occurred, it timed out at the DNS step
bool timedout_at_handshake = pretransfer == 0; // pretransfer determines if the HTTP step started, if 0 no HTTP ocurred and thus the timeout occurred at TCP or SSL handshake step
bool timedout_at_http = pretransfer > 0; // The HTTP step did start and the timeout occurred here

// Calculate the steps times
double _dns_time =
timedout_at_dns ?
total: // get the total since namelookup will be 0 because of the timeout
timedout_at_handshake ?
namelookup:
timedout_at_http ?
namelookup:
0;

double _handshake_time =
timedout_at_dns ?
0:
timedout_at_handshake ?
total - namelookup: // connect or appconnect will be 0 because of the timeout, get the total - DNS step time
timedout_at_http ?
(connect - namelookup) + // TCP handshake time
(appconnect > 0 ? (appconnect - connect): 0): // SSL handshake time. Prevent a negative here which can happen when no SSL is involved (plain HTTP request) and appconnect is 0
0;

double _http_time =
timedout_at_dns ?
0:
timedout_at_handshake ?
0:
timedout_at_http ?
total - pretransfer:
0;

// convert seconds to milliseconds
double dns_time_ms = _dns_time * 1000;
double handshake_time_ms = _handshake_time * 1000;
double http_time_ms = _http_time * 1000;
double total_time_ms = total * 1000;

// build the error message
curl_timeout_msg result = {.msg = {}};
sprintf(result.msg,
"Timeout of %d ms reached. Total time: %f ms (DNS time: %f ms, TCP/SSL handshake time: %f ms, HTTP Request/Response time: %f ms)",
timeout_milliseconds, total_time_ms, dns_time_ms, handshake_time_ms, http_time_ms
);
return result;
}

static void insert_failure_response(CURL *ez_handle, CURLcode return_code, int64 id, int32 timeout_milliseconds){
StartTransactionCommand();
PushActiveSnapshot(GetTransactionSnapshot());
Expand Down
81 changes: 81 additions & 0 deletions src/errors.c
Original file line number Diff line number Diff line change
@@ -0,0 +1,81 @@
#include <postgres.h>
#include <curl/curl.h>

#include "errors.h"

/*
* Show a more detailed error message when a timeout happens, which includes the DNS, TCP/SSL handshake and HTTP request/response time. An example message is like:
*
* "Timeout of 800 ms reached. Total time: 801.159000 ms (DNS time: 73.407000 ms, TCP/SSL handshake time: 677.256000 ms, HTTP Request/Respose time: 50.103000 ms)"
*
* Curl allows to calculate the above by applying substractions on some internal timings. Refer to https://blog.cloudflare.com/a-question-of-timing/ for an explanation of these timings.
*
* There are extra considerations:
*
* - If a step surpasses the request timeout, say the TCP handshake (CURLINFO_CONNECT_TIME), its given timing is 0.
* However the TCP handshake duration can still be determined by using the total time (CURLINFO_TOTAL_TIME).
* We want to show at which phase the timeout occurred.
*
* - If a step is omitted, say an SSL handshake (CURLINFO_APPCONNECT_TIME) on non-HTTPS requests, its given timing is 0.
*
* - The pretransfer time (CURLINFO_PRETRANSFER_TIME) is greater than 0 when the HTTP request step starts.
*/
curl_timeout_msg detailed_timeout_strerror(CURL *ez_handle, int32 timeout_milliseconds){
double namelookup; CURL_EZ_GETINFO(ez_handle, CURLINFO_NAMELOOKUP_TIME, &namelookup);
double appconnect; CURL_EZ_GETINFO(ez_handle, CURLINFO_APPCONNECT_TIME, &appconnect);
double connect; CURL_EZ_GETINFO(ez_handle, CURLINFO_CONNECT_TIME, &connect);
double pretransfer; CURL_EZ_GETINFO(ez_handle, CURLINFO_PRETRANSFER_TIME, &pretransfer);
double starttransfer; CURL_EZ_GETINFO(ez_handle, CURLINFO_STARTTRANSFER_TIME, &starttransfer);
double total; CURL_EZ_GETINFO(ez_handle, CURLINFO_TOTAL_TIME, &total);

elog(DEBUG2, "The curl timings are time_namelookup: %f, time_connect: %f, time_appconnect: %f, time_pretransfer: %f, time_starttransfer: %f, time_total: %f",
namelookup, connect, appconnect, pretransfer, starttransfer, total);

// Steps at which the request timed out
bool timedout_at_dns = namelookup == 0 && connect == 0; // if DNS time is 0 and no TCP occurred, it timed out at the DNS step
bool timedout_at_handshake = pretransfer == 0; // pretransfer determines if the HTTP step started, if 0 no HTTP ocurred and thus the timeout occurred at TCP or SSL handshake step
bool timedout_at_http = pretransfer > 0; // The HTTP step did start and the timeout occurred here

// Calculate the steps times
double _dns_time =
timedout_at_dns ?
total: // get the total since namelookup will be 0 because of the timeout
timedout_at_handshake ?
namelookup:
timedout_at_http ?
namelookup:
0;

double _handshake_time =
timedout_at_dns ?
0:
timedout_at_handshake ?
total - namelookup: // connect or appconnect will be 0 because of the timeout, get the total - DNS step time
timedout_at_http ?
(connect - namelookup) + // TCP handshake time
(appconnect > 0 ? (appconnect - connect): 0): // SSL handshake time. Prevent a negative here which can happen when no SSL is involved (plain HTTP request) and appconnect is 0
0;

double _http_time =
timedout_at_dns ?
0:
timedout_at_handshake ?
0:
timedout_at_http ?
total - pretransfer:
0;

// convert seconds to milliseconds
double dns_time_ms = _dns_time * 1000;
double handshake_time_ms = _handshake_time * 1000;
double http_time_ms = _http_time * 1000;
double total_time_ms = total * 1000;

// build the error message
curl_timeout_msg result = {.msg = {}};
snprintf(result.msg, CURL_TIMEOUT_MSG_SIZE,
"Timeout of %d ms reached. Total time: %f ms (DNS time: %f ms, TCP/SSL handshake time: %f ms, HTTP Request/Response time: %f ms)",
timeout_milliseconds, total_time_ms, dns_time_ms, handshake_time_ms, http_time_ms
);
return result;
}
51 changes: 51 additions & 0 deletions src/errors.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,51 @@
#ifndef ERRORS_H
#define ERRORS_H

#define CURL_EZ_SETOPT(hdl, opt, prm) \
do { \
if (curl_easy_setopt(hdl, opt, prm) != CURLE_OK) \
ereport(ERROR, errmsg("Could not curl_easy_setopt(%s)", #opt)); \
} while (0)

#define CURL_EZ_GETINFO(hdl, opt, prm) \
do { \
if (curl_easy_getinfo(hdl, opt, prm) != CURLE_OK) \
ereport(ERROR, errmsg("Could not curl_easy_getinfo(%s)", #opt)); \
} while (0)

#define CURL_MULTI_SETOPT(hdl, opt, prm) \
do { \
if (curl_multi_setopt(hdl, opt, prm) != CURLM_OK) \
ereport(ERROR, errmsg("Could not curl_multi_setopt(%s)", #opt)); \
} while (0)

#define CURL_SLIST_APPEND(list, str) \
do { \
struct curl_slist *new_list = curl_slist_append(list, str); \
if (new_list == NULL) \
ereport(ERROR, errmsg("curl_slist_append returned NULL")); \
list = new_list; \
} while (0)

#define EREPORT_NULL_ATTR(tupIsNull, attr) \
do { \
if (tupIsNull) \
ereport(ERROR, errmsg("%s cannot be null", #attr)); \
} while (0)

#define EREPORT_MULTI(multi_call) \
do { \
CURLMcode code = multi_call; \
if (code != CURLM_OK) \
ereport(ERROR, errmsg("%s failed with %s", #multi_call, curl_multi_strerror(code))); \
} while (0)

#define CURL_TIMEOUT_MSG_SIZE 256

typedef struct {
char msg[CURL_TIMEOUT_MSG_SIZE];
} curl_timeout_msg;

curl_timeout_msg detailed_timeout_strerror(CURL *ez_handle, int32 timeout_milliseconds);

#endif
22 changes: 0 additions & 22 deletions src/util.c
Original file line number Diff line number Diff line change
Expand Up @@ -66,25 +66,3 @@ Datum _encode_url_with_params_array(PG_FUNCTION_ARGS) {
PG_RETURN_TEXT_P(cstring_to_text(full_url));
}

struct curl_slist *pg_text_array_to_slist(ArrayType *array,
struct curl_slist *headers) {
ArrayIterator iterator;
Datum value;
bool isnull;
char *hdr;

iterator = array_create_iterator(array, 0, NULL);

while (array_iterate(iterator, &value, &isnull)) {
if (isnull) {
continue;
}

hdr = TextDatumGetCString(value);
CURL_SLIST_APPEND(headers, hdr);
pfree(hdr);
}
array_free_iterator(iterator);

return headers;
}
42 changes: 0 additions & 42 deletions src/util.h
Original file line number Diff line number Diff line change
@@ -1,46 +1,4 @@
#ifndef UTIL_H
#define UTIL_H

#define CURL_EZ_SETOPT(hdl, opt, prm) \
do { \
if (curl_easy_setopt(hdl, opt, prm) != CURLE_OK) \
ereport(ERROR, errmsg("Could not curl_easy_setopt(%s)", #opt)); \
} while (0)

#define CURL_EZ_GETINFO(hdl, opt, prm) \
do { \
if (curl_easy_getinfo(hdl, opt, prm) != CURLE_OK) \
ereport(ERROR, errmsg("Could not curl_easy_getinfo(%s)", #opt)); \
} while (0)

#define CURL_MULTI_SETOPT(hdl, opt, prm) \
do { \
if (curl_multi_setopt(hdl, opt, prm) != CURLM_OK) \
ereport(ERROR, errmsg("Could not curl_multi_setopt(%s)", #opt)); \
} while (0)

#define CURL_SLIST_APPEND(list, str) \
do { \
struct curl_slist *new_list = curl_slist_append(list, str); \
if (new_list == NULL) \
ereport(ERROR, errmsg("curl_slist_append returned NULL")); \
list = new_list; \
} while (0)

#define EREPORT_NULL_ATTR(tupIsNull, attr) \
do { \
if (tupIsNull) \
ereport(ERROR, errmsg("%s cannot be null", #attr)); \
} while (0)

#define EREPORT_MULTI(multi_call) \
do { \
CURLMcode code = multi_call; \
if (code != CURLM_OK) \
ereport(ERROR, errmsg("%s failed with %s", #multi_call, curl_multi_strerror(code))); \
} while (0)

extern struct curl_slist *pg_text_array_to_slist(ArrayType *array,
struct curl_slist *headers);

#endif
1 change: 1 addition & 0 deletions src/worker.c
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@
#include <storage/shmem.h>

#include "util.h"
#include "errors.h"
#include "core.h"
#include "event.h"

Expand Down

0 comments on commit 60a1efa

Please sign in to comment.