From 5a8ddd6268c294ed1f62111938d5a7f640d4507c Mon Sep 17 00:00:00 2001
From: Stephen Hess <stephen.k.hess@gmail.com>
Date: Thu, 25 May 2017 12:07:18 -0400
Subject: [PATCH] added debug logging for sorting

---
 middleware/sortResponseData.js           | 15 +++++++++++
 test/unit/middleware/sortResponseData.js | 32 ++++++++++++++++++------
 2 files changed, 39 insertions(+), 8 deletions(-)

diff --git a/middleware/sortResponseData.js b/middleware/sortResponseData.js
index 2d4ad1c7..a8806af4 100644
--- a/middleware/sortResponseData.js
+++ b/middleware/sortResponseData.js
@@ -1,5 +1,7 @@
 const _ = require('lodash');
 
+const logger = require('pelias-logger').get('api');
+
 function setup(comparator, should_execute) {
   function middleware(req, res, next) {
     // bail early if req/res don't pass conditions for execution or there's no data to sort
@@ -7,9 +9,22 @@ function setup(comparator, should_execute) {
       return next();
     }
 
+    // capture the pre-sort order
+    const presort_order = res.data.map(_.property('_id'));
+
     // sort operates on array in place
     res.data.sort(comparator(req.clean));
 
+    // capture the post-sort order
+    const postsort_order = res.data.map(_.property('_id'));
+
+    // log it for debugging purposes
+    logger.debug([
+      `req.clean: ${JSON.stringify(req.clean)}`,
+      `pre-sort: [${presort_order}]`,
+      `post-sort: [${postsort_order}]`
+    ].join(', '));
+
     next();
   }
 
diff --git a/test/unit/middleware/sortResponseData.js b/test/unit/middleware/sortResponseData.js
index 06b87c59..8e9ad1c1 100644
--- a/test/unit/middleware/sortResponseData.js
+++ b/test/unit/middleware/sortResponseData.js
@@ -1,4 +1,6 @@
 const _ = require('lodash');
+const proxyquire =  require('proxyquire').noCallThru();
+const mock_logger = require('pelias-mock-logger');
 
 const sortResponseData = require('../../../middleware/sortResponseData');
 
@@ -100,27 +102,41 @@ module.exports.tests.general_tests = (test, common) => {
 
 module.exports.tests.successful_sort = (test, common) => {
   test('comparator should be sort res.data', (t) => {
+    const logger = mock_logger();
+
     const comparator = () => {
       return (a, b) => {
-        return a.key > b.key;
+        return a._id > b._id;
       };
     };
 
+    const sortResponseData = proxyquire('../../../middleware/sortResponseData', {
+      'pelias-logger': logger
+    });
+
     const sort = sortResponseData(comparator, _.constant(true));
 
-    const req = {};
+    const req = {
+      clean: {
+        field: 'value'
+      }
+    };
     const res = {
       data: [
-        { key: 3 },
-        { key: 2 },
-        { key: 1 },
+        { _id: 3 },
+        { _id: 2 },
+        { _id: 1 },
       ]
     };
 
     sort(req, res, () => {
-      t.deepEquals(res.data.shift(), { key: 1 });
-      t.deepEquals(res.data.shift(), { key: 2 });
-      t.deepEquals(res.data.shift(), { key: 3 });
+      t.deepEquals(res.data.shift(), { _id: 1 });
+      t.deepEquals(res.data.shift(), { _id: 2 });
+      t.deepEquals(res.data.shift(), { _id: 3 });
+
+      t.ok(logger.isDebugMessage(
+        'req.clean: {"field":"value"}, pre-sort: [3,2,1], post-sort: [1,2,3]'));
+
       t.end();
     });