Issue with Qpid Memory

classic Classic list List threaded Threaded
10 messages Options
Reply | Threaded
Open this post in threaded view
|

Issue with Qpid Memory

Venkat Jaligama
Hello Users,


We are having issue with memory of one of our prod QPID broker (version 1.38.0).

Qpid container memory is 4GB , every few days the memory starts spiking restarting the container.  Checked the Qpid connections, exchanges and queues they seem to be fine.  Any inputs about this issue is highly appreciated. I am attaching some stats from the Qpid which is having this issue


Broker Memory Statistics:
  Statistic        Value
  ================================
  malloc_arena     1,795,076,096
  malloc_keepcost  201,264
  malloc_ordblks   3,224
  malloc_uordblks  1,789,002,512
  malloc_hblkhd    5,328,896
  malloc_fordblks  6,073,584
  malloc_hblks     1

Aggregate Broker Statistics:
  Statistic                   Messages    Bytes
  ========================================================
  queue-depth                 528         453,204
  total-enqueues              54,163,898  46,069,896,320
  total-dequeues              54,163,370  46,069,443,116
  persistent-enqueues         0           0
  persistent-dequeues         0           0
  transactional-enqueues      25,833,943  16,024,501,474
  transactional-dequeues      25,830,811  15,980,385,184
  flow-to-disk-depth          0           0
  flow-to-disk-enqueues       0           0
  flow-to-disk-dequeues       0           0
  acquires                    54,164,189
  releases                    9
  discards-no-route           26,617,570
  discards-ttl-expired        10
  discards-limit-overflow     0
  discards-ring-overflow      0
  discards-lvq-replace        343
  discards-subscriber-reject  7,906
  discards-purged             1,140
  reroutes                    116,664
  abandoned                   3,562
  abandoned-via-alt           0



ACL Policy Statistics:
  Statistic          Value
  =============================================
  policy-file        /etc/qpid/qpidd.acl
  enforcing          Y
  has-transfer-acls  Y
  last-acl-load      Mon Feb 25 21:11:10 2019
  acl-denials        0



Thanks

Venkat
Reply | Threaded
Open this post in threaded view
|

Re: Issue with Qpid Memory

Gordon Sim
On 27/02/2019 11:29 pm, Venkat Jaligama wrote:
> Hello Users,
>
>
> We are having issue with memory of one of our prod QPID broker (version 1.38.0).
>
> Qpid container memory is 4GB , every few days the memory starts spiking restarting the container.  Checked the Qpid connections, exchanges and queues they seem to be fine.  Any inputs about this issue is highly appreciated.

What do you mean by 'spiking'? Is it a sudden very large increase in
memory consumed? Is there any activity that corresponds to this? Have
you observed any constant growth in memory apart from these 'spikes'?

> I am attaching some stats from the Qpid which is having this issue
>
>
> Broker Memory Statistics:
>    Statistic        Value
>    ================================
>    malloc_arena     1,795,076,096
>    malloc_keepcost  201,264
>    malloc_ordblks   3,224
>    malloc_uordblks  1,789,002,512
>    malloc_hblkhd    5,328,896
>    malloc_fordblks  6,073,584
>    malloc_hblks     1
>
> Aggregate Broker Statistics:
>    Statistic                   Messages    Bytes
>    ========================================================
>    queue-depth                 528         453,204
>    total-enqueues              54,163,898  46,069,896,320
>    total-dequeues              54,163,370  46,069,443,116
>    persistent-enqueues         0           0
>    persistent-dequeues         0           0
>    transactional-enqueues      25,833,943  16,024,501,474
>    transactional-dequeues      25,830,811  15,980,385,184
>    flow-to-disk-depth          0           0
>    flow-to-disk-enqueues       0           0
>    flow-to-disk-dequeues       0           0
>    acquires                    54,164,189
>    releases                    9
>    discards-no-route           26,617,570
>    discards-ttl-expired        10
>    discards-limit-overflow     0
>    discards-ring-overflow      0
>    discards-lvq-replace        343
>    discards-subscriber-reject  7,906
>    discards-purged             1,140
>    reroutes                    116,664
>    abandoned                   3,562
>    abandoned-via-alt           0
>
>
>
> ACL Policy Statistics:
>    Statistic          Value
>    =============================================
>    policy-file        /etc/qpid/qpidd.acl
>    enforcing          Y
>    has-transfer-acls  Y
>    last-acl-load      Mon Feb 25 21:11:10 2019
>    acl-denials        0
>
>
>
> Thanks
>
> Venkat
>


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Issue with Qpid Memory

Chester
Gordon,

We see several days of low/normal (.1 GB) memory usage, followed by a linear increase of about .15 GB per hour, until we OOM after about 24 hours. I've attached some graphs and a spreadsheet to help visualize.
1week_memory_usage.png
30day_memory_usage.png

We have not identified any pattern of activity associated with the changing memory utilization. Our workload has a fairly constant enqueue/dequeue rate. Most messages are expected to be queued for small numbers of seconds or less, with some longer living messages of a few hours. Messages are small (hundreds of bytes) and queues typically have less than 1MB of data at any given time.

Thanks,
Chester

On Thu, Feb 28, 2019 at 8:08 AM Gordon Sim <[hidden email]> wrote:
On 27/02/2019 11:29 pm, Venkat Jaligama wrote:
> Hello Users,
>
>
> We are having issue with memory of one of our prod QPID broker (version 1.38.0).
>
> Qpid container memory is 4GB , every few days the memory starts spiking restarting the container.  Checked the Qpid connections, exchanges and queues they seem to be fine.  Any inputs about this issue is highly appreciated.

What do you mean by 'spiking'? Is it a sudden very large increase in
memory consumed? Is there any activity that corresponds to this? Have
you observed any constant growth in memory apart from these 'spikes'?

> I am attaching some stats from the Qpid which is having this issue
>
>
> Broker Memory Statistics:
>    Statistic        Value
>    ================================
>    malloc_arena     1,795,076,096
>    malloc_keepcost  201,264
>    malloc_ordblks   3,224
>    malloc_uordblks  1,789,002,512
>    malloc_hblkhd    5,328,896
>    malloc_fordblks  6,073,584
>    malloc_hblks     1
>
> Aggregate Broker Statistics:
>    Statistic                   Messages    Bytes
>    ========================================================
>    queue-depth                 528         453,204
>    total-enqueues              54,163,898  46,069,896,320
>    total-dequeues              54,163,370  46,069,443,116
>    persistent-enqueues         0           0
>    persistent-dequeues         0           0
>    transactional-enqueues      25,833,943  16,024,501,474
>    transactional-dequeues      25,830,811  15,980,385,184
>    flow-to-disk-depth          0           0
>    flow-to-disk-enqueues       0           0
>    flow-to-disk-dequeues       0           0
>    acquires                    54,164,189
>    releases                    9
>    discards-no-route           26,617,570
>    discards-ttl-expired        10
>    discards-limit-overflow     0
>    discards-ring-overflow      0
>    discards-lvq-replace        343
>    discards-subscriber-reject  7,906
>    discards-purged             1,140
>    reroutes                    116,664
>    abandoned                   3,562
>    abandoned-via-alt           0
>
>
>
> ACL Policy Statistics:
>    Statistic          Value
>    =============================================
>    policy-file        /etc/qpid/qpidd.acl
>    enforcing          Y
>    has-transfer-acls  Y
>    last-acl-load      Mon Feb 25 21:11:10 2019
>    acl-denials        0
>
>
>
> Thanks
>
> Venkat
>


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]



---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

24hour_memory_usage.ods (19K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Issue with Qpid Memory

Gordon Sim
On 28/02/2019 1:58 pm, Chester wrote:

> Gordon,
>
> We see several days of low/normal (.1 GB) memory usage, followed by a
> linear increase of about .15 GB per hour, until we OOM after about 24
> hours. I've attached some graphs and a spreadsheet to help visualize.
> 1week_memory_usage.png
> 30day_memory_usage.png
>
> We have not identified any pattern of activity associated with the
> changing memory utilization. Our workload has a fairly constant
> enqueue/dequeue rate.

I think trying to find what else changes when the memory starts growing
would be the best way to progress. I assume there is nothing in the logs?

Perhaps try getting qpid-stat queries periodically to try and see if the
differences over time show anything?

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Issue with Qpid Memory

Venkat Jaligama
Gordon,


I have see the Logs  of the Qpid container which had high memory usage,  application logs seem to be normal however I see many  error logs.

These error logs constitute to 70% of the total logs generated by Qpid Container. Below  are some of the error logs. Could these error logs indicate something?


===============================

2019-02-28 13:07:44.171 ip-10-251-5-215
2019-02-28 13:07:44 [System] error [0x7f89e3fff700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:44.171 ip-10-251-5-215
2019-02-28 13:07:44 [System] error [0x7f89e9d18700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:44.171 ip-10-251-5-215
2019-02-28 13:07:44 [System] error [0x7f89e8d16700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43.468 ip-10-251-5-215
2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43.467 ip-10-251-5-215
2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43.464 ip-10-251-5-215
2019-02-28 13:07:43 [System] error [0x7f89ead1a700] Error reading socket: Encountered end of file [-5938]
=================================

________________________________
From: Chester Knapp
Sent: Thursday, February 28, 2019 10:29:01 AM
To: Venkat Jaligama; In Ho Sok
Subject: Fw: Issue with Qpid Memory



________________________________
From: Chester <[hidden email]>
Sent: Thursday, February 28, 2019 10:26 AM
To: Chester Knapp
Subject: Fwd: Issue with Qpid Memory



---------- Forwarded message ---------
From: Gordon Sim <[hidden email]<mailto:[hidden email]>>
Date: Thu, Feb 28, 2019 at 9:25 AM
Subject: Re: Issue with Qpid Memory
To: <[hidden email]<mailto:[hidden email]>>


On 28/02/2019 1:58 pm, Chester wrote:

> Gordon,
>
> We see several days of low/normal (.1 GB) memory usage, followed by a
> linear increase of about .15 GB per hour, until we OOM after about 24
> hours. I've attached some graphs and a spreadsheet to help visualize.
> 1week_memory_usage.png
> 30day_memory_usage.png
>
> We have not identified any pattern of activity associated with the
> changing memory utilization. Our workload has a fairly constant
> enqueue/dequeue rate.

I think trying to find what else changes when the memory starts growing
would be the best way to progress. I assume there is nothing in the logs?

Perhaps try getting qpid-stat queries periodically to try and see if the
differences over time show anything?

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]<mailto:[hidden email]>
For additional commands, e-mail: [hidden email]<mailto:[hidden email]>

Reply | Threaded
Open this post in threaded view
|

Re: Issue with Qpid Memory

Gordon Sim
On 28/02/2019 11:06 pm, Venkat Jaligama wrote:

> Gordon,
>
>
> I have see the Logs  of the Qpid container which had high memory usage,  application logs seem to be normal however I see many  error logs.
>
> These error logs constitute to 70% of the total logs generated by Qpid Container. Below  are some of the error logs. Could these error logs indicate something?
>
>
> ===============================
>
> 2019-02-28 13:07:44.171 ip-10-251-5-215
> 2019-02-28 13:07:44 [System] error [0x7f89e3fff700] Error reading socket: Encountered end of file [-5938]
> 2019-02-28 13:07:44.171 ip-10-251-5-215
> 2019-02-28 13:07:44 [System] error [0x7f89e9d18700] Error reading socket: Encountered end of file [-5938]
> 2019-02-28 13:07:44.171 ip-10-251-5-215
> 2019-02-28 13:07:44 [System] error [0x7f89e8d16700] Error reading socket: Encountered end of file [-5938]
> 2019-02-28 13:07:43.468 ip-10-251-5-215
> 2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
> 2019-02-28 13:07:43.467 ip-10-251-5-215
> 2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
> 2019-02-28 13:07:43.464 ip-10-251-5-215
> 2019-02-28 13:07:43 [System] error [0x7f89ead1a700] Error reading socket: Encountered end of file [-5938]
> =================================

That certainly looks suspicious unless you have any idea why there would
be so many disconnections. Is there any pattern to the occurence of
these errors? Are they evenly distributed throughout the log file, or do
they perhaps correspond to the start of the memory issues?

Do you know what is logging the 'ip-10-251-5-215' messages? Is that
extra logging you have in your server? Does the ip mean anything? Are
there any other ips or is it always that one?

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Issue with Qpid Memory

Venkat Jaligama
In reply to this post by Venkat Jaligama
Gordon,

Previously attached logs consists of Log metadata also, the actual log messages are as follows


2019-02-28 13:07:44 [System] error [0x7f89e3fff700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:44 [System] error [0x7f89e9d18700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:44 [System] error [0x7f89e8d16700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43 [System] error [0x7f89ead1a700] Error reading socket: Encountered end of file [-5938]


Does these error indicate something with the memory issue, out of 3.4 million logs 2.4 million logs are these error messages which is almost 70 percent

________________________________
From: Venkat Jaligama
Sent: Thursday, February 28, 2019 6:06:02 PM
To: Chester Knapp; In Ho Sok; [hidden email]
Subject: Re: Issue with Qpid Memory


Gordon,


I have see the Logs  of the Qpid container which had high memory usage,  application logs seem to be normal however I see many  error logs.

These error logs constitute to 70% of the total logs generated by Qpid Container. Below  are some of the error logs. Could these error logs indicate something?


===============================

2019-02-28 13:07:44.171 ip-10-251-5-215
2019-02-28 13:07:44 [System] error [0x7f89e3fff700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:44.171 ip-10-251-5-215
2019-02-28 13:07:44 [System] error [0x7f89e9d18700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:44.171 ip-10-251-5-215
2019-02-28 13:07:44 [System] error [0x7f89e8d16700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43.468 ip-10-251-5-215
2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43.467 ip-10-251-5-215
2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43.464 ip-10-251-5-215
2019-02-28 13:07:43 [System] error [0x7f89ead1a700] Error reading socket: Encountered end of file [-5938]
=================================

________________________________
From: Chester Knapp
Sent: Thursday, February 28, 2019 10:29:01 AM
To: Venkat Jaligama; In Ho Sok
Subject: Fw: Issue with Qpid Memory



________________________________
From: Chester <[hidden email]>
Sent: Thursday, February 28, 2019 10:26 AM
To: Chester Knapp
Subject: Fwd: Issue with Qpid Memory



---------- Forwarded message ---------
From: Gordon Sim <[hidden email]<mailto:[hidden email]>>
Date: Thu, Feb 28, 2019 at 9:25 AM
Subject: Re: Issue with Qpid Memory
To: <[hidden email]<mailto:[hidden email]>>


On 28/02/2019 1:58 pm, Chester wrote:

> Gordon,
>
> We see several days of low/normal (.1 GB) memory usage, followed by a
> linear increase of about .15 GB per hour, until we OOM after about 24
> hours. I've attached some graphs and a spreadsheet to help visualize.
> 1week_memory_usage.png
> 30day_memory_usage.png
>
> We have not identified any pattern of activity associated with the
> changing memory utilization. Our workload has a fairly constant
> enqueue/dequeue rate.

I think trying to find what else changes when the memory starts growing
would be the best way to progress. I assume there is nothing in the logs?

Perhaps try getting qpid-stat queries periodically to try and see if the
differences over time show anything?

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]<mailto:[hidden email]>
For additional commands, e-mail: [hidden email]<mailto:[hidden email]>

Reply | Threaded
Open this post in threaded view
|

Re: Issue with Qpid Memory

Gordon Sim
On 01/03/2019 4:09 pm, Venkat Jaligama wrote:

> Gordon,
>
> Previously attached logs consists of Log metadata also, the actual log messages are as follows
>
>
> 2019-02-28 13:07:44 [System] error [0x7f89e3fff700] Error reading socket: Encountered end of file [-5938]
> 2019-02-28 13:07:44 [System] error [0x7f89e9d18700] Error reading socket: Encountered end of file [-5938]
> 2019-02-28 13:07:44 [System] error [0x7f89e8d16700] Error reading socket: Encountered end of file [-5938]
> 2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
> 2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
> 2019-02-28 13:07:43 [System] error [0x7f89ead1a700] Error reading socket: Encountered end of file [-5938]
>
>
> Does these error indicate something with the memory issue, out of 3.4 million logs 2.4 million logs are these error messages which is almost 70 percent

The errors indicate a TLS based client connection that ended
unexpectedly. In itself that is not a memory issue. However given the
volume of these errors, it sounds like something that needs to be
explained and that might be a clue as to the cause of the other issue.

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Issue with Qpid Memory

Venkat Jaligama
In reply to this post by Venkat Jaligama
Gordon,


The Qpid Broker memory started spiking again, its usage is 50% now, is there anything specific I should be looking at in the logs, can you elucidate some pointers to look at to figure the root cause.

________________________________
From: Venkat Jaligama
Sent: Friday, March 1, 2019 11:09:26 AM
To: Chester Knapp; In Ho Sok; [hidden email]
Subject: Re: Issue with Qpid Memory


Gordon,

Previously attached logs consists of Log metadata also, the actual log messages are as follows


2019-02-28 13:07:44 [System] error [0x7f89e3fff700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:44 [System] error [0x7f89e9d18700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:44 [System] error [0x7f89e8d16700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43 [System] error [0x7f89ead1a700] Error reading socket: Encountered end of file [-5938]


Does these error indicate something with the memory issue, out of 3.4 million logs 2.4 million logs are these error messages which is almost 70 percent

________________________________
From: Venkat Jaligama
Sent: Thursday, February 28, 2019 6:06:02 PM
To: Chester Knapp; In Ho Sok; [hidden email]
Subject: Re: Issue with Qpid Memory


Gordon,


I have see the Logs  of the Qpid container which had high memory usage,  application logs seem to be normal however I see many  error logs.

These error logs constitute to 70% of the total logs generated by Qpid Container. Below  are some of the error logs. Could these error logs indicate something?


===============================

2019-02-28 13:07:44.171 ip-10-251-5-215
2019-02-28 13:07:44 [System] error [0x7f89e3fff700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:44.171 ip-10-251-5-215
2019-02-28 13:07:44 [System] error [0x7f89e9d18700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:44.171 ip-10-251-5-215
2019-02-28 13:07:44 [System] error [0x7f89e8d16700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43.468 ip-10-251-5-215
2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43.467 ip-10-251-5-215
2019-02-28 13:07:43 [System] error [0x7f89e2ffd700] Error reading socket: Encountered end of file [-5938]
2019-02-28 13:07:43.464 ip-10-251-5-215
2019-02-28 13:07:43 [System] error [0x7f89ead1a700] Error reading socket: Encountered end of file [-5938]
=================================

________________________________
From: Chester Knapp
Sent: Thursday, February 28, 2019 10:29:01 AM
To: Venkat Jaligama; In Ho Sok
Subject: Fw: Issue with Qpid Memory



________________________________
From: Chester <[hidden email]>
Sent: Thursday, February 28, 2019 10:26 AM
To: Chester Knapp
Subject: Fwd: Issue with Qpid Memory



---------- Forwarded message ---------
From: Gordon Sim <[hidden email]<mailto:[hidden email]>>
Date: Thu, Feb 28, 2019 at 9:25 AM
Subject: Re: Issue with Qpid Memory
To: <[hidden email]<mailto:[hidden email]>>


On 28/02/2019 1:58 pm, Chester wrote:

> Gordon,
>
> We see several days of low/normal (.1 GB) memory usage, followed by a
> linear increase of about .15 GB per hour, until we OOM after about 24
> hours. I've attached some graphs and a spreadsheet to help visualize.
> 1week_memory_usage.png
> 30day_memory_usage.png
>
> We have not identified any pattern of activity associated with the
> changing memory utilization. Our workload has a fairly constant
> enqueue/dequeue rate.

I think trying to find what else changes when the memory starts growing
would be the best way to progress. I assume there is nothing in the logs?

Perhaps try getting qpid-stat queries periodically to try and see if the
differences over time show anything?

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]<mailto:[hidden email]>
For additional commands, e-mail: [hidden email]<mailto:[hidden email]>

Reply | Threaded
Open this post in threaded view
|

Re: Issue with Qpid Memory

Gordon Sim
On 05/03/2019 6:37 pm, Venkat Jaligama wrote:
> Gordon,
>
>
> The Qpid Broker memory started spiking again, its usage is 50% now, is there anything specific I should be looking at in the logs, can you elucidate some pointers to look at to figure the root cause.

Get some data from qpid-stats (global, queues, exchange, connection for
example) at intervals and see if if there are any trends in the
differences between them.

In the logs, are you seeing any errors starting at about the time the
growth in memory began?

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]