Performance guest directory

Bug #1829249 reported by Herald ten Dam
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
zVM Cloud Connector
New
Undecided
Unassigned

Bug Description

We have around 60 guests deployed through Cloud Connector. We want to get data of these guest sometimes in a report. For these we made a Python script for collecting. This script however runs couple minutes. We call /guests/SLD510T, this costs around 2 sec.

I tried the smcli version (times):

time smcli Image_Query_DM -T SLD510T
USER SLD510T LBYONLY 4096M 4G G
INCLUDE LINUX
COMMAND DEF STOR RESERVED 0M
CPU 00 BASE
CPU 01
IPL CMS PARM AUTOCR
MACHINE ESA 10
DEDICATE 5C50 E014
DEDICATE 5C51 F014
MDISK 0100 FB-512 126829152 25165824 LNXOS2
MDISK 0403 FB-512 30165856 104857600 LNXOS3
MDISK 1300 FB-512 126829152 1000000 LNXOS4
*DVHOPT LNK0 LOG1 RCM1 SMS0 NPW1 LNGAMENG PWC20190403 CRCXX

real 0m2.060s
user 0m0.001s
sys 0m0.002s

So this give indeed a timing of 2 seconds.

Is this normal because a call with DIRMAINT on z/VM to get this data is under 0.1 s?
Or is this the interface penalty with persmapi or zthin?
Or could this be a failure in the setup of our Cloud Connector?

Thanks
Herald ten Dam

Revision history for this message
jichenjc (jichenjc) wrote :

I did some test locally ,it takes 1 sec, from my expereince, it's unlikely be caused by zthin for long delay, it might be caused by zthin socket connect to SMAPI and lead to some network latency
and 0.1 sec you mentioned might be DIRMAINT only? as the time will be smcli -> SMAPI -> DIRMAINT (actually DIRMAINT is more slow, so SMAPI has an internal cache and return very fast)

IDENTITY OPNCLOUD XXXXXXXXX 8G 8G G
BUILD ON OPNSTK1 USING SUBCONFIG OPNCLO-1
BUILD ON OPNSTK2 USING SUBCONFIG OPNCLO-2
CPU 00 BASE
CPU 01
CPU 02
CPU 03
MACHINE ESA 4
IPL 190 PARM AUTOCR
IUCV ANY MSGLIMIT 512
OPTION LNKNOPAS
CONSOLE 0009 3215 T
SPOOL 00C 2540 READER *
SPOOL 00D 2540 PUNCH A
SPOOL 00E 1403 A
* END IDENTITY OPNCLOUD

*DVHOPT LNK0 LOG1 RCM1 SMS0 NPW1 LNGAMENG PWC20161220 CRC▒"

real 0m1.032s
user 0m0.001s
sys 0m0.001s

yes, it take some time and it do need some

Revision history for this message
Herald ten Dam (damsteen) wrote :

Hi,

I did some tracing and it is correct it is the socket receiving:
     0.000090 socket(PF_IUCV, SOCK_STREAM, 0) = 3
     0.000061 setsockopt(3, SOL_SOCKET, SO_SNDTIMEO, "\0\0\0\0\0\0\0<\0\0\0\0\0\0\0\0", 16) = 0
     0.000045 connect(3, {sa_family=AF_IUCV, sa_data="\0\0\0\0\0\0 "}, 32) = 0
     0.000707 setsockopt(3, SOL_SOCKET, SO_SNDTIMEO, "\0\0\0\0\0\0\0\360\0\0\0\0\0\0\0\0", 16) = 0
     0.000049 setsockopt(3, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
     0.000047 send(3, "\0\0\0%\0\0\0\16Image_Query_DM\0\0\0\0\0\0\0\0\0\0"..., 41, 0) = 41
     0.000060 setsockopt(3, SOL_SOCKET, SO_RCVTIMEO, "\0\0\0\0\0\0\0\360\0\0\0\0\0\0\0\0", 16) = 0
     0.000052 setsockopt(3, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
     0.000048 recv(3, "\4\335\232:", 4, 0) = 4
     0.042885 setsockopt(3, SOL_SOCKET, SO_RCVTIMEO, "\0\0\0\0\0\0\0\360\0\0\0\0\0\0\0\0", 16) = 0
     0.000067 setsockopt(3, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
     0.000066 recv(3, "\0\0\4T", 4, 0) = 4
     2.009859 setsockopt(3, SOL_SOCKET, SO_RCVTIMEO, "\0\0\0\0\0\0\0\360\0\0\0\0\0\0\0\0", 16) = 0
     0.000083 setsockopt(3, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
     0.000047 recv(3, "\4\335\232:\0\0\0\0\0\0\0\0\0\0\4D\0\0\0PUSER SLD510T"..., 1108, 0) = 1108
     0.000066 shutdown(3, SHUT_RDWR) = 0
     0.000078 close(3) = 0

Because we have already a difference of 2 seconds to 1 seconds, is there something I can look in our setup were the delay is?

Herald

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.