| |
|
RSS Feed - WebSphere MQ Support
|
RSS Feed - Message Broker Support
|
  |
|
| Question about mh04 output and QSTATUS QTIME values |
« View previous topic :: View next topic » |
| Author |
Message
|
| LouML |
 Posted: Thu Sep 10, 2015 6:14 am Post subject: Question about mh04 output and QSTATUS QTIME values |
 |
|
Partisan
Joined: 10 Nov 2005
Posts: 305
Location: Jersey City, NJ / Bethpage, NY
|
We're running MQ Server 8.0.0.2 on a Linux RedHat VM. MQ Server is the only thing that runs on this server. Applications connect as remote clients.
We have one application team that always complains about slowness in processing messages from a queue. No other applications that access this queue manager have any issues.
I'm monitoring the queue using mh04 and I get the following:
| Code: |
Time MxML MxQD G P OIC OUC MDC MEC UNC CQD PQF TQF TQE QOM OQTS OQTL
-------------------------------------------------------------------------------------------------------------------
09:25:07 4194304 100000 E E 0 1 61 0 0 0 0.00% 35.42s 33.01s
09:25:37 4194304 100000 E E 0 1 0 11 0 11 0.01% 3d 22s 35.42s 33.01s
09:26:08 4194304 100000 E E 0 1 0 0 0 0 0.00% 35.96s 33.49s
09:26:38 4194304 100000 E E 0 1 0 3 0 3 0.00% 11d 22s 35.96s 33.49s
09:27:09 4194304 100000 E E 0 1 3 0 0 0 0.00% 35.79s 33.58s
09:27:40 4194304 100000 E E 0 1 0 13 0 13 0.01% 2d 23s 35.79s 33.58s
09:28:10 4194304 100000 E E 0 1 13 0 0 0 0.00% 35.99s 34.02s
09:28:41 4194304 100000 E E 0 1 0 1 0 1 0.00% inf 24s 35.99s 34.02s
09:29:11 4194304 100000 E E 0 1 1 0 0 0 0.00% 36.03s 34.06s
09:29:42 4194304 100000 E E 0 1 0 105 0 105 0.10% 7h 24s 36.03s 34.06s
09:30:12 4194304 100000 E E 0 1 105 0 0 0 0.00% 39.05s 37.34s
09:30:43 4194304 100000 E E 0 1 0 6 0 6 0.01% 5d 24s 39.05s 37.34s
09:31:13 4194304 100000 E E 0 1 0 0 0 0 0.00% 38.91s 37.47s
09:31:44 4194304 100000 E E 0 1 0 4 0 4 0.00% 8d 25s 38.91s 37.47s
09:32:14 4194304 100000 E E 0 1 4 0 0 0 0.00% 38.99s 37.57s
09:32:45 4194304 100000 E E 0 1 0 2 0 2 0.00% 17d 26s 38.99s 37.57s
09:33:15 4194304 100000 E E 0 1 2 0 0 0 0.00% 39.06s 37.62s
09:33:46 4194304 100000 E E 0 1 0 11 0 11 0.01% 3d 26s 39.06s 37.62s
09:34:16 4194304 100000 E E 0 1 11 0 0 0 0.00% 38.62s 37.75s
09:34:47 4194304 100000 E E 0 1 0 34 0 34 0.03% 1d 27s 38.62s 37.75s
09:35:17 4194304 100000 E E 0 1 34 0 0 0 0.00% 40.71s 38.70s
09:35:48 4194304 100000 E E 0 1 0 15 0 15 0.02% 2d 27s 40.71s 38.70s
09:36:18 4194304 100000 E E 0 1 15 0 0 0 0.00% 41.28s 39.23s
09:36:49 4194304 100000 E E 0 1 0 18 0 18 0.02% 1d 28s 41.28s 39.23s
09:37:19 4194304 100000 E E 0 1 18 0 0 0 0.00% 42.56s 40.03s
09:37:50 4194304 100000 E E 0 1 0 43 0 43 0.04% 19h 29s 42.56s 40.03s
09:38:20 4194304 100000 E E 0 1 43 0 0 0 0.00% 44.55s 42.02s
09:38:51 4194304 100000 E E 0 1 0 72 0 72 0.07% 11h 28s 44.55s 42.02s
09:39:21 4194304 100000 E E 0 1 72 0 0 0 0.00% 47.78s 45.30s
09:39:52 4194304 100000 E E 0 1 0 23 0 23 0.02% 1d 28s 47.78s 45.30s
09:40:22 4194304 100000 E E 0 1 23 0 0 0 0.00% 48.97s 46.36s
09:40:53 4194304 100000 E E 0 1 0 10 0 10 0.01% 3d 29s 48.97s 46.36s
09:41:23 4194304 100000 E E 0 1 10 0 0 0 0.00% 49.67s 46.87s
09:41:54 4194304 100000 E E 0 1 0 2 0 2 0.00% 17d 30s 49.67s 46.87s
09:42:25 4194304 100000 E E 0 1 2 12 0 12 0.01% 3d 1s 49.88s 46.98s
09:42:55 4194304 100000 E E 0 1 0 0 0 12 0.01% 31s 49.88s 46.98s
09:43:26 4194304 100000 E E 0 1 12 23 0 23 0.02% 3d 1s 51.09s 47.73s
09:43:56 4194304 100000 E E 0 1 0 0 0 23 0.02% 31s 51.09s 47.73s
09:44:27 4194304 100000 E E 0 1 23 2 0 2 0.00% 3s 2s 51.58s 48.85s
09:44:57 4194304 100000 E E 0 1 0 0 0 2 0.00% 32s 51.58s 48.85s
09:45:28 4194304 100000 E E 0 1 2 7 0 7 0.01% 6d 3s 51.69s 48.95s
09:45:58 4194304 100000 E E 0 1 0 0 0 7 0.01% 33s 51.69s 48.95s
09:46:29 4194304 100000 E E 0 1 7 3 0 3 0.00% 22s 4s 52.22s 49.32s
09:46:59 4194304 100000 E E 0 1 0 0 0 3 0.00% 34s 52.22s 49.32s
09:47:30 4194304 100000 E E 0 1 3 11 0 11 0.01% 4d 4s 52.43s 49.48s
09:48:00 4194304 100000 E E 0 1 0 0 0 11 0.01% 34s 52.43s 49.48s
09:48:31 4194304 100000 E E 0 1 11 12 0 12 0.01% inf 5s 52.21s 49.90s
09:49:01 4194304 100000 E E 0 1 0 0 0 12 0.01% 35s 52.21s 49.90s
09:49:32 4194304 100000 E E 0 1 12 10 0 10 0.01% 2m 6s 52.70s 50.39s
09:50:02 4194304 100000 E E 0 1 0 0 0 10 0.01% 36s 52.70s 50.39s
09:50:33 4194304 100000 E E 0 1 10 7 0 7 0.01% 1m 6s 53.31s 50.84s
09:51:03 4194304 100000 E E 0 1 0 0 0 7 0.01% 36s 53.31s 50.84s
09:51:34 4194304 100000 E E 0 1 7 15 0 15 0.02% 4d 7s 53.33s 51.10s
09:52:04 4194304 100000 E E 0 1 0 0 0 15 0.02% 37s 53.33s 51.10s
09:52:35 4194304 100000 E E 0 1 15 10 0 10 0.01% 1m 8s 54.23s 51.76s
09:53:05 4194304 100000 E E 0 1 0 0 0 10 0.01% 38s 54.23s 51.76s
09:53:36 4194304 100000 E E 0 1 10 34 0 34 0.03% 1d 9s 54.71s 52.22s
09:54:06 4194304 100000 E E 0 1 0 0 0 34 0.03% 39s 54.71s 52.22s
09:54:37 4194304 100000 E E 0 1 34 16 0 16 0.02% 27s 9s 55.41s 53.46s
09:55:07 4194304 100000 E E 0 1 0 0 0 16 0.02% 39s 55.41s 53.46s
09:55:38 4194304 100000 E E 0 1 16 11 0 11 0.01% 1m 10s 56.79s 54.21s
09:56:09 4194304 100000 E E 0 1 0 0 0 11 0.01% 40s 56.79s 54.21s
09:56:39 4194304 100000 E E 0 1 11 5 0 5 0.00% 25s 11s 57.63s 54.79s
09:57:10 4194304 100000 E E 0 1 0 0 0 5 0.00% 41s 57.63s 54.79s
09:57:40 4194304 100000 E E 0 1 5 3 0 3 0.00% 45s 12s 58.09s 55.07s
09:58:11 4194304 100000 E E 0 1 0 0 0 3 0.00% 42s 58.09s 55.07s
09:58:41 4194304 100000 E E 0 1 3 11 0 11 0.01% 4d 12s 58.45s 55.26s
09:59:12 4194304 100000 E E 0 1 0 0 0 11 0.01% 42s 58.45s 55.26s
09:59:42 4194304 100000 E E 0 1 11 35 0 35 0.04% 1d 13s 58.69s 55.80s
10:00:13 4194304 100000 E E 0 1 0 0 0 35 0.04% 43s 58.69s 55.80s
10:00:43 4194304 100000 E E 0 1 39 4 0 0 0.00% 35.52s 53.98s
10:01:14 4194304 100000 E E 0 1 0 0 0 0 0.00% 35.52s 53.98s
10:01:44 4194304 100000 E E 0 1 10 10 0 0 0.00% 10.32s 46.30s
10:02:15 4194304 100000 E E 0 1 0 0 0 0 0.00% 10.32s 46.30s
10:02:45 4194304 100000 E E 0 1 17 17 0 0 0.00% 2.98s 35.90s
10:03:16 4194304 100000 E E 0 1 0 0 0 0 0.00% 2.98s 35.90s
10:03:46 4194304 100000 E E 0 1 26 26 0 0 0.00% 2.21s 24.48s
10:04:17 4194304 100000 E E 0 1 0 0 0 0 0.00% 2.21s 24.48s
10:04:48 4194304 100000 E E 0 1 9 9 0 0 0.00% 2.86s 21.65s
10:05:18 4194304 100000 E E 0 1 0 0 0 0 0.00% 2.86s 21.65s
10:05:49 4194304 100000 E E 0 1 25 25 0 0 0.00% 4.65s 16.03s
10:06:19 4194304 100000 E E 0 1 0 0 0 0 0.00% 4.65s 16.03s
10:06:50 4194304 100000 E E 0 1 14 14 0 0 0.00% 4.99s 13.83s
10:07:20 4194304 100000 E E 0 1 0 0 0 0 0.00% 4.99s 13.83s
10:07:51 4194304 100000 E E 0 1 19 19 0 0 0.00% 6.07s 11.80s
10:08:21 4194304 100000 E E 0 1 0 0 0 0 0.00% 6.07s 11.80s
10:08:52 4194304 100000 E E 0 1 19 19 0 0 0.00% 6.34s 10.39s
10:09:22 4194304 100000 E E 0 1 0 0 0 0 0.00% 6.34s 10.39s
10:09:53 4194304 100000 E E 0 1 8 8 0 0 0.00% 6.89s 10.01s
10:10:23 4194304 100000 E E 0 1 0 0 0 0 0.00% 6.89s 10.01s
10:10:54 4194304 100000 E E 0 1 4 4 0 0 0.00% 7.14s 9.85s
10:11:24 4194304 100000 E E 0 1 0 0 0 0 0.00% 7.14s 9.85s
|
I see the queue times (OQTS and OQTL) increasing. I see this blurb in the queue status section of the documentation:
QTIME
These values depend on the configuration and behavior of your system, as well as the levels of activity within it, and serve as an indicator that your system is performing normally. A significant variation in these values might indicate a problem with your system. For queues with QSGDISP(SHARED), the values shown are for measurements collected on this queue manager only
Are they talking about the client application's system or the MQ server? I see no issues on the MQ server.
_________________
Yeah, well, you know, that's just, like, your opinion, man. - The Dude |
|
| Back to top |
|
 |
| mqjeff |
| Posted: Thu Sep 10, 2015 6:18 am Post subject: |
|
|
Grand Master
Joined: 25 Jun 2008
Posts: 17447
|
QTIME is the time that messages spend on a queue - on the server.
I forget if it's the max time over an interval or the average.
What the note is telling you is that if you have intervals with widely varying QTIMEs, then each interval is performing differently. This could indicate an issue with CPU or memory interfering with GETs, or disk access interfering. Generally, a resource issue.
The bit about QSGDISP obviously doesn't apply to linux.
_________________
chmod -R ugo-wx / |
|
| Back to top |
|
|
| tczielke |
| Posted: Thu Sep 10, 2015 9:07 am Post subject: |
|
|
Guardian
Joined: 08 Jul 2010
Posts: 941
Location: Illinois, USA
|
|
| Back to top |
|
|
| LouML |
| Posted: Thu Sep 10, 2015 11:32 am Post subject: |
|
|
Partisan
Joined: 10 Nov 2005
Posts: 305
Location: Jersey City, NJ / Bethpage, NY
|
What's very odd is that in the following case the queue has 3 messages, then is empty for over 6 minutes before receiving more messages. During the time the queue is empty, there are still queue times:
| Code: |
Time MxML MxQD G P OIC OUC MDC MEC UNC CQD PQF TQF TQE QOM OQTS OQTL
-------------------------------------------------------------------------------------------------------------------
15:02:49 4194304 100000 E E 0 1 0 3 0 3 0.00% 11d 25s 42.98s 51.65s
15:03:19 4194304 100000 E E 0 1 3 0 0 0 0.00% 42.65s 51.20s
15:03:50 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:04:21 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:04:51 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:05:22 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:05:52 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:06:23 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:06:53 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:07:24 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:07:54 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:08:25 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:08:55 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:09:26 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:09:56 4194304 100000 E E 0 1 0 0 0 0 0.00% 42.65s 51.20s
15:10:27 4194304 100000 E E 0 1 0 1 0 1 0.00% inf 1s 42.65s 51.20s
15:10:57 4194304 100000 E E 0 1 0 0 0 1 0.00% 32s 42.65s 51.20s
15:11:28 4194304 100000 E E 0 1 1 0 0 0 0.00% 42.50s 51.05s
|
Now I'm wondering if there is a bug in mh04 that is leaving stale data in these fields. I'm sure this is a long shot, but the values during this time are the same until the queue gets repopulated.
_________________
Yeah, well, you know, that's just, like, your opinion, man. - The Dude |
|
| Back to top |
|
|
| mqjeff |
| Posted: Thu Sep 10, 2015 11:51 am Post subject: |
|
|
Grand Master
Joined: 25 Jun 2008
Posts: 17447
|
So without doublechecking the doc for mh04, I'm guessing that oqtS is "on queue time short" and oqtL is "on queue time long".
What's the QSVCINT ?
_________________
chmod -R ugo-wx / |
|
| Back to top |
|
|
| LouML |
| Posted: Thu Sep 10, 2015 12:07 pm Post subject: |
|
|
Partisan
Joined: 10 Nov 2005
Posts: 305
Location: Jersey City, NJ / Bethpage, NY
|
First, I did a qs in runmqsc and the qtimes are there, so stale data is not the issue:
| Code: |
AMQ8450: Display queue status details.
QUEUE(GLOSS.IPM.P.QL) TYPE(QUEUE)
CURDEPTH(0) IPPROCS(0)
LGETDATE(2015-09-10) LGETTIME(20.33.11)
LPUTDATE(2015-09-10) LPUTTIME(20.32.31)
MEDIALOG( ) MONQ(HIGH)
MSGAGE(0) OPPROCS(1)
QTIME(45867770, 39739031) UNCOM(NO)
|
Second, I don't see a QSVCINT value, but the other two are:
OQTS indicates the time (in seconds) that the messages remain on the queue (value based on recent activity over a short period of time)
OQTL indicates the time (in seconds ) that the messages remain on the queue (value based on activity over a longer period of time)
_________________
Yeah, well, you know, that's just, like, your opinion, man. - The Dude |
|
| Back to top |
|
|
| LouML |
| Posted: Thu Sep 10, 2015 12:14 pm Post subject: |
|
|
Partisan
Joined: 10 Nov 2005
Posts: 305
Location: Jersey City, NJ / Bethpage, NY
|
It's odd that it's only one application that has this issue. This same application had an issue back when we were on 7.0.1.3 (I think). The amqrmppa process would gradually increase cpu usage until the slowness became a problem. It was fixed in a later fix pack. Then we had it again with 8.0.0.1 and it was fixed with 8.0.0.2 (APAR IT03414). Again, no other application had any issues.
| Code: |
[ ~]$ ps aux --sort=-pcpu | head -500 | egrep 'COMMAND|amqrmppa' | grep -v egrep
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
mqm 6441 1.2 0.1 2315360 28740 ? Ssl Sep06 81:32 /opt/mqm/bin/amqrmppa -m QM.CRESTGW1.01
[ ~]$ |
I believe the application is poorly written while the application team keeps blaming MQ. The Unix admins do not see any performance issues.
_________________
Yeah, well, you know, that's just, like, your opinion, man. - The Dude |
|
| Back to top |
|
|
| mqjeff |
| Posted: Thu Sep 10, 2015 12:17 pm Post subject: |
|
|
Grand Master
Joined: 25 Jun 2008
Posts: 17447
|
QSVCINT would be on the queue you're monitoring, not in the queue stats.
_________________
chmod -R ugo-wx / |
|
| Back to top |
|
|
| LouML |
| Posted: Thu Sep 10, 2015 12:27 pm Post subject: |
|
|
Partisan
Joined: 10 Nov 2005
Posts: 305
Location: Jersey City, NJ / Bethpage, NY
|
| mqjeff wrote: |
| QSVCINT would be on the queue you're monitoring, not in the queue stats. |
QSVCINT(999999999)
_________________
Yeah, well, you know, that's just, like, your opinion, man. - The Dude |
|
| Back to top |
|
|
|
|
|
| |
|
Page 1 of 1 |
|
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum
|
|
|
|
