void
read_timeout_cb(rw_request* rw)
{
if (! rw->from.any) {
return; // lost race against dup-res callback
}
switch (rw->origin) {
case FROM_CLIENT:
as_msg_send_reply(rw->from.proto_fd_h, AS_ERR_TIMEOUT, 0, 0, NULL, NULL,
0, rw->rsv.ns, rw_request_trid(rw));
// Timeouts aren't included in histograms.
client_read_update_stats(rw->rsv.ns, AS_ERR_TIMEOUT);
break;
case FROM_PROXY:
if (rw_request_is_batch_sub(rw)) {
from_proxy_batch_sub_read_update_stats(rw->rsv.ns, AS_ERR_TIMEOUT);
}
else {
from_proxy_read_update_stats(rw->rsv.ns, AS_ERR_TIMEOUT);
}
break;
case FROM_BATCH:
as_batch_add_error(rw->from.batch_shared, rw->from_data.batch_index,
AS_ERR_TIMEOUT);
// Timeouts aren't included in histograms.
batch_sub_read_update_stats(rw->rsv.ns, AS_ERR_TIMEOUT);
break;
default:
cf_crash(AS_RW, "unexpected transaction origin %u", rw->origin);
break;
}
rw->from.any = NULL; // inform other callback it lost the race
}
void
as_transaction_error(as_transaction* tr, uint32_t error_code)
{
if (tr->proto_fd_h) {
if (tr->batch_shared) {
as_batch_add_error(tr->batch_shared, tr->batch_index, error_code);
// Clear this transaction's msgp so calling code does not free it.
tr->msgp = 0;
}
else {
as_msg_send_reply(tr->proto_fd_h, error_code, 0, 0, NULL, NULL, 0, NULL, NULL, as_transaction_trid(tr), NULL);
tr->proto_fd_h = 0;
MICROBENCHMARK_HIST_INSERT_P(error_hist);
cf_atomic_int_incr(&g_config.err_tsvc_requests);
if (error_code == AS_PROTO_RESULT_FAIL_TIMEOUT) {
cf_atomic_int_incr(&g_config.err_tsvc_requests_timeout);
}
}
}
else if (tr->proxy_msg) {
as_proxy_send_response(tr->proxy_node, tr->proxy_msg, error_code, 0, 0, NULL, NULL, 0, NULL, as_transaction_trid(tr), NULL);
tr->proxy_msg = NULL;
}
else if (tr->udata.req_udata) {
if (udf_rw_needcomplete(tr)) {
udf_rw_complete(tr, error_code, __FILE__,__LINE__);
}
}
}
// TODO - deprecate this when swap is moved out into thr_demarshal.c!
void
as_transaction_error_unswapped(as_transaction* tr, uint32_t error_code)
{
if (tr->batch_shared) {
as_batch_add_error(tr->batch_shared, tr->batch_index, error_code);
// Clear this transaction's msgp so calling code does not free it.
tr->msgp = 0;
}
else {
as_msg_send_reply(tr->proto_fd_h, error_code, 0, 0, NULL, NULL, 0, NULL, NULL, 0, NULL);
tr->proto_fd_h = 0;
MICROBENCHMARK_HIST_INSERT_P(error_hist);
cf_atomic_int_incr(&g_config.err_tsvc_requests);
if (error_code == AS_PROTO_RESULT_FAIL_TIMEOUT) {
cf_atomic_int_incr(&g_config.err_tsvc_requests_timeout);
}
}
}
// Incoming messages start here.
// - Could get a request that we need to service.
// - Could get a response to one of our requests - need to find the request and
// send the real response to the remote end.
int
proxy_msg_fn(cf_node id, msg *m, void *udata)
{
int rv;
if (cf_rc_count((void*)m) == 0) {
cf_debug(AS_PROXY, " proxy_msg_fn was given a refcount 0 message! Someone has been naugty %p", m);
return -1;
}
uint32_t op = 99999;
msg_get_uint32(m, PROXY_FIELD_OP, &op);
uint32_t transaction_id = 0;
msg_get_uint32(m, PROXY_FIELD_TID, &transaction_id);
cf_detail(AS_PROXY, "received proxy message: tid %d type %d from %"PRIx64, transaction_id, op, id);
switch (op) {
case PROXY_OP_REQUEST:
{
cf_atomic_int_incr(&g_config.proxy_action);
#ifdef DEBUG
cf_debug(AS_PROXY, "Proxy_msg: received request");
#ifdef DEBUG_VERBOSE
msg_dump(m, "incoming proxy msg");
#endif
#endif
cf_digest *key;
size_t sz = 0;
if (0 != msg_get_buf(m, PROXY_FIELD_DIGEST, (byte **) &key, &sz, MSG_GET_DIRECT)) {
cf_info(AS_PROXY, "proxy msg function: no digest, problem");
as_fabric_msg_put(m);
return 0;
}
cl_msg *msgp;
size_t as_msg_sz = 0;
if (0 != msg_get_buf(m, PROXY_FIELD_AS_PROTO, (byte **) &msgp, &as_msg_sz, MSG_GET_COPY_MALLOC)) {
cf_info(AS_PROXY, "proxy msg function: no as msg, problem");
as_fabric_msg_put(m);
return 0;
}
uint64_t cluster_key = 0;
if (0 != msg_get_uint64(m, PROXY_FIELD_CLUSTER_KEY, &cluster_key)) {
cf_info(AS_PROXY, "proxy msg function: no cluster key, problem");
as_fabric_msg_put(m);
return 0;
}
// This is allowed to fail - this is a new field, and gets defaulted
// to 0 if it doesn't exist.
uint32_t timeout_ms = 0;
msg_get_uint32(m, PROXY_FIELD_TIMEOUT_MS, &timeout_ms);
// cf_info(AS_PROXY, "proxy msg: received timeout_ms of %d",timeout_ms);
// Put the as_msg on the normal queue for processing.
// INIT_TR
as_transaction tr;
as_transaction_init(&tr, key, msgp);
tr.incoming_cluster_key = cluster_key;
tr.end_time = (timeout_ms != 0) ? ((uint64_t)timeout_ms * 1000000) + tr.start_time : 0;
tr.proxy_node = id;
tr.proxy_msg = m;
// Check here if this is shipped op.
uint32_t info = 0;
msg_get_uint32(m, PROXY_FIELD_INFO, &info);
if (info & PROXY_INFO_SHIPPED_OP) {
tr.flag |= AS_TRANSACTION_FLAG_SHIPPED_OP;
cf_detail_digest(AS_PROXY, &tr.keyd, "SHIPPED_OP WINNER Operation Received");
} else {
cf_detail_digest(AS_PROXY, &tr.keyd, "Received Proxy Request digest tid(%d)", tr.trid);
}
MICROBENCHMARK_RESET();
thr_tsvc_enqueue(&tr);
}
break;
case PROXY_OP_RESPONSE:
{
#ifdef DEBUG
// Got the response from the actual endpoint.
cf_debug(AS_PROXY, " proxy: received response! tid %d node %"PRIx64, transaction_id, id);
#ifdef DEBUG_VERBOSE
msg_dump(m, "incoming proxy response");
#endif
#endif
// Look up the element.
proxy_request pr;
bool free_msg = true;
if (SHASH_OK == shash_get_and_delete(g_proxy_hash, &transaction_id, &pr)) {
// Found the element (sometimes we get two acks so it's OK for
// an ack to not find the transaction).
if (pr.wr) {
as_proxy_shipop_response_hdlr(m, &pr, &free_msg);
} else {
as_proto *proto;
size_t proto_sz;
if (0 != msg_get_buf(m, PROXY_FIELD_AS_PROTO, (byte **) &proto, &proto_sz, MSG_GET_DIRECT)) {
cf_info(AS_PROXY, "msg get buf failed!");
}
#ifdef DEBUG_VERBOSE
cf_debug(AS_PROXY, "proxy: sending proto response: ptr %p sz %"PRIu64" %d", proto, proto_sz, pr.fd);
for (size_t _i = 0; _i < proto_sz; _i++) {
fprintf(stderr, " %x", ((byte *)proto)[_i]);
if (_i % 16 == 15) {
fprintf(stderr, "\n");
}
}
#endif
#ifdef EXTRA_CHECKS
as_proto proto_copy = *proto;
as_proto_swap(&proto_copy);
if (proto_copy.sz + 8 != proto_sz) {
cf_info(AS_PROXY, "BONE BONE BONE!!!");
cf_info(AS_PROXY, "proto sz: %"PRIu64" sz %u", (uint64_t) proto_copy.sz, proto_sz);
}
#endif
// Write to the file descriptor.
cf_detail(AS_PROXY, "direct write fd %d", pr.fd_h->fd);
cf_assert(pr.fd_h->fd, AS_PROXY, CF_WARNING, "attempted write to fd 0");
if (pr.batch_shared) {
cf_digest* digest;
size_t digest_sz = 0;
if (msg_get_buf(pr.fab_msg, PROXY_FIELD_DIGEST, (byte **)&digest, &digest_sz, MSG_GET_DIRECT) == 0) {
as_batch_add_proxy_result(pr.batch_shared, pr.batch_index, digest, (cl_msg*)proto, proto_sz);
as_proxy_set_stat_counters(0);
}
else {
cf_warning(AS_PROXY, "Failed to find batch proxy digest %u", transaction_id);
as_batch_add_error(pr.batch_shared, pr.batch_index, AS_PROTO_RESULT_FAIL_UNKNOWN);
as_proxy_set_stat_counters(-1);
}
cf_hist_track_insert_data_point(g_config.px_hist, pr.start_time);
}
else {
size_t pos = 0;
while (pos < proto_sz) {
rv = send(pr.fd_h->fd, (((uint8_t *)proto) + pos), proto_sz - pos, MSG_NOSIGNAL);
if (rv > 0) {
pos += rv;
}
else if (rv < 0) {
if (errno != EWOULDBLOCK) {
// Common message when a client aborts.
cf_debug(AS_PROTO, "protocol proxy write fail: fd %d sz %d pos %d rv %d errno %d", pr.fd_h->fd, proto_sz, pos, rv, errno);
shutdown(pr.fd_h->fd, SHUT_RDWR);
as_proxy_set_stat_counters(-1);
goto SendFin;
}
usleep(1); // yield
}
else {
cf_info(AS_PROTO, "protocol write fail zero return: fd %d sz %d pos %d ", pr.fd_h->fd, proto_sz, pos);
shutdown(pr.fd_h->fd, SHUT_RDWR);
as_proxy_set_stat_counters(-1);
goto SendFin;
}
}
as_proxy_set_stat_counters(0);
SendFin:
cf_hist_track_insert_data_point(g_config.px_hist, pr.start_time);
// Return the fabric message or the direct file descriptor -
// after write and complete.
pr.fd_h->t_inprogress = false;
AS_RELEASE_FILE_HANDLE(pr.fd_h);
pr.fd_h = 0;
}
as_fabric_msg_put(pr.fab_msg);
pr.fab_msg = 0;
}
}
else {
cf_debug(AS_PROXY, "proxy: received result but no transaction, tid %d", transaction_id);
as_proxy_set_stat_counters(-1);
}
if (free_msg) {
as_fabric_msg_put(m);
}
}
break;
case PROXY_OP_REDIRECT:
{
// Sometimes the destination we proxied a request to isn't able to
// satisfy it (for example, their copy of the partition in question
// might be desync).
cf_node new_dst = 0;
msg_get_uint64(m, PROXY_FIELD_REDIRECT, &new_dst);
cf_detail(AS_PROXY, "proxy redirect message: transaction %d to node %"PRIx64, transaction_id, new_dst);
// Look in the proxy retransmit hash for the tid.
proxy_request *pr;
pthread_mutex_t *pr_lock;
int r = 0;
if (0 != (r = shash_get_vlock(g_proxy_hash, &transaction_id, (void **)&pr, &pr_lock))) {
cf_debug(AS_PROXY, "redirect: could not find transaction %d", transaction_id);
as_fabric_msg_put(m);
return -1;
}
if (g_config.self_node == new_dst) {
// Although we don't know we're the final destination, undo the
// proxy-nature and put back on the main queue. Dangerous, as it
// leaves open the possibility of a looping message.
cf_digest *key;
size_t sz = 0;
if (0 != msg_get_buf(pr->fab_msg, PROXY_FIELD_DIGEST, (byte **) &key, &sz, MSG_GET_DIRECT)) {
cf_warning(AS_PROXY, "op_redirect: proxy msg function: no digest, problem");
pthread_mutex_unlock(pr_lock);
as_fabric_msg_put(m);
return -1;
}
cl_msg *msgp;
sz = 0;
if (0 != msg_get_buf(pr->fab_msg, PROXY_FIELD_AS_PROTO, (byte **) &msgp, &sz, MSG_GET_COPY_MALLOC)) {
cf_warning(AS_PROXY, "op_redirect: proxy msg function: no as proto, problem");
pthread_mutex_unlock(pr_lock);
as_fabric_msg_put(m);
return -1;
}
// Put the as_msg on the normal queue for processing.
// INIT_TR
as_transaction tr;
as_transaction_init(&tr, key, msgp);
tr.start_time = pr->start_time; // start time
tr.end_time = pr->end_time;
tr.proto_fd_h = pr->fd_h;
tr.batch_shared = pr->batch_shared;
tr.batch_index = pr->batch_index;
MICROBENCHMARK_RESET();
thr_tsvc_enqueue(&tr);
as_fabric_msg_put(pr->fab_msg);
shash_delete_lockfree(g_proxy_hash, &transaction_id);
}
else {
// Change the destination, update the retransmit time.
pr->dest = new_dst;
pr->xmit_ms = cf_getms() + 1;
// Send it.
msg_incr_ref(pr->fab_msg);
if (0 != (rv = as_fabric_send(pr->dest, pr->fab_msg, AS_FABRIC_PRIORITY_MEDIUM))) {
cf_debug(AS_PROXY, "redirect: change destination: %"PRIx64" send error %d", pr->dest, rv);
as_fabric_msg_put(pr->fab_msg);
}
}
pthread_mutex_unlock(pr_lock);
}
as_fabric_msg_put(m);
break;
default:
cf_debug(AS_PROXY, "proxy_msg_fn: received unknown, unsupported message %d from remote endpoint", op);
msg_dump(m, "proxy received unknown msg");
as_fabric_msg_put(m);
break;
} // end switch
return 0;
} // end proxy_msg_fn()
