ASG
IBM
Zystems
Cressida
Icon
Netflexity
 
  MQSeries.net
Search  Search       Tech Exchange      Education      Certifications      Library      Info Center      SupportPacs      LinkedIn  Search  Search                                                                   FAQ  FAQ   Usergroups  Usergroups
 
Register  ::  Log in Log in to check your private messages
 
RSS Feed - WebSphere MQ Support RSS Feed - Message Broker Support

MQSeries.net Forum IndexIBM MQ Performance MonitoringQuestion about mh04 output and QSTATUS QTIME values

Post new topicReply to topic
Question about mh04 output and QSTATUS QTIME values View previous topic :: View next topic
Author Message
LouML
PostPosted: Thu Sep 10, 2015 6:14 am Post subject: Question about mh04 output and QSTATUS QTIME values Reply with quote

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
View user's profile Send private message
mqjeff
PostPosted: Thu Sep 10, 2015 6:18 am Post subject: Reply with quote

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
View user's profile Send private message
tczielke
PostPosted: Thu Sep 10, 2015 9:07 am Post subject: Reply with quote

Shaman

Joined: 08 Jul 2010
Posts: 736
Location: Illinois, USA

Since you are at 8.0.0.2, you might want to also consider using the Activity Trace to measure the response time of the application API calls. That recently new enhancement to MQ at 8.0 is discussed in this thread -> http://www.mqseries.net/phpBB2/viewtopic.php?t=68250&highlight=amqsactz
_________________
MQ administrator since 2010.
Back to top
View user's profile Send private message
LouML
PostPosted: Thu Sep 10, 2015 11:32 am Post subject: Reply with quote

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
View user's profile Send private message
mqjeff
PostPosted: Thu Sep 10, 2015 11:51 am Post subject: Reply with quote

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
View user's profile Send private message
LouML
PostPosted: Thu Sep 10, 2015 12:07 pm Post subject: Reply with quote

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
View user's profile Send private message
LouML
PostPosted: Thu Sep 10, 2015 12:14 pm Post subject: Reply with quote

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
View user's profile Send private message
mqjeff
PostPosted: Thu Sep 10, 2015 12:17 pm Post subject: Reply with quote

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
View user's profile Send private message
LouML
PostPosted: Thu Sep 10, 2015 12:27 pm Post subject: Reply with quote

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
View user's profile Send private message
Display posts from previous:
Post new topicReply to topic Page 1 of 1

MQSeries.net Forum IndexIBM MQ Performance MonitoringQuestion about mh04 output and QSTATUS QTIME values
Jump to:



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
Protected by Anti-Spam ACP


Theme by Dustin Baccetti
Powered by phpBB 2001, 2002 phpBB Group

Copyright MQSeries.net. All rights reserved.