| Author |
Message
|
| an4ous |
 Posted: Sat Jan 15, 2022 9:20 am Post subject: |
 |
|
Apprentice
Joined: 14 Jan 2022
Posts: 38
|
| Quote: |
| you should certainly look at the log latency (published in the amqsru data for the recovery log) and ensure its what you expect (SSD would typically be sub millisecond, the field is reported in micro seconds by amqsrua) |
I have checked log write latency from amqsrua utility - now beetween 2000-2500 uSec (2-2.5 millisecond), it is bad? At next week we add this metrics to solarwind monitoring to collect statistics.
| Code: |
...
Publication received PutDate:20220115 PutTime:16585095 Interval:10.000 seconds
Log - bytes in use 77039800320
Log - bytes max 87240192000
Log file system - bytes in use 665032077312
Log file system - bytes max 1294550888448
Log - physical bytes written 7532544 753254/sec
Log - logical bytes written 2641121 264112/sec
Log - write latency 2120 uSec
Log - write size 5332
Log - current primary space in use 0.66%
Log - workload primary space utilization 0.71%
Publication received PutDate:20220115 PutTime:16590095 Interval:10.000 seconds
Log - bytes in use 77039800320
Log - bytes max 87240192000
Log file system - bytes in use 665032077312
Log file system - bytes max 1294550888448
Log - physical bytes written 8466432 846643/sec
Log - logical bytes written 3860866 386087/sec
Log - write latency 2282 uSec
Log - write size 5858
Log - current primary space in use 0.67%
Log - workload primary space utilization 0.72%
Publication received PutDate:20220115 PutTime:16591095 Interval:10.000 seconds
Log - bytes in use 77039800320
Log - bytes max 87240192000
Log file system - bytes in use 665032093696
Log file system - bytes max 1294550888448
Log - physical bytes written 14053376 1405309/sec
Log - logical bytes written 8636172 863600/sec
Log - write latency 2442 uSec
Log - write size 7194
Log - current primary space in use 0.68%
Log - workload primary space utilization 0.72%
...
|
| Quote: |
| here are various flavours of runmqras that collect differing amounts of data. The stand alone command amqldmpa... |
I executed amqldmpa command on developer stand (but with mq 9.2.2.0 for developers version) and report was successfully created. If I get report from production stand, can You help me interpret his results? |
|
| Back to top |
|
 |
| an4ous |
| Posted: Sat Jan 15, 2022 9:27 am Post subject: |
|
|
Apprentice
Joined: 14 Jan 2022
Posts: 38
|
| Quote: |
What changed in November timeframe? Please don’t say ‘nothing changed.’
|
I am sorry, but in configuration of mq server really nothing changed. )
But from april to december 2021 our developers and devops deploymented some new camel applications-cleints that generate more messages.
Unfortunately early we did not monitoring count of messages for splunk
Also our developers enabled exclusive (i.e. not sharing) access for some queues, but not splunk queue. |
|
| Back to top |
|
|
| bruce2359 |
| Posted: Sat Jan 15, 2022 11:22 am Post subject: |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9399
Location: US: west coast, almost. Otherwise, enroute.
|
| an4ous wrote: |
| Also our developers enabled exclusive (i.e. not sharing) access for some queues, but not splunk queue. |
Exclusive control would have limited access to only one getting app at a time, thus imposing significant delays in the other getting apps waiting in line for their turn.
How do the apps that attempt to MQOPEN the queue, but fail to get exclusive access, resolve this? Do they iteratively attempt to MQOPEN the queue, fail, try again, fail, try again ... until it succeeds? If you have 1000 getters, 999 will fail concurrently. Consider enabling an MQI statistics and application trace to discover if this might be an issue.
I don't understand the distinction you've offered in '...some queues, but not splunk queues.'
_________________
I like deadlines. I like to wave as they pass by.
ב''ה
Lex Orandi, Lex Credendi, Lex Vivendi. As we Worship, So we Believe, So we Live. |
|
| Back to top |
|
|
| an4ous |
| Posted: Sat Jan 15, 2022 11:43 am Post subject: |
|
|
Apprentice
Joined: 14 Jan 2022
Posts: 38
|
| Quote: |
| How do the apps that attempt to MQOPEN the queue, but fail to get exclusive access, resolve this? Do they iteratively attempt to MQOPEN the queue, fail, try again, fail, try again ... until it succeeds? |
looks like it. In application useing exclusive queue I see many warnings evey second
| Code: |
WARN 1 --- c.c.j.DefaultJmsMessageListenerContainer : Setup of JMS message listener invoker failed for destination - trying to recover. Cause: JMSWMQ2008: Failed to open MQ queue .; nested exception is com.ibm.mq.MQException: JMSCMQ0001: IBM MQ call failed with compcode '2' ('MQCC_FAILED') reason '2042' ('MQRC_OBJECT_IN_USE').
|
| Quote: |
I don't understand the distinction you've offered in '...some queues, but not splunk queues.'
|
I mean that for queue that grows via persistent messages send to splunk server we exclusive mode did not turn on |
|
| Back to top |
|
|
| PeterPotkay |
| Posted: Sat Jan 15, 2022 12:28 pm Post subject: |
|
|
Poobah
Joined: 15 May 2001
Posts: 7716
|
| an4ous wrote: |
| Quote: |
| How do the apps that attempt to MQOPEN the queue, but fail to get exclusive access, resolve this? Do they iteratively attempt to MQOPEN the queue, fail, try again, fail, try again ... until it succeeds? |
looks like it. In application useing exclusive queue I see many warnings evey second
| Code: |
WARN 1 --- c.c.j.DefaultJmsMessageListenerContainer : Setup of JMS message listener invoker failed for destination - trying to recover. Cause: JMSWMQ2008: Failed to open MQ queue .; nested exception is com.ibm.mq.MQException: JMSCMQ0001: IBM MQ call failed with compcode '2' ('MQCC_FAILED') reason '2042' ('MQRC_OBJECT_IN_USE').
|
|
They have effectively made the app that reads from the queue a single threaded app. Only one thread from one instance can pull one message from the one queue at a time.
_________________
Peter Potkay
Keep Calm and MQ On |
|
| Back to top |
|
|
| Andyh |
| Posted: Sat Jan 15, 2022 12:38 pm Post subject: |
|
|
Master
Joined: 29 Jul 2010
Posts: 237
|
2-2.5 milliseconds would indicate 400-500 writes per second.
With minimal concurrency, that would suggest only 100-200 msg/sec.
The high ratio of physical to logical bytes written would also suggest a lack of concurrency.
The earlier discussion on opening for input exclusive vs input shared might explain this lack of concurrency. MQ itself doesn't provide a means of waiting for exclusive input access and that might explain any polling.
amqsrua would allow you to see a "Failed MQOPEN count" for a queue, which would be expected to be very large if there's polling for input exclusive access going on. Comparing the MQOPEN counts with the MQGET and MQPUT counts might also be illuminating. |
|
| Back to top |
|
|
| an4ous |
| Posted: Sat Jan 15, 2022 12:46 pm Post subject: |
|
|
Apprentice
Joined: 14 Jan 2022
Posts: 38
|
| Quote: |
They have effectively made the app that reads from the queue a single threaded app. Only one thread from one instance can pull one message from the one queue at a time.
|
I understand. But when many applications or one application with many threads have read from queue, message delivery order was broken, our developers solved the problem this way
But if we say about queue for splunk where puts to 500 messages per second and gets only to 150 - on this queue exclisive mode has not turned, but increase of apps ot threads do not increase get speed from this queue |
|
| Back to top |
|
|
| an4ous |
| Posted: Sat Jan 15, 2022 12:51 pm Post subject: |
|
|
Apprentice
Joined: 14 Jan 2022
Posts: 38
|
| Quote: |
The earlier discussion on opening for input exclusive vs input shared might explain this lack of concurrency. MQ itself doesn't provide a means of waiting for exclusive input access and that might explain any polling.
|
I repeat that exclusive mode has applied for other queue, but not for queue for splunk |
|
| Back to top |
|
|
| bruce2359 |
| Posted: Sat Jan 15, 2022 1:08 pm Post subject: |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9399
Location: US: west coast, almost. Otherwise, enroute.
|
| an4ous wrote: |
| Quote: |
The earlier discussion on opening for input exclusive vs input shared might explain this lack of concurrency. MQ itself doesn't provide a means of waiting for exclusive input access and that might explain any polling.
|
I repeat that exclusive mode has applied for other queue, but not for queue for splunk |
Please be precise.
What are 'other queue(s)'? What does this mean?
If it's an MQ queue, then 'exclusive' is for input-only - allows for many putters, but only one getter.
_________________
I like deadlines. I like to wave as they pass by.
ב''ה
Lex Orandi, Lex Credendi, Lex Vivendi. As we Worship, So we Believe, So we Live. |
|
| Back to top |
|
|
| an4ous |
| Posted: Sat Jan 15, 2022 10:40 pm Post subject: |
|
|
Apprentice
Joined: 14 Jan 2022
Posts: 38
|
| Quote: |
What are 'other queue(s)'? What does this mean?
|
I mean that in our MQ queue manager created multiple queues.
For some them we set exclusive mode.
But for mq queue about I wrote in my first post we did not set exclusive mode. |
|
| Back to top |
|
|
| an4ous |
| Posted: Sat Jan 15, 2022 11:57 pm Post subject: |
|
|
Apprentice
Joined: 14 Jan 2022
Posts: 38
|
In amqsrua for STATMQI/SYNCPOINT I see
about 800 committed per second and about 300 rollbacks per second.
| Code: |
...
Publication received PutDate:20220116 PutTime:07405827 Interval:10.006 seconds
Commit count 7753 775/sec
Rollback count 3150 315/sec
Publication received PutDate:20220116 PutTime:07410827 Interval:10.003 seconds
Commit count 8416 841/sec
Rollback count 3424 342/sec
...
|
For GET/PUT MQI I see 0 Failed MQPUT/MQPUT1 count per second but about 150-200 Failed MQGET count per second
| Code: |
...
Publication received PutDate:20220116 PutTime:07462502 Interval:10.003 seconds
Interval total destructive get- count 910 91/sec
Interval total destructive get - byte count 7538028 753535/sec
Non-persistent message destructive get - count 5
Persistent message destructive get - count 905 90/sec
Failed MQGET - count 1693 169/sec
Got non-persistent messages - byte count 4664 466/sec
Got persistent messages - byte count 7533364 753069/sec
Non-persistent message browse - count 0
Persistent message browse - count 0
Failed browse count 0
Non-persistent message browse - byte count 0
Persistent message browse - byte count 0
Expired message count 0
Purged queue count 0
MQCB count 901 90/sec
Failed MQCB count 0
MQCTL count 0
Publication received PutDate:20220116 PutTime:07463502 Interval:10.000 seconds
Interval total destructive get- count 2676 268/sec
Interval total destructive get - byte count 9353788 935356/sec
Non-persistent message destructive get - count 1702 170/sec
Persistent message destructive get - count 974 97/sec
Failed MQGET - count 1653 165/sec
Got non-persistent messages - byte count 652400 65238/sec
Got persistent messages - byte count 8701388 870117/sec
Non-persistent message browse - count 0
Persistent message browse - count 0
Failed browse count 0
Non-persistent message browse - byte count 0
Persistent message browse - byte count 0
Expired message count 0
Purged queue count 0
MQCB count 865 86/sec
Failed MQCB count 0
MQCTL count 0
...
|
For OPENCLOSE MQI
| Code: |
...
Publication received PutDate:20220116 PutTime:07501535 Interval:10.000 seconds
MQOPEN count 4646 465/sec
Failed MQOPEN count 24 2/sec
MQCLOSE count 4644 464/sec
Failed MQCLOSE count 0
Publication received PutDate:20220116 PutTime:07502535 Interval:10.000 seconds
MQOPEN count 4440 444/sec
Failed MQOPEN count 24 2/sec
MQCLOSE count 4442 444/sec
Failed MQCLOSE count 0
Publication received PutDate:20220116 PutTime:07503535 Interval:10.001 seconds
MQOPEN count 5400 540/sec
Failed MQOPEN count 24 2/sec
MQCLOSE count 5397 540/sec
Failed MQCLOSE count 0
...
|
and for CONNDISC
| Code: |
Publication received PutDate:20220116 PutTime:07523226 Interval:10.007 seconds
MQCONN/MQCONNX count 2082 208/sec
Failed MQCONN/MQCONNX count 0
Concurrent connections - high water mark 1972
MQDISC count 2084 208/sec
Publication received PutDate:20220116 PutTime:07524226 Interval:10.000 seconds
MQCONN/MQCONNX count 2025 203/sec
Failed MQCONN/MQCONNX count 0
Concurrent connections - high water mark 1972
MQDISC count 2024 202/sec
Publication received PutDate:20220116 PutTime:07525228 Interval:10.022 seconds
MQCONN/MQCONNX count 2079 207/sec
Failed MQCONN/MQCONNX count 0
Concurrent connections - high water mark 1972
MQDISC count 2079 207/sec
|
But for problem queue in STATQ I see only
| Code: |
Publication received PutDate:20220116 PutTime:07542017 Interval:10.004 seconds
SPLUNK.Q MQOPEN count 9 1/sec
SPLUNK.Q MQCLOSE count 9 1/sec
Publication received PutDate:20220116 PutTime:07543017 Interval:10.002 seconds
SPLUNK.Q MQOPEN count 3
SPLUNK.Q MQCLOSE count 3
|
Is this ratio normal or abnormal? |
|
| Back to top |
|
|
| bruce2359 |
| Posted: Sun Jan 16, 2022 6:31 am Post subject: |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9399
Location: US: west coast, almost. Otherwise, enroute.
|
| an4ous wrote: |
In amqsrua for STATMQI/SYNCPOINT I see
about 800 committed per second and about 300 rollbacks per second.
Is this ratio normal or abnormal? |
I find it highly unusual (read: alarming) the number of failed GETs and transactions rolled back. Ideally, there should be few or no roll backs.
Missing from this conversation is output from the application. What errors were thrown? What errors did the app try catch? How did it deal with them?
Each failed GET call, for example, should have written the error (and reason code) to the run-time output from the app. The reason code will tell you why the call failed. Possible ReasonCodes from MQGET call: https://www.ibm.com/docs/en/ibm-mq/9.1?topic=calls-mqget-get-message
_________________
I like deadlines. I like to wave as they pass by.
ב''ה
Lex Orandi, Lex Credendi, Lex Vivendi. As we Worship, So we Believe, So we Live. |
|
| Back to top |
|
|
| an4ous |
| Posted: Sun Jan 16, 2022 7:00 am Post subject: |
|
|
Apprentice
Joined: 14 Jan 2022
Posts: 38
|
| bruce2359 wrote: |
| an4ous wrote: |
In amqsrua for STATMQI/SYNCPOINT I see
about 800 committed per second and about 300 rollbacks per second.
Is this ratio normal or abnormal? |
I find it highly unusual (read: alarming) the number of failed GETs and transactions rolled back. Ideally, there should be few or no roll backs.
Missing from this conversation is output from the application. What errors were thrown? What errors did the app try catch? How did it deal with them?
Each failed GET call, for example, should have written the error (and reason code) to the run-time output from the app. The reason code will tell you why the call failed. Possible ReasonCodes from MQGET call: https://www.ibm.com/docs/en/ibm-mq/9.1?topic=calls-mqget-get-message |
In IBM MQ Server or QM logs there are no any errors about failed transactions or gets calls.
In camel applications there are ('MQCC_FAILED') reason '2042' ('MQRC_OBJECT_IN_USE') warnings because exclusive mode has enabled for relevant queues, but for discussed mq queue SPLUNK.Q exclusive mode has not enabled so there are no any errros about getting in camel application logs that get messages from SPLUNK.Q but exactly SPLUNK.Q queue groes because low perfomance |
|
| Back to top |
|
|
| bruce2359 |
| Posted: Sun Jan 16, 2022 7:39 am Post subject: |
|
|
Poobah
Joined: 05 Jan 2008
Posts: 9399
Location: US: west coast, almost. Otherwise, enroute.
|
| an4ous wrote: |
| In IBM MQ Server or QM logs there are no any errors about failed transactions or gets calls. |
As designed and documented, MQ application-level errors (like 2033 NO MESSAGE AVAILABLE, 2042 OBJECT IN USE) do not appear in qmgr error logs. Applications must deal appropriately with these error conditions.
| an4ous wrote: |
| In camel applications there are ('MQCC_FAILED') reason '2042' ('MQRC_OBJECT_IN_USE') warnings because exclusive mode has enabled for relevant queues, but for discussed mq queue SPLUNK.Q exclusive mode has not enabled so there are no any errros about getting in camel application logs that get messages from SPLUNK.Q but exactly SPLUNK.Q queue groes because low perfomance |
I suggest that you do further research to determine exactly how the application deals with open fails, get fails, and why (under what circumstances) it rolls back.
Are you a developer? Are you the developer of this app? I strongly recommend that you enable an application run-time trace to determine precisely how the app behaves.
I'll defer to others with experience with Camel environment and Splunk.
_________________
I like deadlines. I like to wave as they pass by.
ב''ה
Lex Orandi, Lex Credendi, Lex Vivendi. As we Worship, So we Believe, So we Live. |
|
| Back to top |
|
|
| an4ous |
| Posted: Sun Jan 16, 2022 8:03 am Post subject: |
|
|
Apprentice
Joined: 14 Jan 2022
Posts: 38
|
Thx for our help
| Code: |
| Are your a developer? |
No, I am not developer, but tomorrow I will consult with our developers. |
|
| Back to top |
|
|
|
|
