Add NFC snoop logging to log all NCI communication

Adds ring buffer mechanism to store recent NCI traffic.
This buffer is then dumped into the bugreport for further debugging.

Bug: 63636926
Test: dumpsys nfc
Change-Id: I65e6e0268f70cf959f7d510dbd4cdc625d01e4d0
Signed-off-by: Ruchi Kandoi <kandoiruchi@google.com>
(cherry picked from commit dc56bd6a50442f2f1b09a1c558751c44ea363710)

8 files changed, 432 insertions, 0 deletions

diff --git a/src/Android.bp b/src/Android.bp
index 669d63c..39d3007 100644
--- a/src/Android.bp
+++ b/src/Android.bp
@@ -12,6 +12,7 @@ cc_library_shared {
         "libhardware",
         "libmetricslogger",
         "libpower",
+        "libz",
 
         // Treble configuration
         "libhidlbase",
@@ -55,6 +56,7 @@ cc_library_shared {
         "nfc/tags/*.c",
         "adaptation/*.c",
         "adaptation/*.cpp",
+        "adaptation/*.cc",
         "gki/common/*.c",
         "gki/ulinux/*.c",
         "nfca_version.c",
diff --git a/src/adaptation/NfcAdaptation.cpp b/src/adaptation/NfcAdaptation.cpp
index 4194ff6..c09339c 100644
--- a/src/adaptation/NfcAdaptation.cpp
+++ b/src/adaptation/NfcAdaptation.cpp
@@ -22,6 +22,9 @@
 #include <hwbinder/ProcessState.h>
 #include <pthread.h>
 #include "NfcAdaptation.h"
+#include "debug_nfcsnoop.h"
+#include "nfc_target.h"
+
 extern "C" {
 #include "gki.h"
 #include "nfa_api.h"
@@ -227,6 +230,7 @@ void NfcAdaptation::Initialize() {
   mHalCallback = NULL;
   memset(&mHalEntryFuncs, 0, sizeof(mHalEntryFuncs));
   InitializeHalDeviceContext();
+  debug_nfcsnoop_init();
   ALOGD("%s: exit", func);
 }
 
@@ -257,6 +261,17 @@ void NfcAdaptation::Finalize() {
 
 /*******************************************************************************
 **
+** Function:    NfcAdaptation::Dump
+**
+** Description: Native support for dumpsys function.
+**
+** Returns:     None.
+**
+*******************************************************************************/
+void NfcAdaptation::Dump(int fd) { debug_nfcsnoop_dump(fd); }
+
+/*******************************************************************************
+**
 ** Function:    NfcAdaptation::signal()
 **
 ** Description: signal the CondVar to release the thread that is waiting
diff --git a/src/adaptation/debug_nfcsnoop.cc b/src/adaptation/debug_nfcsnoop.cc
new file mode 100644
index 0000000..b7229d6
--- /dev/null
+++ b/src/adaptation/debug_nfcsnoop.cc
@@ -0,0 +1,182 @@
+/******************************************************************************
+ *
+ *  Copyright (C) 2017 Google Inc.
+ *
+ *  Licensed under the Apache License, Version 2.0 (the "License");
+ *  you may not use this file except in compliance with the License.
+ *  You may obtain a copy of the License at:
+ *
+ *  http://www.apache.org/licenses/LICENSE-2.0
+ *
+ *  Unless required by applicable law or agreed to in writing, software
+ *  distributed under the License is distributed on an "AS IS" BASIS,
+ *  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ *  See the License for the specific language governing permissions and
+ *  limitations under the License.
+ *
+ ******************************************************************************/
+
+#include <assert.h>
+#include <resolv.h>
+#include <zlib.h>
+#include <mutex>
+
+#include "bt_types.h"
+#include "include/debug_nfcsnoop.h"
+#include "include/ringbuffer.h"
+#include "nfc_int.h"
+#include "nfc_types.h"
+
+#define USEC_PER_SEC 1000000ULL
+
+// Total nfcsnoop memory log buffer size
+#ifndef NFCSNOOP_MEM_BUFFER_SIZE
+static const size_t NFCSNOOP_MEM_BUFFER_SIZE = (256 * 1024);
+#endif
+
+// Block size for copying buffers (for compression/encoding etc.)
+static const size_t BLOCK_SIZE = 16384;
+
+// Maximum line length in bugreport (should be multiple of 4 for base64 output)
+static const uint8_t MAX_LINE_LENGTH = 128;
+
+static std::mutex buffer_mutex;
+static ringbuffer_t* buffer = NULL;
+static uint64_t last_timestamp_ms = 0;
+
+static void nfcsnoop_cb(const uint8_t* data, const size_t length,
+                        bool is_received, const uint64_t timestamp_us) {
+  nfcsnooz_header_t header;
+
+  std::lock_guard<std::mutex> lock(buffer_mutex);
+
+  // Make room in the ring buffer
+
+  while (ringbuffer_available(buffer) < (length + sizeof(nfcsnooz_header_t))) {
+    ringbuffer_pop(buffer, (uint8_t*)&header, sizeof(nfcsnooz_header_t));
+    ringbuffer_delete(buffer, header.length - 1);
+  }
+
+  // Insert data
+  header.length = length;
+  header.is_received = is_received ? 1 : 0;
+  header.delta_time_ms =
+      last_timestamp_ms ? timestamp_us - last_timestamp_ms : 0;
+  last_timestamp_ms = timestamp_us;
+
+  ringbuffer_insert(buffer, (uint8_t*)&header, sizeof(nfcsnooz_header_t));
+  ringbuffer_insert(buffer, data, length);
+}
+
+static bool nfcsnoop_compress(ringbuffer_t* rb_dst, ringbuffer_t* rb_src) {
+  assert(rb_dst != NULL);
+  assert(rb_src != NULL);
+
+  z_stream zs;
+  zs.zalloc = Z_NULL;
+  zs.zfree = Z_NULL;
+  zs.opaque = Z_NULL;
+
+  if (deflateInit(&zs, Z_DEFAULT_COMPRESSION) != Z_OK) return false;
+
+  bool rc = true;
+  uint8_t block_src[BLOCK_SIZE];
+  uint8_t block_dst[BLOCK_SIZE];
+
+  const size_t num_blocks =
+      (ringbuffer_size(rb_src) + BLOCK_SIZE - 1) / BLOCK_SIZE;
+  for (size_t i = 0; i < num_blocks; ++i) {
+    zs.avail_in =
+        ringbuffer_peek(rb_src, i * BLOCK_SIZE, block_src, BLOCK_SIZE);
+    zs.next_in = block_src;
+
+    do {
+      zs.avail_out = BLOCK_SIZE;
+      zs.next_out = block_dst;
+
+      int err = deflate(&zs, (i == num_blocks - 1) ? Z_FINISH : Z_NO_FLUSH);
+      if (err == Z_STREAM_ERROR) {
+        rc = false;
+        break;
+      }
+
+      const size_t length = BLOCK_SIZE - zs.avail_out;
+      ringbuffer_insert(rb_dst, block_dst, length);
+    } while (zs.avail_out == 0);
+  }
+
+  deflateEnd(&zs);
+  return rc;
+}
+
+void nfcsnoop_capture(const NFC_HDR* packet, bool is_received) {
+  struct timeval tv;
+  gettimeofday(&tv, NULL);
+  uint64_t timestamp = static_cast<uint64_t>(tv.tv_sec) * USEC_PER_SEC +
+                       static_cast<uint64_t>(tv.tv_usec);
+  uint8_t* p = (uint8_t*)(packet + 1) + packet->offset;
+  uint8_t mt = (*(p)&NCI_MT_MASK) >> NCI_MT_SHIFT;
+
+  if (mt == NCI_MT_DATA) {
+    nfcsnoop_cb(p, NCI_DATA_HDR_SIZE, is_received, timestamp);
+  } else if (packet->len > 2) {
+    nfcsnoop_cb(p, p[2] + NCI_MSG_HDR_SIZE, is_received, timestamp);
+  }
+}
+
+void debug_nfcsnoop_init(void) {
+  if (buffer == NULL) buffer = ringbuffer_init(NFCSNOOP_MEM_BUFFER_SIZE);
+}
+
+void debug_nfcsnoop_dump(int fd) {
+  ringbuffer_t* ringbuffer = ringbuffer_init(NFCSNOOP_MEM_BUFFER_SIZE);
+  if (ringbuffer == NULL) {
+    dprintf(fd, "%s Unable to allocate memory for compression", __func__);
+    return;
+  }
+
+  // Prepend preamble
+
+  nfcsnooz_preamble_t preamble;
+  preamble.version = NFCSNOOZ_CURRENT_VERSION;
+  preamble.last_timestamp_ms = last_timestamp_ms;
+  ringbuffer_insert(ringbuffer, (uint8_t*)&preamble,
+                    sizeof(nfcsnooz_preamble_t));
+
+  // Compress data
+
+  uint8_t b64_in[3] = {0};
+  char b64_out[5] = {0};
+
+  size_t line_length = 0;
+
+  bool rc;
+  {
+    std::lock_guard<std::mutex> lock(buffer_mutex);
+    dprintf(fd, "--- BEGIN:NFCSNOOP_LOG_SUMMARY (%zu bytes in) ---\n",
+            ringbuffer_size(buffer));
+    rc = nfcsnoop_compress(ringbuffer, buffer);
+  }
+
+  if (rc == false) {
+    dprintf(fd, "%s Log compression failed", __func__);
+    goto error;
+  }
+
+  // Base64 encode & output
+
+  while (ringbuffer_size(ringbuffer) > 0) {
+    size_t read = ringbuffer_pop(ringbuffer, b64_in, 3);
+    if (line_length >= MAX_LINE_LENGTH) {
+      dprintf(fd, "\n");
+      line_length = 0;
+    }
+    line_length += b64_ntop(b64_in, read, b64_out, 5);
+    dprintf(fd, "%s", b64_out);
+  }
+
+  dprintf(fd, "\n--- END:NFCSNOOP_LOG_SUMMARY ---\n");
+
+error:
+  ringbuffer_free(ringbuffer);
+}
diff --git a/src/adaptation/ringbuffer.cc b/src/adaptation/ringbuffer.cc
new file mode 100644
index 0000000..d7798fd
--- /dev/null
+++ b/src/adaptation/ringbuffer.cc
@@ -0,0 +1,116 @@
+/******************************************************************************
+ *
+ *  Copyright (C) 2017 Google Inc.
+ *
+ *  Licensed under the Apache License, Version 2.0 (the "License");
+ *  you may not use this file except in compliance with the License.
+ *  You may obtain a copy of the License at:
+ *
+ *  http://www.apache.org/licenses/LICENSE-2.0
+ *
+ *  Unless required by applicable law or agreed to in writing, software
+ *  distributed under the License is distributed on an "AS IS" BASIS,
+ *  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ *  See the License for the specific language governing permissions and
+ *  limitations under the License.
+ *
+ ******************************************************************************/
+
+#include <assert.h>
+#include <stdlib.h>
+
+#include "ringbuffer.h"
+
+struct ringbuffer_t {
+  size_t total;
+  size_t available;
+  uint8_t* base;
+  uint8_t* head;
+  uint8_t* tail;
+};
+
+ringbuffer_t* ringbuffer_init(const size_t size) {
+  ringbuffer_t* p = static_cast<ringbuffer_t*>(calloc(1, sizeof(ringbuffer_t)));
+
+  if (p == NULL) return p;
+
+  p->base = static_cast<uint8_t*>(calloc(size, sizeof(uint8_t)));
+  p->head = p->tail = p->base;
+  p->total = p->available = size;
+
+  return p;
+}
+
+void ringbuffer_free(ringbuffer_t* rb) {
+  if (rb != NULL) free(rb->base);
+  free(rb);
+}
+
+size_t ringbuffer_available(const ringbuffer_t* rb) {
+  assert(rb);
+  return rb->available;
+}
+
+size_t ringbuffer_size(const ringbuffer_t* rb) {
+  assert(rb);
+  return rb->total - rb->available;
+}
+
+size_t ringbuffer_insert(ringbuffer_t* rb, const uint8_t* p, size_t length) {
+  assert(rb);
+  assert(p);
+
+  if (length > ringbuffer_available(rb)) length = ringbuffer_available(rb);
+
+  for (size_t i = 0; i != length; ++i) {
+    *rb->tail++ = *p++;
+    if (rb->tail >= (rb->base + rb->total)) rb->tail = rb->base;
+  }
+
+  rb->available -= length;
+  return length;
+}
+
+size_t ringbuffer_delete(ringbuffer_t* rb, size_t length) {
+  assert(rb);
+
+  if (length > ringbuffer_size(rb)) length = ringbuffer_size(rb);
+
+  rb->head += length;
+  if (rb->head >= (rb->base + rb->total)) rb->head -= rb->total;
+
+  rb->available += length;
+  return length;
+}
+
+size_t ringbuffer_peek(const ringbuffer_t* rb, off_t offset, uint8_t* p,
+                       size_t length) {
+  assert(rb);
+  assert(p);
+  assert(offset >= 0);
+  assert((size_t)offset <= ringbuffer_size(rb));
+
+  uint8_t* b = ((rb->head - rb->base + offset) % rb->total) + rb->base;
+  const size_t bytes_to_copy = (offset + length > ringbuffer_size(rb))
+                                   ? ringbuffer_size(rb) - offset
+                                   : length;
+
+  for (size_t copied = 0; copied < bytes_to_copy; ++copied) {
+    *p++ = *b++;
+    if (b >= (rb->base + rb->total)) b = rb->base;
+  }
+
+  return bytes_to_copy;
+}
+
+size_t ringbuffer_pop(ringbuffer_t* rb, uint8_t* p, size_t length) {
+  assert(rb);
+  assert(p);
+
+  const size_t copied = ringbuffer_peek(rb, 0, p, length);
+  rb->head += copied;
+  if (rb->head >= (rb->base + rb->total)) rb->head -= rb->total;
+
+  rb->available += copied;
+  return copied;
+}
diff --git a/src/include/NfcAdaptation.h b/src/include/NfcAdaptation.h
index 06c0c38..606f66b 100644
--- a/src/include/NfcAdaptation.h
+++ b/src/include/NfcAdaptation.h
@@ -80,6 +80,7 @@ class NfcAdaptation {
   static NfcAdaptation& GetInstance();
   tHAL_NFC_ENTRY* GetHalEntryFuncs();
   void DownloadFirmware();
+  void Dump(int fd);
 
  private:
   NfcAdaptation();
diff --git a/src/include/debug_nfcsnoop.h b/src/include/debug_nfcsnoop.h
new file mode 100644
index 0000000..2dd7b6b
--- /dev/null
+++ b/src/include/debug_nfcsnoop.h
@@ -0,0 +1,50 @@
+/******************************************************************************
+ *
+ *  Copyright (C) 2017 Google Inc.
+ *
+ *  Licensed under the Apache License, Version 2.0 (the "License");
+ *  you may not use this file except in compliance with the License.
+ *  You may obtain a copy of the License at:
+ *
+ *  http://www.apache.org/licenses/LICENSE-2.0
+ *
+ *  Unless required by applicable law or agreed to in writing, software
+ *  distributed under the License is distributed on an "AS IS" BASIS,
+ *  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ *  See the License for the specific language governing permissions and
+ *  limitations under the License.
+ *
+ ******************************************************************************/
+#ifndef _DEBUG_NFCSNOOP_
+#define _DEBUG_NFCSNOOP_
+
+#include <stdint.h>
+#include "nfc_target.h"
+#include "nfc_types.h"
+
+#define NFCSNOOZ_CURRENT_VERSION 0x01
+
+// The preamble is stored un-encrypted as the first part
+// of the file.
+typedef struct nfcsnooz_preamble_t {
+  uint8_t version;
+  uint64_t last_timestamp_ms;
+} __attribute__((__packed__)) nfcsnooz_preamble_t;
+
+// One header for each NCI packet
+typedef struct nfcsnooz_header_t {
+  uint16_t length;
+  uint32_t delta_time_ms;
+  uint8_t is_received;
+} __attribute__((__packed__)) nfcsnooz_header_t;
+
+// Initializes nfcsnoop memory logging and registers
+void debug_nfcsnoop_init(void);
+
+// Writes nfcsnoop data base64 encoded to fd
+void debug_nfcsnoop_dump(int fd);
+
+// capture the packet
+void nfcsnoop_capture(const NFC_HDR* packet, bool is_received);
+
+#endif /* _DEBUG_NFCSNOOP_ */
diff --git a/src/include/ringbuffer.h b/src/include/ringbuffer.h
new file mode 100644
index 0000000..d2c310a
--- /dev/null
+++ b/src/include/ringbuffer.h
@@ -0,0 +1,62 @@
+/******************************************************************************
+ *
+ *  Copyright (C) 2017 Google Inc.
+ *
+ *  Licensed under the Apache License, Version 2.0 (the "License");
+ *  you may not use this file except in compliance with the License.
+ *  You may obtain a copy of the License at:
+ *
+ *  http://www.apache.org/licenses/LICENSE-2.0
+ *
+ *  Unless required by applicable law or agreed to in writing, software
+ *  distributed under the License is distributed on an "AS IS" BASIS,
+ *  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ *  See the License for the specific language governing permissions and
+ *  limitations under the License.
+ *
+ ******************************************************************************/
+
+#pragma once
+
+#include <stdint.h>
+
+typedef struct ringbuffer_t ringbuffer_t;
+
+// NOTE:
+// None of the functions below are thread safe when it comes to accessing the
+// *rb pointer. It is *NOT* possible to insert and pop/delete at the same time.
+// Callers must protect the *rb pointer separately.
+
+// Create a ringbuffer with the specified size
+// Returns NULL if memory allocation failed. Resulting pointer must be freed
+// using |ringbuffer_free|.
+ringbuffer_t* ringbuffer_init(const size_t size);
+
+// Frees the ringbuffer structure and buffer
+// Save to call with NULL.
+void ringbuffer_free(ringbuffer_t* rb);
+
+// Returns remaining buffer size
+size_t ringbuffer_available(const ringbuffer_t* rb);
+
+// Returns size of data in buffer
+size_t ringbuffer_size(const ringbuffer_t* rb);
+
+// Attempts to insert up to |length| bytes of data at |p| into the buffer
+// Return actual number of bytes added. Can be less than |length| if buffer
+// is full.
+size_t ringbuffer_insert(ringbuffer_t* rb, const uint8_t* p, size_t length);
+
+// Peek |length| number of bytes from the ringbuffer, starting at |offset|,
+// into the buffer |p|. Return the actual number of bytes peeked. Can be less
+// than |length| if there is less than |length| data available. |offset| must
+// be non-negative.
+size_t ringbuffer_peek(const ringbuffer_t* rb, off_t offset, uint8_t* p,
+                       size_t length);
+
+// Does the same as |ringbuffer_peek|, but also advances the ring buffer head
+size_t ringbuffer_pop(ringbuffer_t* rb, uint8_t* p, size_t length);
+
+// Deletes |length| bytes from the ringbuffer starting from the head
+// Return actual number of bytes deleted.
+size_t ringbuffer_delete(ringbuffer_t* rb, size_t length);
diff --git a/src/nfc/nfc/nfc_ncif.cc b/src/nfc/nfc/nfc_ncif.cc
index 1fa59b0..4b94b8c 100644
--- a/src/nfc/nfc/nfc_ncif.cc
+++ b/src/nfc/nfc/nfc_ncif.cc
@@ -28,6 +28,7 @@
 #include <string.h>
 #include "nfc_target.h"
 
+#include "include/debug_nfcsnoop.h"
 #include "nci_defs.h"
 #include "nci_hmsgs.h"
 #include "nfc_api.h"
@@ -207,6 +208,7 @@ uint8_t nfc_ncif_send_data(tNFC_CONN_CB* p_cb, NFC_HDR* p_data) {
 
     /* send to HAL */
     HAL_WRITE(p);
+    nfcsnoop_capture(p, false);
 
     if (!fragmented) {
       /* check if there are more data to send */
@@ -310,6 +312,7 @@ void nfc_ncif_send_cmd(NFC_HDR* p_buf) {
   /* post the p_buf to NCIT task */
   p_buf->event = BT_EVT_TO_NFC_NCI;
   p_buf->layer_specific = 0;
+  nfcsnoop_capture(p_buf, false);
   nfc_ncif_check_cmd_queue(p_buf);
 }
 
@@ -334,6 +337,7 @@ bool nfc_ncif_process_event(NFC_HDR* p_msg) {
   pp = p;
   NCI_MSG_PRS_HDR0(pp, mt, pbf, gid);
 
+  nfcsnoop_capture(p_msg, true);
   switch (mt) {
     case NCI_MT_DATA:
       NFC_TRACE_DEBUG0("NFC received data");