Discuss test project

[lukebakken]

@gradx - I'm assuming if the issue happens during a load test run, it will appear in the Genie.IngressConsumer output, yes?

C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer [main ≡]
> dotnet run
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Services\Rabbi
tMQServiceSingleThreaded.cs(38,93): warning CS8620: Argument of type 'Dictionary<string, object>' cannot be used for
 parameter 'arguments' of type 'IDictionary<string, object?>' in 'Task<QueueDeclareOk> IChannel.QueueDeclareAsync(st
ring queue, bool durable, bool exclusive, bool autoDelete, IDictionary<string, object?>? arguments = null, bool pass
ive = false, bool noWait = false, CancellationToken cancellationToken = default(CancellationToken))' due to differen
ces in the nullability of reference types. [C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\Geni
eDotNet\Genie.IngressConsumer\Genie.IngressConsumer.csproj]
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Services\Rabbi
tMQService.cs(47,93): warning CS8620: Argument of type 'Dictionary<string, object>' cannot be used for parameter 'ar
guments' of type 'IDictionary<string, object?>' in 'Task<QueueDeclareOk> IChannel.QueueDeclareAsync(string queue, bo
ol durable, bool exclusive, bool autoDelete, IDictionary<string, object?>? arguments = null, bool passive = false, b
ool noWait = false, CancellationToken cancellationToken = default(CancellationToken))' due to differences in the nul
lability of reference types. [C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.
IngressConsumer\Genie.IngressConsumer.csproj]
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Services\Rabbi
tMQServiceSingleThreaded.cs(101,77): warning CS8602: Dereference of a possibly null reference. [C:\Users\lbakken\dev
elopment\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Genie.IngressConsumer.csproj]
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Services\Rabbi
tMQServiceSingleThreaded.cs(123,43): warning CS8602: Dereference of a possibly null reference. [C:\Users\lbakken\dev
elopment\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Genie.IngressConsumer.csproj]
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Services\Rabbi
tMQServiceSingleThreaded.cs(78,18): warning CS0219: The variable 'useAvro' is assigned but its value is never used [
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Genie.IngressC
onsumer.csproj]
Starting RabbitMQ Pump: System.Threading.CancellationToken
[8:14:48 AM] Overall 153 Period: 153
[8:14:58 AM] Overall 289 Period: 2509
[8:15:11 AM] Overall 402 Period: 1858
[8:15:22 AM] Overall 507 Period: 2320
[8:15:36 AM] Overall 590 Period: 172

[lukebakken]

@gradx I assume that since I did not see any exceptions, and that crank provided the following output, that I did not reproduce the issue. Is this correct?

C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Crank>crank --config benchmark.yaml --scenario hello --profile local
[08:10:15.473] Running session 'f4bb29c975b2418b836f90f9590f670b' with description ''
[08:10:15.497] Starting job 'application' ...
[08:10:15.585] Submitted job: http://localhost:5010/jobs/1
[08:10:17.636] 'application' has been selected by the server ...
[08:10:17.637] Using local folder: "C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\"
[08:10:40.438] Uploading C:\Users\lbakken\AppData\Local\Temp\tmpgemjk2.tmp (288,686KB)
[08:10:41.502] 'application' is now building ... http://localhost:5010/jobs/1/buildlog
[08:11:53.176] 'application' is running ... http://localhost:5010/jobs/1/output
[08:11:53.182] Starting job 'load' ...
[08:11:53.184] Submitted job: http://localhost:5010/jobs/2
[08:11:55.204] 'load' has been selected by the server ...
[08:11:55.205] 'load' is now building ... http://localhost:5010/jobs/2/buildlog
[08:12:04.312] 'load' is running ... http://localhost:5010/jobs/2/output
[09:40:47.031] Stopping job 'load' ...
[09:40:48.347] Deleting job 'load' ...
[09:40:48.356] Stopping job 'application' ...
[09:40:49.488] Deleting job 'application' ...

| application             |                    |
| ----------------------- | ------------------ |
| Max CPU Usage (%)       | 2                  |
| Max Cores usage (%)     | 31                 |
| Max Working Set (MB)    | 361                |
| Max Private Memory (MB) | 347                |
| Build Time (ms)         | 37,482             |
| Start Time (ms)         | 5,110              |
| Published Size (KB)     | 196,396            |
| Symbols Size (KB)       | 112                |
| .NET Core SDK Version   | 8.0.401            |
| ASP.NET Core Version    | 8.0.8+954f61dd38b3 |
| .NET Runtime Version    | 8.0.8+08338fcaa5c9 |


| load                    |                    |
| ----------------------- | ------------------ |
| Max CPU Usage (%)       | 3                  |
| Max Cores usage (%)     | 43                 |
| Max Working Set (MB)    | 42                 |
| Max Private Memory (MB) | 37                 |
| Build Time (ms)         | 4,925              |
| Start Time (ms)         | 751                |
| Published Size (KB)     | 72,368             |
| Symbols Size (KB)       | 0                  |
| .NET Core SDK Version   | 8.0.401            |
| ASP.NET Core Version    | 8.0.8+954f61dd38b3 |
| .NET Runtime Version    | 8.0.8+08338fcaa5c9 |
| First Request (ms)      | 1,230              |

[gradx]

That is correct. You'll need to run it for a longer duration. In multithreaded mode the error appears within the first few minutes.

[lukebakken]

You'll need to run it for a longer duration

How do I do that?

[gradx]

@gradx - I'm assuming if the issue happens during a load test run, it will appear in the Genie.IngressConsumer output, yes?

C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer [main ≡]
> dotnet run
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Services\Rabbi
tMQServiceSingleThreaded.cs(38,93): warning CS8620: Argument of type 'Dictionary<string, object>' cannot be used for
 parameter 'arguments' of type 'IDictionary<string, object?>' in 'Task<QueueDeclareOk> IChannel.QueueDeclareAsync(st
ring queue, bool durable, bool exclusive, bool autoDelete, IDictionary<string, object?>? arguments = null, bool pass
ive = false, bool noWait = false, CancellationToken cancellationToken = default(CancellationToken))' due to differen
ces in the nullability of reference types. [C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\Geni
eDotNet\Genie.IngressConsumer\Genie.IngressConsumer.csproj]
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Services\Rabbi
tMQService.cs(47,93): warning CS8620: Argument of type 'Dictionary<string, object>' cannot be used for parameter 'ar
guments' of type 'IDictionary<string, object?>' in 'Task<QueueDeclareOk> IChannel.QueueDeclareAsync(string queue, bo
ol durable, bool exclusive, bool autoDelete, IDictionary<string, object?>? arguments = null, bool passive = false, b
ool noWait = false, CancellationToken cancellationToken = default(CancellationToken))' due to differences in the nul
lability of reference types. [C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.
IngressConsumer\Genie.IngressConsumer.csproj]
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Services\Rabbi
tMQServiceSingleThreaded.cs(101,77): warning CS8602: Dereference of a possibly null reference. [C:\Users\lbakken\dev
elopment\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Genie.IngressConsumer.csproj]
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Services\Rabbi
tMQServiceSingleThreaded.cs(123,43): warning CS8602: Dereference of a possibly null reference. [C:\Users\lbakken\dev
elopment\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Genie.IngressConsumer.csproj]
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Services\Rabbi
tMQServiceSingleThreaded.cs(78,18): warning CS0219: The variable 'useAvro' is assigned but its value is never used [
C:\Users\lbakken\development\lukebakken\rabbitmq-dotnet-client-1660\GenieDotNet\Genie.IngressConsumer\Genie.IngressC
onsumer.csproj]
Starting RabbitMQ Pump: System.Threading.CancellationToken
[8:14:48 AM] Overall 153 Period: 153
[8:14:58 AM] Overall 289 Period: 2509
[8:15:11 AM] Overall 402 Period: 1858
[8:15:22 AM] Overall 507 Period: 2320
[8:15:36 AM] Overall 590 Period: 172

rabbitmq-dotnet-client-1660/GenieDotNet/Crank/benchmark.yaml

Line 82 in 480fb22

duration: 28800

[gradx]

Thanks. I do not have the time to figure stuff like that out on my own, so I appreciate you pointing it out.

I'll try 10x longer next time, which will be next week.

Unless you edited the file it should have run for 8 hours. The single threaded version seems to exit after an error.

[lukebakken]

The single threaded version seems to exit after an error.

Should I have seen something in one of my console windows? I did not see any stack traces, exceptions, etc

[gradx]

The single threaded version seems to exit after an error.

Should I have seen something in one of my console windows? I did not see any stack traces, exceptions, etc

Yes. If there's no c:\temp\rabbiterror.log then it appears you had an external error which couldn't be handled.

[lukebakken]

Yep, that file is not there. I will return to this next week. I appreciate the much simpler project that you provided, thanks.

[gradx]

Yep, that file is not there. I will return to this next week. I appreciate the much simpler project that you provided, thanks.

That's fine. The issue you experienced is quite different from mine. The agent should not have stopped running, something interfered with it. The dramatic drop in your request rate shows something else was happening before it stopped:

[8:15:22 AM] Overall 507 Period: 2320
[8:15:36 AM] Overall 590 Period: 172

I suggest you try shorter intervals (30-60 seconds) and confirm the agent is working correctly.

One last note, the version you're testing is using object pooling which should help you encounter the error within an hour.

If you comment it out a long with

command.GeniePool.Return(pooledObj);

and uncomment the other two lines it will create and dispose the objects on every call but the request rate drops top 20//sec and it'll was a few hours before I encountered the error.

rabbitmq-dotnet-client-1660/GenieDotNet/Genie.Web.Api/Mediator/Commands/RabbitMQCommand.cs

Line 22 in 480fb22

var pooledObj = command.GeniePool.Get();

[lukebakken]

@gradx - you must not use the body outside of the Received event handler. If you do, it must be copied, as the memory is reclaimed when the event handler exits

/~https://github.com/lukebakken/rabbitmq-dotnet-client-1660/pull/3/files#diff-80abe01ed5555f837d89dda4ebefde408b654d8c75321261236314400e4e3299R85

I'm 99.99% certain this is the cause of your issue. It's probably not as well-documented as it should be.

If I have time I may have some suggestions for interacting with the consumer that could work better than using reset events.