Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

BUG -> PhysicalConnection System.NullReferenceException: #2576

Closed
DeepWorksStudios opened this issue Oct 19, 2023 · 8 comments · Fixed by #2629
Closed

BUG -> PhysicalConnection System.NullReferenceException: #2576

DeepWorksStudios opened this issue Oct 19, 2023 · 8 comments · Fixed by #2629

Comments

@DeepWorksStudios
Copy link

DeepWorksStudios commented Oct 19, 2023

Under high load of my development environment the StackExchange.Redis PhysicalConnection class on internal void WriteHeader causes a uncaught exception without any clue. I am using the latest redis release on Ubuntu and the latest nuget version of stackexchange redis

Line 832 -> var span = _ioPipe!.Output.GetSpan(commandBytes.Length + 8 + Format.MaxInt32TextLen + Format.MaxInt32TextLen);

It seems like for no explainable reason the variable _ioPipe is null which causes the exception

Exception data ↓↓

  Name Value Type
$exception {"Object reference not set to an instance of an object."} System.NullReferenceException
  ▶ Data {System.Collections.ListDictionaryInternal} System.Collections.IDictionary {System.Collections.ListDictionaryInternal}
  HResult -2147467261 int
  HasBeenThrown true bool
  HelpLink null string
  ▶ InnerException null System.Exception
  Message "Object reference not set to an instance of an object." string
  SerializationStackTraceString " at StackExchange.Redis.PhysicalConnection.WriteHeader(RedisCommand command, Int32 arguments, CommandBytes commandBytes) in /_/src/StackExchange.Redis/PhysicalConnection.cs:line 809" string
  SerializationWatsonBuckets null object
  Source "StackExchange.Redis" string
  StackTrace " at StackExchange.Redis.PhysicalConnection.WriteHeader(RedisCommand command, Int32 arguments, CommandBytes commandBytes) in /_/src/StackExchange.Redis/PhysicalConnection.cs:line 832" string
  ▶ TargetSite {Void WriteHeader(StackExchange.Redis.RedisCommand, Int32, StackExchange.Redis.CommandBytes)} System.Reflection.MethodBase {System.Reflection.RuntimeMethodInfo}
  _HResult -2147467261 int
  ▶ _data {System.Collections.ListDictionaryInternal} System.Collections.IDictionary {System.Collections.ListDictionaryInternal}
  _dynamicMethods null object[]
  _exceptionMethod null System.Reflection.MethodBase
  _helpURL null string
  ▶ _innerException null System.Exception
  _ipForWatsonBuckets 0x00007ffa328be781 System.UIntPtr
  _message "Object reference not set to an instance of an object." string
  _remoteStackTraceString null string
  _source null string
  ▶ _stackTrace {sbyte[48]} byte[] {sbyte[]}
  _stackTraceString null string
  _watsonBuckets null byte[]
  _xcode -532462766 int
  _xptrs 0x0000000000000000 System.IntPtr
  ▶ Static members    

Callstack data ↓↓

StackExchange.Redis.dll!StackExchange.Redis.PhysicalConnection.WriteHeader(StackExchange.Redis.RedisCommand command, int arguments, StackExchange.Redis.CommandBytes commandBytes) Line 832	C#
StackExchange.Redis.dll!StackExchange.Redis.Message.CommandValueValueMessage.WriteImpl(StackExchange.Redis.PhysicalConnection physical) Line 1503	C#
StackExchange.Redis.dll!StackExchange.Redis.Message.WriteTo(StackExchange.Redis.PhysicalConnection physical) Line 699	C#
StackExchange.Redis.dll!StackExchange.Redis.PhysicalBridge.WriteMessageToServerInsideWriteLock(StackExchange.Redis.PhysicalConnection connection, StackExchange.Redis.Message message) Line 1508	C#
StackExchange.Redis.dll!StackExchange.Redis.PhysicalBridge.WriteMessageInsideLock(StackExchange.Redis.PhysicalConnection physical, StackExchange.Redis.Message message) Line 713	C#
StackExchange.Redis.dll!StackExchange.Redis.PhysicalBridge.WriteMessageTakingWriteLockAsync_Awaited(System.Threading.Tasks.Task<bool> pending, StackExchange.Redis.PhysicalConnection physical, StackExchange.Redis.Message message) Line 1277	C#
[Resuming Async Method]	
System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder<StackExchange.Redis.WriteResult>.AsyncStateMachineBox<StackExchange.Redis.PhysicalBridge.<WriteMessageTakingWriteLockAsync_Awaited>d__106>.ExecutionContextCallback(object s) Line 287	C#
System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 183	C#
System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder<StackExchange.Redis.WriteResult>.AsyncStateMachineBox<StackExchange.Redis.PhysicalBridge.<WriteMessageTakingWriteLockAsync_Awaited>d__106>.MoveNext(System.Threading.Thread threadPoolThread) Line 324	C#
System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder<StackExchange.Redis.WriteResult>.AsyncStateMachineBox<StackExchange.Redis.PhysicalBridge.<WriteMessageTakingWriteLockAsync_Awaited>d__106>.MoveNext() Line 302	C#
System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.OutputWaitEtwEvents.AnonymousMethod__12_0(System.Action innerContinuation, System.Threading.Tasks.Task innerTask) Line 301	C#
System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.System.Threading.IThreadPoolWorkItem.Execute() Line 647	C#
System.Private.CoreLib.dll!System.Threading.ThreadPoolWorkQueue.Dispatch() Line 924	C#
System.Private.CoreLib.dll!System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart() Line 77	C#
[Async Call Stack]	
[Async] StackExchange.Redis.dll!StackExchange.Redis.ServerEndPoint.WriteDirectOrQueueFireAndForgetAsync.__Awaited|131_0<bool>(System.Threading.Tasks.ValueTask<StackExchange.Redis.WriteResult> l_result) Line 848	C#
[Async] StackExchange.Redis.dll!StackExchange.Redis.ServerEndPoint.HandshakeAsync(StackExchange.Redis.PhysicalConnection connection, StackExchange.Redis.LogProxy log) Line 930	C#
@DeepWorksStudios DeepWorksStudios changed the title PhysicalConnection System.NullReferenceException: BUG -> PhysicalConnection System.NullReferenceException: Oct 19, 2023
@DeepWorksStudios
Copy link
Author

DeepWorksStudios commented Oct 20, 2023

@NickCraver Could you try to reproduce it. The case would be on windows install Ubuntu via wsl2 and run there redis and run a test web api that try to establish a connection to the redis client while running the web api than try to increase the cpu load via as exsample windows defender full anti virus scan than the load will be 90 till 100% and than always this is the result

@DeepWorksStudios
Copy link
Author

Since i updated to .net 8 i need to remove redis completly since now nothing works anymore not even under normal load

"StackExchange.Redis.RedisTimeoutException: 'Timeout performing UNSUBSCRIBE (10ms), inst: 1, qu: 0, qs: 0, aw: False, bw: Inactive, rs: ReadAsync, ws: Idle, in: 0, in-pipe: 0, out-pipe: 0, last-in: 0, cur-in: 0, sync-ops: 1, async-ops: 4, serverEndpoint: 127.0.0.1:6379, conn-sec: 2,76, aoc: 0, mc: 1/1/0, mgr: 10 of 10 available, clientName: DESKTOP-NO01VLO(SE.Redis-v2.6.122.38350), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=1,Free=32766,Min=12,Max=32767), POOL: (Threads=6,QueuedItems=0,CompletedItems=312,Timers=7), v: 2.6.122.38350 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)'"

@mgravell
Copy link
Collaborator

@DeepWorksStudios I am very interested, from both a "redis library" aspect and from a "I'm a small part of the .NET 8 team" aspect. So: is there any more context you can give me here about what you saw? What kind of application this was, for example? If it was ASP.NET then I'm even more intrigued, and I can carve out dedicated work time to try and investigate, but other environments: still very much of interest.

@DeepWorksStudios
Copy link
Author

DeepWorksStudios commented Nov 23, 2023

image

It's an ASP.Net Core Web API: On.net 7, it just happens under load; in.net 8, different problems arise, and basically, it's not functional at all

I'm using SignalR Redis (AddStackExchangeRedisCache)
And distribute memory (AddStackExchangeRedisCache).
As well, I implemented a self created RedisHelthCheck

@mgravell

@DeepWorksStudios
Copy link
Author

Any updates?

@jlao
Copy link

jlao commented Jan 9, 2024

I'm not sure if it's exactly the same, but I saw this in logs when we had a network outage due to a network switch getting rebooted.

We have logs hooked up to the mux callbacks:

ConnectionFailed: SocketFailure (ReadSocketError/TimedOut, last-recv: 413) on 10.10.70.233:6001/Interactive, Flushed/Faulted, last: GET, origin: ReadFromPipe, outstanding: 2, last-read: 23s ago, last-write: 18s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 9 of 10 available, in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.6.104.40210

ConnectionFailed: SocketFailure (ReadSocketError/TimedOut, last-recv: 770) on 10.10.70.231:6001/Interactive, Flushed/Faulted, last: GET, origin: ReadFromPipe, outstanding: 2, last-read: 23s ago, last-write: 18s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 9 of 10 available, in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.6.104.40210

InternalError: System.NullReferenceException: Object reference not set to an instance of an object.
	   at StackExchange.Redis.PhysicalConnection.WriteHeader(RedisCommand command, Int32 arguments, CommandBytes commandBytes) in /_/src/StackExchange.Redis/PhysicalConnection.cs:line 809
	   at StackExchange.Redis.RedisTransaction.TransactionMessage.WriteImpl(PhysicalConnection physical) in /_/src/StackExchange.Redis/RedisTransaction.cs:line 439
	   at StackExchange.Redis.Message.WriteTo(PhysicalConnection physical) in /_/src/StackExchange.Redis/Message.cs:line 706

@jlao
Copy link

jlao commented Jan 9, 2024

Forgot to add that we're using version 2.6.104

NickCraver added a commit that referenced this issue Jan 11, 2024
This adds a bit of null ref handling (few ifs). Fixes #2576.
@NickCraver
Copy link
Collaborator

Thanks for the report and stacks here, much appreciated :) Adding some handling for this in #2629.

NickCraver added a commit that referenced this issue Jan 11, 2024
This adds a bit of null ref handling (few ifs). Fixes #2576.

Overall, this is biting people in the shutdown race, more likely under load, so let's eat the if checks here to prevent it. I decided to go with the specific approach here as to not affect inlining.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants