Commit 5633b59a authored by Marc Gravell's avatar Marc Gravell

Merge branch 'feat/exceptiondata' of git@gitlab.stackexchange.com:core/stackexchange-redis.git

parents 7d3a92e0 8bea5864
...@@ -566,7 +566,9 @@ private void LogLockedWithThreadPoolStats(TextWriter log, string message) ...@@ -566,7 +566,9 @@ private void LogLockedWithThreadPoolStats(TextWriter log, string message)
{ {
var sb = new StringBuilder(); var sb = new StringBuilder();
sb.Append(message); sb.Append(message);
AppendThreadPoolStats(sb); string iocp, worker;
GetThreadPoolStats(out iocp, out worker);
sb.Append(", IOCP: ").Append(iocp).Append(", WORKER: ").Append(worker);
LogLocked(log, sb.ToString()); LogLocked(log, sb.ToString());
} }
} }
...@@ -1863,6 +1865,7 @@ internal T ExecuteSyncImpl<T>(Message message, ResultProcessor<T> processor, Ser ...@@ -1863,6 +1865,7 @@ internal T ExecuteSyncImpl<T>(Message message, ResultProcessor<T> processor, Ser
Trace("Timeout performing " + message.ToString()); Trace("Timeout performing " + message.ToString());
Interlocked.Increment(ref syncTimeouts); Interlocked.Increment(ref syncTimeouts);
string errMessage; string errMessage;
List<Tuple<string, string>> data = null;
if (server == null || !IncludeDetailInExceptions) if (server == null || !IncludeDetailInExceptions)
{ {
errMessage = "Timeout performing " + message.Command.ToString(); errMessage = "Timeout performing " + message.Command.ToString();
...@@ -1870,21 +1873,35 @@ internal T ExecuteSyncImpl<T>(Message message, ResultProcessor<T> processor, Ser ...@@ -1870,21 +1873,35 @@ internal T ExecuteSyncImpl<T>(Message message, ResultProcessor<T> processor, Ser
else else
{ {
int inst, qu, qs, qc, wr, wq, @in, ar; int inst, qu, qs, qc, wr, wq, @in, ar;
string iocp, worker;
#if !__MonoCS__ #if !__MonoCS__
var mgrState = socketManager.State; var mgrState = socketManager.State;
#endif #endif
var sb = new StringBuilder("Timeout performing ").Append(message.CommandAndKey);
data = new List<Tuple<string, string>> {Tuple.Create("Message", message.CommandAndKey)};
Action<string, string, string> add = (lk, sk, v) =>
{
data.Add(Tuple.Create(lk, v));
sb.Append(", " + sk + ": " + v);
};
int queue = server.GetOutstandingCount(message.Command, out inst, out qu, out qs, out qc, out wr, out wq, out @in, out ar); int queue = server.GetOutstandingCount(message.Command, out inst, out qu, out qs, out qc, out wr, out wq, out @in, out ar);
var sb = new StringBuilder("Timeout performing ").Append(message.CommandAndKey) GetThreadPoolStats(out iocp, out worker);
.Append(", inst: ").Append(inst) add("Instantaneous", "inst", inst.ToString());
#if !__MonoCS__ #if !__MonoCS__
.Append(", mgr: ").Append(mgrState) add("Manager-State", "mgr", mgrState.ToString());
#endif #endif
.Append(", queue: ").Append(queue).Append(", qu=").Append(qu) add("Queue-Length", "queue", queue.ToString());
.Append(", qs=").Append(qs).Append(", qc=").Append(qc) add("Queue-Outstanding", "qu", qu.ToString());
.Append(", wr=").Append(wr).Append("/").Append(wq) add("Queue-Awaiting-Response", "qs", qs.ToString());
.Append(", in=").Append(@in).Append("/").Append(ar); add("Queue-Completion-Outstanding", "qc", qc.ToString());
add("Active-Writers", "wr", wr.ToString());
AppendThreadPoolStats(sb); add("Write-Queue", "wq", wq.ToString());
add("Inbound-Bytes", "in", @in.ToString());
add("Active-Readers", "ar", ar.ToString());
add("ThreadPool-IO-Completion", "IOCP", iocp);
add("ThreadPool-Workers", "WORKER", worker);
errMessage = sb.ToString(); errMessage = sb.ToString();
if (stormLogThreshold >= 0 && queue >= stormLogThreshold && Interlocked.CompareExchange(ref haveStormLog, 1, 0) == 0) if (stormLogThreshold >= 0 && queue >= stormLogThreshold && Interlocked.CompareExchange(ref haveStormLog, 1, 0) == 0)
...@@ -1894,7 +1911,15 @@ internal T ExecuteSyncImpl<T>(Message message, ResultProcessor<T> processor, Ser ...@@ -1894,7 +1911,15 @@ internal T ExecuteSyncImpl<T>(Message message, ResultProcessor<T> processor, Ser
else Interlocked.Exchange(ref stormLogSnapshot, log); else Interlocked.Exchange(ref stormLogSnapshot, log);
} }
} }
throw ExceptionFactory.Timeout(IncludeDetailInExceptions, errMessage, message, server); var timeoutEx = ExceptionFactory.Timeout(IncludeDetailInExceptions, errMessage, message, server);
if (data != null)
{
foreach (var kv in data)
{
timeoutEx.Data["Redis-" + kv.Item1] = kv.Item2;
}
}
throw timeoutEx;
// very important not to return "source" to the pool here // very important not to return "source" to the pool here
} }
} }
...@@ -1907,7 +1932,7 @@ internal T ExecuteSyncImpl<T>(Message message, ResultProcessor<T> processor, Ser ...@@ -1907,7 +1932,7 @@ internal T ExecuteSyncImpl<T>(Message message, ResultProcessor<T> processor, Ser
return val; return val;
} }
} }
private static void AppendThreadPoolStats(StringBuilder errorMessage) private static void GetThreadPoolStats(out string iocp, out string worker)
{ {
//BusyThreads = TP.GetMaxThreads() –TP.GetAVailable(); //BusyThreads = TP.GetMaxThreads() –TP.GetAVailable();
//If BusyThreads >= TP.GetMinThreads(), then threadpool growth throttling is possible. //If BusyThreads >= TP.GetMinThreads(), then threadpool growth throttling is possible.
...@@ -1924,8 +1949,8 @@ private static void AppendThreadPoolStats(StringBuilder errorMessage) ...@@ -1924,8 +1949,8 @@ private static void AppendThreadPoolStats(StringBuilder errorMessage)
int busyIoThreads = maxIoThreads - freeIoThreads; int busyIoThreads = maxIoThreads - freeIoThreads;
int busyWorkerThreads = maxWorkerThreads - freeWorkerThreads; int busyWorkerThreads = maxWorkerThreads - freeWorkerThreads;
errorMessage.AppendFormat(", IOCP:(Busy={0},Free={1},Min={2},Max={3})", busyIoThreads, freeIoThreads, minIoThreads, maxIoThreads); iocp = string.Format("(Busy={0},Free={1},Min={2},Max={3})", busyIoThreads, freeIoThreads, minIoThreads, maxIoThreads);
errorMessage.AppendFormat(", WORKER:(Busy={0},Free={1},Min={2},Max={3})", busyWorkerThreads, freeWorkerThreads, minWorkerThreads, maxWorkerThreads); worker = string.Format("(Busy={0},Free={1},Min={2},Max={3})", busyWorkerThreads, freeWorkerThreads, minWorkerThreads, maxWorkerThreads);
} }
/// <summary> /// <summary>
......
...@@ -177,23 +177,42 @@ public void RecordConnectionFailed(ConnectionFailureType failureType, Exception ...@@ -177,23 +177,42 @@ public void RecordConnectionFailed(ConnectionFailureType failureType, Exception
lastBeat = Thread.VolatileRead(ref lastBeatTickCount); lastBeat = Thread.VolatileRead(ref lastBeatTickCount);
int unansweredRead = Thread.VolatileRead(ref firstUnansweredWriteTickCount); int unansweredRead = Thread.VolatileRead(ref firstUnansweredWriteTickCount);
string message = failureType + " on " + Format.ToString(bridge.ServerEndPoint.EndPoint) + "/" + connectionType var exMessage = new StringBuilder(failureType + " on " + Format.ToString(bridge.ServerEndPoint.EndPoint) + "/" + connectionType);
+ ", origin: " + origin var data = new List<Tuple<string, string>>
+ ", input-buffer: " + ioBufferBytes + ", outstanding: " + GetSentAwaitingResponseCount() {
+ ", last-read: " + unchecked(now - lastRead) / 1000 + "s ago, last-write: " + unchecked(now - lastWrite) / 1000 + "s ago" Tuple.Create("FailureType", failureType.ToString()),
+ ", unanswered-write: " + unchecked(now - unansweredRead) / 1000 + "s ago" Tuple.Create("EndPoint", Format.ToString(bridge.ServerEndPoint.EndPoint))
+ ", keep-alive: " + bridge.ServerEndPoint.WriteEverySeconds + "s, pending: " };
+ bridge.GetPendingCount() + ", state: " + oldState + ", last-heartbeat: " + (lastBeat == 0 ? "never" : (unchecked(now - lastBeat) / 1000 + "s ago")) Action<string, string, string> add = (lk, sk, v) =>
+ (bridge.IsBeating ? " (mid-beat)" : "") + ", last-mbeat: " + multiplexer.LastHeartbeatSecondsAgo + "s ago, global: " {
+ ConnectionMultiplexer.LastGlobalHeartbeatSecondsAgo + "s ago" data.Add(Tuple.Create(lk, v));
exMessage.Append(", " + sk + ": " + v);
};
add("Origin", "origin", origin);
add("Input-Buffer", "input-buffer", ioBufferBytes.ToString());
add("Outstanding-Responses", "outstanding", GetSentAwaitingResponseCount().ToString());
add("Last-Read", "last-read", unchecked(now - lastRead) / 1000 + "s ago");
add("Last-Write", "last-write", unchecked(now - lastWrite) / 1000 + "s ago");
add("Unanswered-Write", "unanswered-write", unchecked(now - unansweredRead) / 1000 + "s ago");
add("Keep-Alive", "keep-alive", bridge.ServerEndPoint.WriteEverySeconds + "s");
add("Pending", "pending", bridge.GetPendingCount().ToString());
add("Previous-Physical-State", "state", oldState.ToString());
add("Last-Heartbeat", "last-heartbeat", (lastBeat == 0 ? "never" : (unchecked(now - lastBeat)/1000 + "s ago"))+ (bridge.IsBeating ? " (mid-beat)" : "") );
add("Last-Multiplexer-Heartbeat", "last-mbeat", multiplexer.LastHeartbeatSecondsAgo + "s ago");
add("Last-Global-Heartbeat", "global", ConnectionMultiplexer.LastGlobalHeartbeatSecondsAgo + "s ago");
#if !__MonoCS__ #if !__MonoCS__
+ ", mgr: "+ bridge.Multiplexer.SocketManager.State add("SocketManager-State", "mgr", bridge.Multiplexer.SocketManager.State.ToString());
#endif #endif
;
var ex = innerException == null var ex = innerException == null
? new RedisConnectionException(failureType, message) ? new RedisConnectionException(failureType, exMessage.ToString())
: new RedisConnectionException(failureType, message, innerException); : new RedisConnectionException(failureType, exMessage.ToString(), innerException);
foreach (var kv in data)
{
ex.Data["Redis-" + kv.Item1] = kv.Item2;
}
bridge.OnConnectionFailed(this, failureType, ex); bridge.OnConnectionFailed(this, failureType, ex);
} }
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment