From 838e7f1bb26d93e11bd0a66ebc7790c1265c0350 Mon Sep 17 00:00:00 2001
From: Matthias Ringwald <matthias@ringwald.ch>
Date: Thu, 14 Jan 2016 11:41:40 +0100
Subject: [PATCH] log warning if posix h4 read/write takes longer than 10 ms

---
 platform/posix/src/hci_transport_h4_posix.c | 16 ++++++++++++++++
 1 file changed, 16 insertions(+)

diff --git a/platform/posix/src/hci_transport_h4_posix.c b/platform/posix/src/hci_transport_h4_posix.c
index 82e6bce97..db8b12c2a 100644
--- a/platform/posix/src/hci_transport_h4_posix.c
+++ b/platform/posix/src/hci_transport_h4_posix.c
@@ -222,6 +222,8 @@ static int h4_send_packet(uint8_t packet_type, uint8_t * packet, int size){
     if (hci_transport_h4->ds == NULL) return -1;
     if (hci_transport_h4->uart_fd == 0) return -1;
 
+    uint32_t start = run_loop_get_time_ms();
+
     // store packet type before actual data and increase size
     char *data = (char*) packet;
     size++;
@@ -230,12 +232,19 @@ static int h4_send_packet(uint8_t packet_type, uint8_t * packet, int size){
     while (size > 0) {
         int bytes_written = write(hci_transport_h4->uart_fd, data, size);
         if (bytes_written < 0) {
+            log_info("usleep(5000)");
             usleep(5000);
             continue;
         }
         data += bytes_written;
         size -= bytes_written;
     }
+
+    uint32_t end = run_loop_get_time_ms();
+    if (end - start > 10){
+        log_info("h4_send_packet: write took %u ms", end - start);
+    }
+
     return 0;
 }
 
@@ -305,6 +314,8 @@ static int h4_process(struct data_source *ds) {
     if (hci_transport_h4->uart_fd == 0) return -1;
 
     int read_now = bytes_to_read;
+
+    uint32_t start = run_loop_get_time_ms();
     
     // read up to bytes_to_read data in
     ssize_t bytes_read = read(hci_transport_h4->uart_fd, &hci_packet[read_pos], read_now);
@@ -312,6 +323,11 @@ static int h4_process(struct data_source *ds) {
     if (bytes_read < 0) {
         return bytes_read;
     }
+
+    uint32_t end = run_loop_get_time_ms();
+    if (end - start > 10){
+        log_info("h4_process: read took %u ms", end - start);
+    }
     
     bytes_to_read -= bytes_read;
     read_pos      += bytes_read;