Tscached returns the right response after refreshing the query multiple times

[maazkhan]

Hi, I am testing out tscached and the performance is looking really good. One issue that I am consistently seeing is that If I issue a query it returns empty response first two times and then third time it sends the response back. Its quite random and I have to re issue the query multiple times.

Looking at the log for the first 2 requests it says Query is WARM but returns empty response and then 3rd time is says Query is HOT and returns the appropriate response.

2017-04-06 18:46:26,264 [uWSGIWorker1] [INFO ]  Query
2017-04-06 18:46:26,266 [uWSGIWorker1] [DEBUG]  Cache HIT: tscached:kquery:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:26,266 [uWSGIWorker1] [INFO ]  Shadow: Added 0 key: tscached:kquery:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:26,266 [uWSGIWorker1] [INFO ]  KQuery is WARM
2017-04-06 18:46:26,267 [uWSGIWorker1] [INFO ]  Starting new HTTP connection (1): 100.122.12.220
2017-04-06 18:46:26,430 [uWSGIWorker1] [DEBUG]  "POST /api/v1/datapoints/query HTTP/1.1" 200 None
2017-04-06 18:46:26,435 [uWSGIWorker1] [DEBUG]  Cache HIT: tscached:mts:ff6427487fd8e630d06770a42f6d8733
2017-04-06 18:46:26,443 [uWSGIWorker1] [DEBUG]  Cache HIT: tscached:mts:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:26,443 [uWSGIWorker1] [ERROR]  merge_at_end: current MTS is None, or contained no data! tscached:mts:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:26,443 [uWSGIWorker1] [ERROR]  ttl_expire: MTS None, or contained no data points! tscached:mts:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:26,444 [uWSGIWorker1] [INFO ]  MTS write pipeline: 1 of 1 successful
2017-04-06 18:46:26,444 [uWSGIWorker1] [INFO ]  Cache SET True tscached:kquery:8824ff746787b7aed6cfe9a8451e2b25
[pid: 9|app: 0|req: 49/50] 192.168.99.1 () {44 vars in 781 bytes} [Thu Apr  6 18:46:26 2017] POST /api/v1/datapoints/query => generated 48 bytes in 181 msecs (HTTP/1.1 200) 3 headers in 101 bytes (1 switches on core 1)
2017-04-06 18:46:42,593 [uWSGIWorker1] [INFO ]  Query
2017-04-06 18:46:42,594 [uWSGIWorker1] [DEBUG]  Cache HIT: tscached:kquery:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:42,594 [uWSGIWorker1] [INFO ]  Shadow: Added 0 key: tscached:kquery:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:42,594 [uWSGIWorker1] [INFO ]  KQuery is WARM
2017-04-06 18:46:42,595 [uWSGIWorker1] [INFO ]  Starting new HTTP connection (1): 100.122.12.220
2017-04-06 18:46:42,759 [uWSGIWorker1] [DEBUG]  "POST /api/v1/datapoints/query HTTP/1.1" 200 None
2017-04-06 18:46:42,763 [uWSGIWorker1] [DEBUG]  Cache HIT: tscached:mts:ff6427487fd8e630d06770a42f6d8733
2017-04-06 18:46:42,765 [uWSGIWorker1] [DEBUG]  Cache HIT: tscached:mts:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:42,765 [uWSGIWorker1] [ERROR]  merge_at_end: current MTS is None, or contained no data! tscached:mts:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:42,765 [uWSGIWorker1] [ERROR]  ttl_expire: MTS None, or contained no data points! tscached:mts:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:42,765 [uWSGIWorker1] [INFO ]  MTS write pipeline: 1 of 1 successful
2017-04-06 18:46:42,766 [uWSGIWorker1] [INFO ]  Cache SET True tscached:kquery:8824ff746787b7aed6cfe9a8451e2b25
[pid: 9|app: 0|req: 50/51] 192.168.99.1 () {44 vars in 781 bytes} [Thu Apr  6 18:46:42 2017] POST /api/v1/datapoints/query => generated 48 bytes in 174 msecs (HTTP/1.1 200) 3 headers in 101 bytes (1 switches on core 0)
2017-04-06 18:46:43,350 [uWSGIWorker1] [INFO ]  Query
2017-04-06 18:46:43,352 [uWSGIWorker1] [DEBUG]  Cache HIT: tscached:kquery:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:43,352 [uWSGIWorker1] [INFO ]  Shadow: Added 0 key: tscached:kquery:8824ff746787b7aed6cfe9a8451e2b25
2017-04-06 18:46:43,352 [uWSGIWorker1] [INFO ]  KQuery is HOT
2017-04-06 18:46:43,354 [uWSGIWorker1] [DEBUG]  Cache HIT: tscached:mts:ff6427487fd8e630d06770a42f6d8733
2017-04-06 18:46:43,356 [uWSGIWorker1] [DEBUG]  Cache HIT: tscached:mts:8824ff746787b7aed6cfe9a8451e2b25
[pid: 9|app: 0|req: 51/52] 192.168.99.1 () {44 vars in 781 bytes} [Thu Apr  6 18:46:43 2017] POST /api/v1/datapoints/query => generated 104912 bytes in 14 msecs (HTTP/1.1 200) 3 headers in 97 bytes (1 switches on core 5)