Report BLE frame gaps and preserve BlueZ I/O errors
This commit is contained in:
1 parent
8811276ca8
commit
de6e2ada0c
3 files changed
+42
-13
No files matched your search
+18
-4
@@ -137,6 +137,11 @@ static void notify_read(int fd, void* arg) {
|
||||
struct bluez_link* l = arg;
|
||||
uint8_t data[8]; ssize_t n = recv(fd, data, sizeof(data), MSG_DONTWAIT);
|
||||
if (n < 0 && (errno == EAGAIN || errno == EINTR)) return;
|
||||
if (n < 0) {
|
||||
DEBUG_ERROR(CAT, "BLE notification socket read failed link=%llu fd=%d errno=%d: %s",
|
||||
(unsigned long long)l->id, fd, errno, strerror(errno));
|
||||
link_error(l, "notification socket read failed"); return;
|
||||
}
|
||||
if (!n) { link_error(l, "notification subscription closed"); return; }
|
||||
if (n != 1 || data[0] != 1 || fd != l->fd[BLE_CHANNEL_INVITE] || l->channel != BLE_CHANNEL_INVITE ||
|
||||
!l->sending || l->buffered) {
|
||||
@@ -182,7 +187,9 @@ static int options(sd_bus_message* m, const char** device, uint16_t* mtu, uint16
|
||||
}
|
||||
static int reject(sd_bus_message* m, const char* reason) {
|
||||
DEBUG_WARN(CAT, "BLE BlueZ request rejected: %s", reason);
|
||||
return sd_bus_reply_method_errorf(m, "org.bluez.Error.Failed", "%s", reason);
|
||||
int r = sd_bus_reply_method_errorf(m, "org.bluez.Error.Failed", "%s", reason);
|
||||
if (r < 0) DEBUG_ERROR(CAT, "BLE BlueZ error reply failed: %s", strerror(-r));
|
||||
return r;
|
||||
}
|
||||
static int write_value(sd_bus_message* m, void* arg, sd_bus_error* error) {
|
||||
(void)error; struct characteristic* ctx = arg; struct ble_backend* b = ctx->backend;
|
||||
@@ -195,7 +202,9 @@ static int write_value(sd_bus_message* m, void* arg, sd_bus_error* error) {
|
||||
ble_link_id id = l->id;
|
||||
ble_backend_received(b->owner, id, ctx->tx == 2 ? BLE_CHANNEL_INVITE : BLE_CHANNEL_DATA, data, len);
|
||||
if (!find_link(b, id)) return reject(m, "session rejected");
|
||||
return sd_bus_reply_method_return(m, "");
|
||||
int r = sd_bus_reply_method_return(m, "");
|
||||
if (r < 0) DEBUG_ERROR(CAT, "BLE BlueZ WriteValue reply failed link=%llu: %s", (unsigned long long)id, strerror(-r));
|
||||
return r;
|
||||
}
|
||||
static int acquire_notify(sd_bus_message* m, void* arg, sd_bus_error* error) {
|
||||
(void)error; struct characteristic* ctx = arg; struct ble_backend* b = ctx->backend;
|
||||
@@ -206,13 +215,18 @@ static int acquire_notify(sd_bus_message* m, void* arg, sd_bus_error* error) {
|
||||
int channel = ctx->tx == 2 ? BLE_CHANNEL_INVITE : BLE_CHANNEL_DATA;
|
||||
if (!l || l->fd[channel] >= 0) return reject(m, "subscription unavailable");
|
||||
int pair[2];
|
||||
if (socketpair(AF_UNIX, SOCK_SEQPACKET | SOCK_NONBLOCK | SOCK_CLOEXEC, 0, pair) < 0) return reject(m, "socketpair failed");
|
||||
if (socketpair(AF_UNIX, SOCK_SEQPACKET | SOCK_NONBLOCK | SOCK_CLOEXEC, 0, pair) < 0) {
|
||||
DEBUG_ERROR(CAT, "BLE notification socketpair failed: %s", strerror(errno)); return reject(m, "socketpair failed");
|
||||
}
|
||||
l->fd[channel] = pair[0]; l->mtu = mtu;
|
||||
l->io[channel] = uasync_add_socket(b->ua, l->fd[channel], notify_read, notify_write, notify_read, "ble_notify", l);
|
||||
if (!l->io[channel]) { close(pair[0]); close(pair[1]); l->fd[channel] = -1; return reject(m, "fd registration failed"); }
|
||||
uasync_set_socket_write(b->ua, l->io[channel], 0);
|
||||
int r = sd_bus_reply_method_return(m, "hq", pair[1], mtu); close(pair[1]);
|
||||
if (r < 0) { link_error(l, "AcquireNotify reply failed"); return r; }
|
||||
if (r < 0) {
|
||||
DEBUG_ERROR(CAT, "BLE BlueZ AcquireNotify reply failed link=%llu: %s", (unsigned long long)l->id, strerror(-r));
|
||||
link_error(l, "AcquireNotify reply failed"); return r;
|
||||
}
|
||||
DEBUG_DEBUG(CAT, "BLE BlueZ subscription link=%llu channel=%d mode=%s mtu=%u",
|
||||
(unsigned long long)l->id, channel, channel == BLE_CHANNEL_DATA ? "notification" : "indication", mtu);
|
||||
if (l->fd[0] >= 0 && l->fd[1] >= 0 && !l->opened) {
|
||||
|
||||
+23
-9
@@ -12,14 +12,14 @@
|
||||
#define STATS_US 5000000ULL
|
||||
struct ble_stats {
|
||||
uint64_t since, tx_bytes, rx_bytes, wait_us, max_wait_us;
|
||||
unsigned tx_frames, rx_frames, fragments, dropped;
|
||||
unsigned tx_frames, rx_frames, fragments, dropped, missing;
|
||||
};
|
||||
struct ble_channel_state {
|
||||
struct ll_queue *tx, *rx;
|
||||
struct ll_entry* current;
|
||||
uint64_t rx_deadline;
|
||||
uint16_t sequence, offset, rx_sequence, rx_size, rx_offset, dropped_sequence;
|
||||
int blocked, dropping;
|
||||
uint16_t sequence, offset, rx_sequence, rx_size, rx_offset, dropped_sequence, rx_next;
|
||||
int blocked, dropping, rx_seen;
|
||||
uint8_t assembly[BLE_FRAME_MAX];
|
||||
};
|
||||
struct ble_connection {
|
||||
@@ -69,10 +69,10 @@ static void log_stats(struct ble_connection* c, uint64_t now) {
|
||||
uint64_t elapsed = now > s->since ? now - s->since : 1;
|
||||
if (s->tx_frames || s->rx_frames || s->fragments || s->dropped || c->pending) {
|
||||
DEBUG_DEBUG(CAT, "BLE traffic link=%llu outgoing=%d elapsed_ms=%llu TX_Bps=%llu RX_Bps=%llu TX_frames=%u RX_frames=%u "
|
||||
"fragments=%u drops=%u wait_avg_us=%llu wait_max_us=%llu DATA_queue=%d INVITE_queue=%d pending_ms=%llu",
|
||||
"fragments=%u drops=%u missing=%u wait_avg_us=%llu wait_max_us=%llu DATA_queue=%d INVITE_queue=%d pending_ms=%llu",
|
||||
(unsigned long long)c->id, c->outgoing, (unsigned long long)(elapsed / 1000),
|
||||
(unsigned long long)(s->tx_bytes * 1000000 / elapsed), (unsigned long long)(s->rx_bytes * 1000000 / elapsed),
|
||||
s->tx_frames, s->rx_frames, s->fragments, s->dropped,
|
||||
s->tx_frames, s->rx_frames, s->fragments, s->dropped, s->missing,
|
||||
(unsigned long long)(s->fragments ? s->wait_us / s->fragments : 0), (unsigned long long)s->max_wait_us,
|
||||
queue_entry_count(c->channels[BLE_CHANNEL_DATA].tx) + !!c->channels[BLE_CHANNEL_DATA].current,
|
||||
queue_entry_count(c->channels[BLE_CHANNEL_INVITE].tx) + !!c->channels[BLE_CHANNEL_INVITE].current,
|
||||
@@ -330,7 +330,8 @@ void ble_backend_received(struct ble_transport* t, ble_link_id id, enum ble_chan
|
||||
pump(t, c); return;
|
||||
}
|
||||
if (!c->ready || len <= HEADER || len > c->capacity || data[0] != FRAME) {
|
||||
DEBUG_WARN(CAT, "BLE invalid value link=%llu bytes=%zu ready=%d", (unsigned long long)id, len, c->ready);
|
||||
DEBUG_WARN(CAT, "BLE invalid value link=%llu channel=%d bytes=%zu capacity=%u ready=%d type=%u",
|
||||
(unsigned long long)id, channel, len, c->capacity, c->ready, len ? data[0] : 0);
|
||||
c->stats.dropped++;
|
||||
ch->rx_size = ch->rx_offset = 0; return;
|
||||
}
|
||||
@@ -342,7 +343,19 @@ void ble_backend_received(struct ble_transport* t, ble_link_id id, enum ble_chan
|
||||
if (!offset) ch->dropping = 0;
|
||||
if (!total || total > BLE_FRAME_MAX || offset > total || n > (size_t)(total - offset)) goto invalid;
|
||||
if (!offset) {
|
||||
if (ch->rx_size) { DEBUG_WARN(CAT, "BLE incomplete frame replaced link=%llu", (unsigned long long)id); c->stats.dropped++; }
|
||||
uint16_t expected = ch->rx_seen ? ch->rx_next : 1;
|
||||
if (seq != expected) {
|
||||
uint16_t gap = (uint16_t)(seq - expected);
|
||||
DEBUG_WARN(CAT, "BLE RX sequence gap link=%llu channel=%d expected=%u received=%u missing=%u",
|
||||
(unsigned long long)id, channel, expected, seq, gap < 0x8000 ? gap : 0);
|
||||
if (gap < 0x8000) c->stats.missing += gap;
|
||||
}
|
||||
ch->rx_seen = 1; ch->rx_next = (uint16_t)(seq + 1);
|
||||
if (ch->rx_size) {
|
||||
DEBUG_WARN(CAT, "BLE incomplete frame replaced link=%llu channel=%d seq=%u received=%u total=%u next=%u",
|
||||
(unsigned long long)id, channel, ch->rx_sequence, ch->rx_offset, ch->rx_size, seq);
|
||||
c->stats.dropped++;
|
||||
}
|
||||
ch->rx_sequence = seq; ch->rx_size = total; ch->rx_offset = 0; ch->rx_deadline = get_time_us() + DEADLINE_US;
|
||||
}
|
||||
if (ch->rx_size != total || ch->rx_sequence != seq || ch->rx_offset != offset) goto invalid;
|
||||
@@ -354,7 +367,7 @@ void ble_backend_received(struct ble_transport* t, ble_link_id id, enum ble_chan
|
||||
c->stats.dropped++; return;
|
||||
}
|
||||
struct ll_entry* entry = ll_alloc_lldgram(total);
|
||||
if (!entry) { DEBUG_ERROR(CAT, "BLE RX allocation failed bytes=%u", total); return; }
|
||||
if (!entry) { DEBUG_ERROR(CAT, "BLE RX allocation failed bytes=%u", total); c->stats.dropped++; return; }
|
||||
memcpy(entry->dgram, ch->assembly, total); entry->len = total;
|
||||
if (queue_data_put(ch->rx, entry) != 0) { DEBUG_ERROR(CAT, "BLE RX queue invariant failed"); return; }
|
||||
c->stats.rx_bytes += total; c->stats.rx_frames++;
|
||||
@@ -374,7 +387,8 @@ invalid:
|
||||
void ble_backend_sent(struct ble_transport* t, ble_link_id id, int success) {
|
||||
struct ble_connection* c = lookup(t, id);
|
||||
if (!c) return;
|
||||
if (!success || !c->pending) { DEBUG_WARN(CAT, "BLE send completion failed link=%llu", (unsigned long long)id);
|
||||
if (!success || !c->pending) { DEBUG_WARN(CAT, "BLE send completion failed link=%llu success=%d pending=%d channel=%d bytes=%u",
|
||||
(unsigned long long)id, success, c->pending, c->pending_channel, c->pending_bytes);
|
||||
close_link(t, c, "send failed"); return; }
|
||||
enum ble_channel channel = c->pending_channel;
|
||||
uint64_t waited = get_time_us() - c->submitted;
|
||||
|
||||
@@ -76,6 +76,7 @@ int main(int argc, char** argv) {
|
||||
instance = utun_instance_create_from_str(ua, config);
|
||||
if (!instance) { uasync_destroy(ua, 0); return 1; }
|
||||
if (getenv("UTUN_TEST_DEBUG")) {
|
||||
debug_set_category_level(DEBUG_CATEGORY_DEBUG, DEBUG_LEVEL_TRACE);
|
||||
debug_set_category_level(DEBUG_CATEGORY_ETCP, DEBUG_LEVEL_TRACE);
|
||||
debug_set_category_level(DEBUG_CATEGORY_CONNECTION, DEBUG_LEVEL_DEBUG);
|
||||
}
|
||||
|
||||
Reference in new issue
Block a user