You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@trafficserver.apache.org by am...@apache.org on 2016/03/09 21:28:21 UTC
trafficserver git commit: TS-1775: General hrtime cleanup. This close
#515.
Repository: trafficserver
Updated Branches:
refs/heads/master 954deaf3c -> d95d9e84e
TS-1775: General hrtime cleanup.
This close #515.
Project: http://git-wip-us.apache.org/repos/asf/trafficserver/repo
Commit: http://git-wip-us.apache.org/repos/asf/trafficserver/commit/d95d9e84
Tree: http://git-wip-us.apache.org/repos/asf/trafficserver/tree/d95d9e84
Diff: http://git-wip-us.apache.org/repos/asf/trafficserver/diff/d95d9e84
Branch: refs/heads/master
Commit: d95d9e84e82e7752c0348cfa17a851f4bc914061
Parents: 954deaf
Author: Alan M. Carroll <am...@apache.org>
Authored: Sun Mar 6 11:56:12 2016 -0600
Committer: Alan M. Carroll <am...@apache.org>
Committed: Wed Mar 9 13:54:47 2016 -0600
----------------------------------------------------------------------
iocore/aio/AIO.cc | 4 +-
iocore/cache/CacheDir.cc | 8 ++--
iocore/eventsystem/I_Thread.h | 28 ++++++++++++++
iocore/eventsystem/PQ-List.cc | 2 +-
iocore/eventsystem/P_UnixEventProcessor.h | 4 +-
iocore/eventsystem/Thread.cc | 6 ---
iocore/eventsystem/UnixEThread.cc | 8 ++--
iocore/eventsystem/UnixEventProcessor.cc | 2 +-
iocore/net/SSLNetVConnection.cc | 2 +-
iocore/net/UnixNetVConnection.cc | 2 +-
iocore/net/UnixUDPNet.cc | 14 +++----
lib/ts/ink_hrtime.h | 53 +++-----------------------
proxy/TestDNS.cc | 10 ++---
proxy/http/HttpSM.cc | 41 ++++++++++++--------
14 files changed, 87 insertions(+), 97 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/iocore/aio/AIO.cc
----------------------------------------------------------------------
diff --git a/iocore/aio/AIO.cc b/iocore/aio/AIO.cc
index 3bb6885..3f9f2a8 100644
--- a/iocore/aio/AIO.cc
+++ b/iocore/aio/AIO.cc
@@ -116,7 +116,7 @@ static AIOTestData *data;
int
AIOTestData::ink_aio_stats(int event, void *d)
{
- ink_hrtime now = ink_get_hrtime();
+ ink_hrtime now = Thread::get_hrtime();
double time_msec = (double)(now - start) / (double)HRTIME_MSECOND;
int i = (aio_reqs[0] == NULL) ? 1 : 0;
for (; i < num_filedes; ++i)
@@ -509,7 +509,7 @@ aio_thread_main(void *arg)
op->thread->schedule_imm_signal(op);
ink_mutex_acquire(&my_aio_req->aio_mutex);
} while (1);
- timespec timedwait_msec = ink_hrtime_to_timespec(Thread::get_hrtime() + HRTIME_MSECONDS(net_config_poll_timeout));
+ timespec timedwait_msec = ink_hrtime_to_timespec(Thread::get_hrtime_updated() + HRTIME_MSECONDS(net_config_poll_timeout));
ink_cond_timedwait(&my_aio_req->aio_cond, &my_aio_req->aio_mutex, &timedwait_msec);
}
return 0;
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/iocore/cache/CacheDir.cc
----------------------------------------------------------------------
diff --git a/iocore/cache/CacheDir.cc b/iocore/cache/CacheDir.cc
index c9a7068..17f4348 100644
--- a/iocore/cache/CacheDir.cc
+++ b/iocore/cache/CacheDir.cc
@@ -1425,25 +1425,25 @@ EXCLUSIVE_REGRESSION_TEST(Cache_dir)(RegressionTest *t, int /* atype ATS_UNUSED
// test insert-delete
rprintf(t, "insert-delete test\n");
regress_rand_init(13);
- ttime = ink_get_hrtime_internal();
+ ttime = Thread::get_hrtime_updated();
for (i = 0; i < newfree; i++) {
regress_rand_CacheKey(&key);
dir_insert(&key, d, &dir);
}
- uint64_t us = (ink_get_hrtime_internal() - ttime) / HRTIME_USECOND;
+ uint64_t us = (Thread::get_hrtime_updated() - ttime) / HRTIME_USECOND;
// On windows us is sometimes 0. I don't know why.
// printout the insert rate only if its not 0
if (us)
rprintf(t, "insert rate = %d / second\n", (int)((newfree * (uint64_t)1000000) / us));
regress_rand_init(13);
- ttime = ink_get_hrtime_internal();
+ ttime = Thread::get_hrtime_updated();
for (i = 0; i < newfree; i++) {
Dir *last_collision = 0;
regress_rand_CacheKey(&key);
if (!dir_probe(&key, d, &dir, &last_collision))
ret = REGRESSION_TEST_FAILED;
}
- us = (ink_get_hrtime_internal() - ttime) / HRTIME_USECOND;
+ us = (Thread::get_hrtime_updated() - ttime) / HRTIME_USECOND;
// On windows us is sometimes 0. I don't know why.
// printout the probe rate only if its not 0
if (us)
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/iocore/eventsystem/I_Thread.h
----------------------------------------------------------------------
diff --git a/iocore/eventsystem/I_Thread.h b/iocore/eventsystem/I_Thread.h
index 7d3e74c..abc1726 100644
--- a/iocore/eventsystem/I_Thread.h
+++ b/iocore/eventsystem/I_Thread.h
@@ -157,9 +157,37 @@ public:
{
}
+ /** Get the current ATS high resolution time.
+ This gets a cached copy of the time so it is very fast and reasonably accurate.
+ The cached time is updated every time the actual operating system time is fetched which is
+ at least every 10ms and generally more frequently.
+ @note The cached copy shared among threads which means the cached copy is udpated
+ for all threads if any thread updates it.
+ */
static ink_hrtime get_hrtime();
+
+ /** Get the operating system high resolution time.
+
+ Get the current time at high resolution from the operating system. This is more expensive
+ than @c get_hrtime and should be used only where very precise timing is required.
+
+ @note This also updates the cached time.
+ */
+ static ink_hrtime get_hrtime_updated();
};
extern Thread *this_thread();
+TS_INLINE ink_hrtime
+Thread::get_hrtime()
+{
+ return cur_time;
+}
+
+TS_INLINE ink_hrtime
+Thread::get_hrtime_updated()
+{
+ return cur_time = ink_get_hrtime_internal();
+}
+
#endif /*_I_Thread_h*/
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/iocore/eventsystem/PQ-List.cc
----------------------------------------------------------------------
diff --git a/iocore/eventsystem/PQ-List.cc b/iocore/eventsystem/PQ-List.cc
index 8d7944d..c3686bf 100644
--- a/iocore/eventsystem/PQ-List.cc
+++ b/iocore/eventsystem/PQ-List.cc
@@ -25,7 +25,7 @@
PriorityEventQueue::PriorityEventQueue()
{
- last_check_time = ink_get_based_hrtime_internal();
+ last_check_time = Thread::get_hrtime_updated();
last_check_buckets = last_check_time / PQ_BUCKET_TIME(0);
}
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/iocore/eventsystem/P_UnixEventProcessor.h
----------------------------------------------------------------------
diff --git a/iocore/eventsystem/P_UnixEventProcessor.h b/iocore/eventsystem/P_UnixEventProcessor.h
index 55bf4a8..21be1bc 100644
--- a/iocore/eventsystem/P_UnixEventProcessor.h
+++ b/iocore/eventsystem/P_UnixEventProcessor.h
@@ -90,7 +90,7 @@ EventProcessor::schedule_imm_signal(Continuation *cont, EventType et, int callba
ink_assert(et < MAX_EVENT_TYPES);
#ifdef ENABLE_TIME_TRACE
- e->start_time = ink_get_hrtime();
+ e->start_time = Thread::get_hrtime();
#endif
e->callback_event = callback_event;
e->cookie = cookie;
@@ -104,7 +104,7 @@ EventProcessor::schedule_imm(Continuation *cont, EventType et, int callback_even
ink_assert(et < MAX_EVENT_TYPES);
#ifdef ENABLE_TIME_TRACE
- e->start_time = ink_get_hrtime();
+ e->start_time = Thread::get_hrtime();
#endif
e->callback_event = callback_event;
e->cookie = cookie;
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/iocore/eventsystem/Thread.cc
----------------------------------------------------------------------
diff --git a/iocore/eventsystem/Thread.cc b/iocore/eventsystem/Thread.cc
index 41b17ca..03af6db 100644
--- a/iocore/eventsystem/Thread.cc
+++ b/iocore/eventsystem/Thread.cc
@@ -102,9 +102,3 @@ Thread::start(const char *name, size_t stacksize, ThreadFunction f, void *a)
return tid;
}
-
-ink_hrtime
-Thread::get_hrtime()
-{
- return Thread::cur_time;
-}
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/iocore/eventsystem/UnixEThread.cc
----------------------------------------------------------------------
diff --git a/iocore/eventsystem/UnixEThread.cc b/iocore/eventsystem/UnixEThread.cc
index e178930..8af5c98 100644
--- a/iocore/eventsystem/UnixEThread.cc
+++ b/iocore/eventsystem/UnixEThread.cc
@@ -42,14 +42,14 @@ struct AIOCallback;
bool shutdown_event_system = false;
EThread::EThread()
- : generator((uint64_t)ink_get_hrtime_internal() ^ (uint64_t)(uintptr_t) this), ethreads_to_be_signalled(NULL),
+ : generator((uint64_t)Thread::get_hrtime_updated() ^ (uint64_t)(uintptr_t) this), ethreads_to_be_signalled(NULL),
n_ethreads_to_be_signalled(0), main_accept_index(-1), id(NO_ETHREAD_ID), event_types(0), signal_hook(0), tt(REGULAR)
{
memset(thread_private, 0, PER_THREAD_DATA);
}
EThread::EThread(ThreadType att, int anid)
- : generator((uint64_t)ink_get_hrtime_internal() ^ (uint64_t)(uintptr_t) this), ethreads_to_be_signalled(NULL),
+ : generator((uint64_t)Thread::get_hrtime_updated() ^ (uint64_t)(uintptr_t) this), ethreads_to_be_signalled(NULL),
n_ethreads_to_be_signalled(0), main_accept_index(-1), id(anid), event_types(0), signal_hook(0), tt(att),
server_session_pool(NULL)
{
@@ -136,7 +136,7 @@ EThread::process_event(Event *e, int calling_code)
if (e->period < 0)
e->timeout_at = e->period;
else {
- cur_time = get_hrtime();
+ this->get_hrtime_updated();
e->timeout_at = cur_time + e->period;
if (e->timeout_at < cur_time)
e->timeout_at = cur_time;
@@ -175,7 +175,7 @@ EThread::execute()
}
// execute all the available external events that have
// already been dequeued
- cur_time = ink_get_based_hrtime_internal();
+ cur_time = Thread::get_hrtime_updated();
while ((e = EventQueueExternal.dequeue_local())) {
if (e->cancelled)
free_event(e);
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/iocore/eventsystem/UnixEventProcessor.cc
----------------------------------------------------------------------
diff --git a/iocore/eventsystem/UnixEventProcessor.cc b/iocore/eventsystem/UnixEventProcessor.cc
index a7d5395..7711965 100644
--- a/iocore/eventsystem/UnixEventProcessor.cc
+++ b/iocore/eventsystem/UnixEventProcessor.cc
@@ -85,7 +85,7 @@ EventProcessor::start(int n_event_threads, size_t stacksize)
if (i == 0) {
ink_thread_setspecific(Thread::thread_data_key, t);
global_mutex = t->mutex;
- t->cur_time = ink_get_based_hrtime_internal();
+ Thread::get_hrtime_updated();
}
all_ethreads[i] = t;
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/iocore/net/SSLNetVConnection.cc
----------------------------------------------------------------------
diff --git a/iocore/net/SSLNetVConnection.cc b/iocore/net/SSLNetVConnection.cc
index bb81687..9373405 100644
--- a/iocore/net/SSLNetVConnection.cc
+++ b/iocore/net/SSLNetVConnection.cc
@@ -698,7 +698,7 @@ SSLNetVConnection::load_buffer_and_write(int64_t towrite, int64_t &wattempted, i
// Dynamic TLS record sizing
ink_hrtime now = 0;
if (SSLConfigParams::ssl_maxrecord == -1) {
- now = ink_get_hrtime_internal();
+ now = Thread::get_hrtime_updated();
int msec_since_last_write = ink_hrtime_diff_msec(now, sslLastWriteTime);
if (msec_since_last_write > SSL_DEF_TLS_RECORD_MSEC_THRESHOLD) {
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/iocore/net/UnixNetVConnection.cc
----------------------------------------------------------------------
diff --git a/iocore/net/UnixNetVConnection.cc b/iocore/net/UnixNetVConnection.cc
index e235bc7..3da42ab 100644
--- a/iocore/net/UnixNetVConnection.cc
+++ b/iocore/net/UnixNetVConnection.cc
@@ -1163,7 +1163,7 @@ UnixNetVConnection::mainEvent(int event, Event *e)
if (event == EVENT_IMMEDIATE) {
/* BZ 49408 */
// ink_assert(inactivity_timeout_in);
- // ink_assert(next_inactivity_timeout_at < ink_get_hrtime());
+ // ink_assert(next_inactivity_timeout_at < Thread::get_hrtime());
if (!inactivity_timeout_in || next_inactivity_timeout_at > Thread::get_hrtime())
return EVENT_CONT;
signal_event = VC_EVENT_INACTIVITY_TIMEOUT;
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/iocore/net/UnixUDPNet.cc
----------------------------------------------------------------------
diff --git a/iocore/net/UnixUDPNet.cc b/iocore/net/UnixUDPNet.cc
index b4dd8c1..3c460b2 100644
--- a/iocore/net/UnixUDPNet.cc
+++ b/iocore/net/UnixUDPNet.cc
@@ -630,7 +630,7 @@ void
UDPQueue::service(UDPNetHandler *nh)
{
(void)nh;
- ink_hrtime now = ink_get_hrtime_internal();
+ ink_hrtime now = Thread::get_hrtime_updated();
uint64_t timeSpent = 0;
uint64_t pktSendStartTime;
UDPPacketInternal *p;
@@ -684,8 +684,8 @@ void
UDPQueue::SendPackets()
{
UDPPacketInternal *p;
- static ink_hrtime lastCleanupTime = ink_get_hrtime_internal();
- ink_hrtime now = ink_get_hrtime_internal();
+ static ink_hrtime lastCleanupTime = Thread::get_hrtime_updated();
+ ink_hrtime now = Thread::get_hrtime_updated();
ink_hrtime send_threshold_time = now + SLOT_TIME;
int32_t bytesThisSlot = INT_MAX, bytesUsed = 0;
int32_t bytesThisPipe, sentOne;
@@ -721,7 +721,7 @@ sendPackets:
if ((bytesThisSlot > 0) && sentOne) {
// redistribute the slack...
- now = ink_get_hrtime_internal();
+ now = Thread::get_hrtime_updated();
if (pipeInfo.firstPacket(now) == NULL) {
pipeInfo.advanceNow(now);
}
@@ -797,7 +797,7 @@ UDPNetHandler::UDPNetHandler()
mutex = new_ProxyMutex();
ink_atomiclist_init(&udpOutQueue.atomicQueue, "Outgoing UDP Packet queue", offsetof(UDPPacketInternal, alink.next));
ink_atomiclist_init(&udpNewConnections, "UDP Connection queue", offsetof(UnixUDPConnection, newconn_alink.next));
- nextCheck = ink_get_hrtime_internal() + HRTIME_MSECONDS(1000);
+ nextCheck = Thread::get_hrtime_updated() + HRTIME_MSECONDS(1000);
lastCheck = 0;
SET_HANDLER((UDPNetContHandler)&UDPNetHandler::startNetEvent);
}
@@ -847,7 +847,7 @@ UDPNetHandler::mainNetEvent(int event, Event *e)
} // end for
// remove dead UDP connections
- ink_hrtime now = ink_get_hrtime_internal();
+ ink_hrtime now = Thread::get_hrtime_updated();
if (now >= nextCheck) {
for (uc = udp_polling.head; uc; uc = next) {
ink_assert(uc->mutex && uc->continuation);
@@ -859,7 +859,7 @@ UDPNetHandler::mainNetEvent(int event, Event *e)
uc->Release();
}
}
- nextCheck = ink_get_hrtime_internal() + HRTIME_MSECONDS(1000);
+ nextCheck = Thread::get_hrtime_updated() + HRTIME_MSECONDS(1000);
}
// service UDPConnections with data ready for callback.
Que(UnixUDPConnection, callback_link) q = udp_callbacks;
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/lib/ts/ink_hrtime.h
----------------------------------------------------------------------
diff --git a/lib/ts/ink_hrtime.h b/lib/ts/ink_hrtime.h
index f084948..9e76deb 100644
--- a/lib/ts/ink_hrtime.h
+++ b/lib/ts/ink_hrtime.h
@@ -44,30 +44,6 @@ char *int64_to_str(char *buf, unsigned int buf_size, int64_t val, unsigned int *
//////////////////////////////////////////////////////////////////////////////
//
-// Time Stamp Counter
-//
-//////////////////////////////////////////////////////////////////////////////
-#ifdef USE_TIME_STAMP_COUNTER_HRTIME
-extern ink_hrtime init_hrtime_TSC();
-extern uint32_t hrtime_freq;
-extern double hrtime_freq_float;
-static inline ink_hrtime
-hrtime_rdtsc()
-{
- ink_hrtime rv;
- asm volatile(".byte 0x0f, 0x31" : "=A"(rv));
- return (rv);
-}
-static inline uint64_t
-get_hrtime_rdtsc()
-{
- // do it fixed point if you have better hardware support
- return (uint64_t)(hrtime_freq_float * hrtime_rdtsc());
-}
-#endif
-
-//////////////////////////////////////////////////////////////////////////////
-//
// Factors to multiply units by to obtain coresponding ink_hrtime values.
//
//////////////////////////////////////////////////////////////////////////////
@@ -82,7 +58,7 @@ get_hrtime_rdtsc()
#define HRTIME_SECOND (1000 * HRTIME_MSECOND)
#define HRTIME_MSECOND (1000 * HRTIME_USECOND)
#define HRTIME_USECOND (1000 * HRTIME_NSECOND)
-#define HRTIME_NSECOND (1LL)
+#define HRTIME_NSECOND (static_cast<ink_hrtime>(1))
#define HRTIME_APPROX_SECONDS(_x) ((_x) >> 30) // off by 7.3%
#define HRTIME_APPROX_FACTOR (((float)(1 << 30)) / (((float)HRTIME_SECOND)))
@@ -248,9 +224,7 @@ ink_hrtime_to_timeval2(ink_hrtime t, struct timeval *tv)
static inline ink_hrtime
ink_get_hrtime_internal()
{
-#if defined(USE_TIME_STAMP_COUNTER_HRTIME)
- return get_hrtime_rdtsc();
-#elif defined(freebsd)
+#if defined(freebsd) || HAVE_CLOCK_GETTIME
timespec ts;
clock_gettime(CLOCK_REALTIME, &ts);
return ink_hrtime_from_timespec(&ts);
@@ -261,39 +235,22 @@ ink_get_hrtime_internal()
#endif
}
-static inline ink_hrtime
-ink_get_based_hrtime_internal()
-{
-#if defined(USE_TIME_STAMP_COUNTER_HRTIME)
- return hrtime_offset + ink_get_hrtime_internal();
-#elif !HAVE_CLOCK_GETTIME
- timeval tv;
- gettimeofday(&tv, NULL);
- return ink_hrtime_from_timeval(&tv);
-#else
- timespec ts;
- clock_gettime(CLOCK_REALTIME, &ts);
- return ink_hrtime_from_timespec(&ts);
-#endif
-}
-
-
static inline struct timeval
ink_gettimeofday()
{
- return ink_hrtime_to_timeval(ink_get_based_hrtime_internal());
+ return ink_hrtime_to_timeval(ink_get_hrtime_internal());
}
static inline int
ink_gethrtimeofday(struct timeval *tp, void *)
{
- return ink_hrtime_to_timeval2(ink_get_based_hrtime_internal(), tp);
+ return ink_hrtime_to_timeval2(ink_get_hrtime_internal(), tp);
}
static inline int
ink_time()
{
- return (int)ink_hrtime_to_sec(ink_get_based_hrtime_internal());
+ return (int)ink_hrtime_to_sec(ink_get_hrtime_internal());
}
static inline int
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/proxy/TestDNS.cc
----------------------------------------------------------------------
diff --git a/proxy/TestDNS.cc b/proxy/TestDNS.cc
index 21cc8b2..e2efce7 100644
--- a/proxy/TestDNS.cc
+++ b/proxy/TestDNS.cc
@@ -181,7 +181,7 @@ complete()
ink_hrtime now;
state_machines_finished++;
if (!(state_machines_finished % measurement_interval)) {
- now = ink_get_hrtime();
+ now = Thread::get_hrtime();
cumul_throughput = state_machines_finished * 1.0 * HRTIME_SECOND / (now - start_time);
throughput = measurement_interval * 1.0 * HRTIME_SECOND / (now - last_measurement_time);
last_measurement_time = now;
@@ -199,7 +199,7 @@ complete()
fout_rate.flush();
}
if (state_machines_finished == state_machines_created) {
- now = ink_get_hrtime();
+ now = Thread::get_hrtime();
fout_rate_misc << (now - start_time) * 1.0 / HRTIME_SECOND << "\n";
fout_rate_misc.flush();
fout.close();
@@ -240,14 +240,14 @@ test()
state_machines_created = N_STATE_MACHINES;
state_machines_finished = 0;
measurement_interval = MEASUREMENT_INTERVAL;
- start_time = ink_get_hrtime();
- last_measurement_time = ink_get_hrtime();
+ start_time = Thread::get_hrtime();
+ last_measurement_time = Thread::get_hrtime();
while ((fscanf(fin, "%s", host) != EOF) && (i < state_machines_created)) {
test_dns_state_machine = new TestDnsStateMachine(host, sizeof(host));
test_dns_state_machine->handleEvent();
i++;
}
- now = ink_get_hrtime();
+ now = Thread::get_hrtime();
cout << "Finished creating all Continuations at " << (now - start_time) / HRTIME_SECOND << " sec and "
<< (now - start_time) % HRTIME_SECOND << "nanosec\n";
fout_rate_misc << (now - start_time) * 1.0 / HRTIME_SECOND << "\n";
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/d95d9e84/proxy/http/HttpSM.cc
----------------------------------------------------------------------
diff --git a/proxy/http/HttpSM.cc b/proxy/http/HttpSM.cc
index 6ac4531..28ef1aa 100644
--- a/proxy/http/HttpSM.cc
+++ b/proxy/http/HttpSM.cc
@@ -95,22 +95,21 @@ milestone_update_api_time(TransactionMilestones &milestones, ink_hrtime &api_tim
bool active = api_timer >= 0;
if (!active)
api_timer = -api_timer;
- delta = Thread::get_hrtime() - api_timer;
+ delta = Thread::get_hrtime_updated() - api_timer;
api_timer = 0;
- // Exactly zero is a problem because we want to signal *something* happened
- // vs. no API activity at all. This can happen when the API time is less than
- // the HR timer resolution, so in fact we're understating the time even with
- // this tweak.
- if (0 == delta)
- ++delta;
+ // Zero or negative time is a problem because we want to signal *something* happened
+ // vs. no API activity at all. This can happen due to graininess or real time
+ // clock adjustment.
+ if (delta <= 0)
+ delta = 1;
if (0 == milestones[TS_MILESTONE_PLUGIN_TOTAL])
milestones[TS_MILESTONE_PLUGIN_TOTAL] = milestones[TS_MILESTONE_SM_START];
- milestones[TS_MILESTONE_PLUGIN_TOTAL] = milestones[TS_MILESTONE_PLUGIN_TOTAL] + delta;
+ milestones[TS_MILESTONE_PLUGIN_TOTAL] += delta;
if (active) {
if (0 == milestones[TS_MILESTONE_PLUGIN_ACTIVE])
milestones[TS_MILESTONE_PLUGIN_ACTIVE] = milestones[TS_MILESTONE_SM_START];
- milestones[TS_MILESTONE_PLUGIN_ACTIVE] = milestones[TS_MILESTONE_PLUGIN_ACTIVE] + delta;
+ milestones[TS_MILESTONE_PLUGIN_ACTIVE] += delta;
}
}
}
@@ -1309,11 +1308,18 @@ HttpSM::state_api_callout(int event, void *data)
STATE_ENTER(&HttpSM::state_api_callout, event);
}
+ if (api_timer < 0) {
+ // This happens when either the plugin lock was missed and the hook rescheduled or
+ // the transaction got an event without the plugin calling TsHttpTxnReenable().
+ // The call chain does not recurse here if @a api_timer < 0 which means this call
+ // is the first from an event dispatch in this case.
+ milestone_update_api_time(milestones, api_timer);
+ }
+
switch (event) {
case EVENT_INTERVAL:
ink_assert(pending_action == data);
pending_action = NULL;
- milestone_update_api_time(milestones, api_timer);
// FALLTHROUGH
case EVENT_NONE:
case HTTP_API_CONTINUE:
@@ -1360,10 +1366,14 @@ HttpSM::state_api_callout(int event, void *data)
plugin_lock = MUTEX_TAKE_TRY_LOCK(cur_hook->m_cont->mutex, mutex->thread_holding);
if (!plugin_lock) {
- api_timer = -Thread::get_hrtime();
+ api_timer = -Thread::get_hrtime_updated();
HTTP_SM_SET_DEFAULT_HANDLER(&HttpSM::state_api_callout);
ink_assert(pending_action == NULL);
pending_action = mutex->thread_holding->schedule_in(this, HRTIME_MSECONDS(10));
+ // Should @a callout_state be reset back to HTTP_API_NO_CALLOUT here? Because the default
+ // handler has been changed the value isn't important to the rest of the state machine
+ // but not resetting means there is no way to reliably detect re-entrance to this state with an
+ // outstanding callout.
return 0;
}
} else {
@@ -1376,14 +1386,15 @@ HttpSM::state_api_callout(int event, void *data)
APIHook *hook = cur_hook;
cur_hook = cur_hook->next();
- api_timer = Thread::get_hrtime();
+ if (!api_timer)
+ api_timer = Thread::get_hrtime_updated();
hook->invoke(TS_EVENT_HTTP_READ_REQUEST_HDR + cur_hook_id, this);
- if (api_timer > 0) {
+ if (api_timer > 0) { // true if the hook did not call TxnReenable()
milestone_update_api_time(milestones, api_timer);
- api_timer = -Thread::get_hrtime(); // set in order to track non-active callout duration
+ api_timer = -Thread::get_hrtime_updated(); // set in order to track non-active callout duration
// which means that if we get back from the invoke with api_timer < 0 we're already
// tracking a non-complete callout from a chain so just let it ride. It will get cleaned
- // up in state_api_callback.
+ // up in state_api_callback when the plugin re-enables this transaction.
}
if (plugin_lock) {