PV stops processing

[cortlandstarrett]

After message throttling was implemented, situations occur where PV processing stops. It looks like messages on the reception channel stop being received, but it is not yet clear. This was first exposed while running hard enough to exercise the throttling mechanism.

The first plan is to run without throttling long enough to gain confidence in the non-throttled AMQP.

[cortlandstarrett]

git/munin/deploy git:(262_message_throttling_lps) ✗ docker logs deploy-aeo_svdc_proc-4
Starting Process AEO_SVDC_PROC
Included utility MetaData
Included utility ActiveMQ
Program Error :Timer 364621 not found.

This was encountered trying to run 8m events.

Something happened:

job_success: 89329 job_fail: 1

[cortlandstarrett]

Interestingly, there are messages queued on topics that are never consumed.

[cortlandstarrett]

It just stopped processing. Memory usage was high.

CONTAINER ID NAME CPU % MEM USAGE / LIMIT MEM % NET I/O BLOCK I/O PIDS
0c3a0ec5c1de deploy-aeo_svdc_proc-1 0.00% 2.051GiB / 23.43GiB 8.75% 6.62GB / 121MB 32.2MB / 445MB 7
ab6c30e06f1e deploy-istore_proc-1 0.00% 4.289MiB / 23.43GiB 0.02% 34.2kB / 33kB 7.84MB / 16.4kB 7
7ee4354ca755 deploy-aeo_svdc_proc-3 0.00% 2.108GiB / 23.43GiB 8.99% 6.62GB / 121MB 23MB / 377MB 7
3a44aba67450 deploy-jm_proc-1 0.02% 13.55GiB / 23.43GiB 57.81% 2.65GB / 6.56GB 204MB / 1.15GB 7
bf00df139faa deploy-aeo_svdc_proc-4 0.00% 2.435GiB / 23.43GiB 10.39% 6.62GB / 119MB 139kB / 0B 7
4932b95434c0 deploy-aeo_svdc_proc-2 0.00% 2.092GiB / 23.43GiB 8.93% 6.62GB / 119MB 8.02MB / 378MB 7
72dfe3339fc1 deploy-apache-activemq-1 0.18% 357.8MiB / 23.43GiB 1.49% 9.63GB / 29.4GB 87.8MB / 21.6MB 87

More interesting is that the the Reception topic is not dequeued:

[cortlandstarrett]

Nothing interesting in the logs. Everything else looked normal. It just seemed to stop receiving.

[cortlandstarrett]

Next, I am slowing down to take stress out of the equation.

[cortlandstarrett]

Cuz it occurred to me that maybe a brief slow spot caused a few unassigned jobs and maybe some throttling... but I doubt it. MaxUnassigned is 2000, and I did not see any.

[cortlandstarrett]

I reproduced the lost Timer running more slowly (2000 e/s for 8 million).

docker logs deploy-aeo_svdc_proc-4
Starting Process AEO_SVDC_PROC
Included utility MetaData
Included utility ActiveMQ
Program Error :Timer 609835 not found.
Stack:

This happened on all 4 svdcs at about the same time. Even the timer number was similar (not identical) between containers.

I have now edited the docker compose file and added (back):

ulimits:
sigpending: -1

Running the same slow, long steady configuration.

[cortlandstarrett]

I am suspicious of memory usage and that timer resource exhaustion.

[cortlandstarrett]

How is the mapping of _service done now? I looked in the old services.hh file...

[answer: Find the enumeration in ____interface.hh]

[cortlandstarrett]

All of the domains except for iStore are using significantly more memory than before.
After 1 hour JM is at 13G. SVDCs are above 2G.

[cortlandstarrett]

With ulimits raised, it took longer, but I hit:

docker logs deploy-aeo_svdc_proc-1
Starting Process AEO_SVDC_PROC
Included utility MetaData
Included utility ActiveMQ
Program Error :Timer 1646697 not found.

2 of the 4 SVDCs died

I notice this timer number is larger and perhaps proportionally longer by run time and number of events processed.

I do note that PV is carrying with the remaining 2 workers! Yay!

[cortlandstarrett]

rcvd_events: in the dashboard quit updating after 2 of the workers exited. Investigate why.

[cortlandstarrett]

I was not watching to see it, but it looks like PV quit responding to the Reception topic after 7.7M events.

[cortlandstarrett]

next steps:

• Investigate Timer not found.
• Investigate the AMQP topics which have unconsumed messages. [See comment below.]
• Attach Inspector, calculate instance population and estimate memory usage.
• Investigate memory usage by architecture and messaging.
• Consider turning on logging on the architecture AMQP module.
• Consider turning on logging on the IDM module.
• Investigate rcvd_events and msgin_rate discrepancies (dashboard / InfoWarn). [See comment (rcvd_events and msgin_rate) below.)

[cortlandstarrett]

The AMQP topics that have unconsumed messages are 'Advisory' topics. I don't know what it means, but they are not the channels we are using for message passing.