processHealthSvc.py (14010B)
1 #Embedded file name: C:\BuildAgent\work\20d73f1b24eed06e\eve\release\V24.01\carbon\common\script\sys\processHealthSvc.py 2 import _socket 3 import copy 4 import os 5 import subprocess 6 import sys 7 import blue 8 import bluepy 9 import uthread 10 import log 11 import monolithmetrics 12 import utillib 13 from carbon.common.script.net.ServiceCallGPCS import CoreServiceCall 14 from carbon.common.script.sys import sessions 15 from carbon.common.script.sys.service import Service 16 from carbon.common.script.sys.serviceConst import SERVICE_RUNNING 17 from carbon.common.script.sys.sessions import GetNumberOfCharacterSessions 18 from carbon.common.script.util.format import FmtDateEng 19 from eve.common.lib import appConst as const 20 from eveprefs import prefs, boot 21 METRIC_PROCESS_HEALTH = 'process_health' 22 23 class ProcessHealthSvc(Service): 24 __guid__ = 'svc.processHealth' 25 __servicename__ = 'processHealth' 26 __displayname__ = 'Process Health Service' 27 __startupdependencies__ = ['machoNet'] 28 __notifyevents__ = ['ProcessShutdown'] 29 30 def ProcessShutdown(self): 31 self.WriteLog(20, True, useLogNotice=True) 32 33 def __init__(self, *args): 34 Service.__init__(self, *args) 35 self.logLines = [] 36 self._SetStartTime() 37 self.cache = utillib.KeyVal() 38 self.cache.cacheTime = 0 39 self.cache.minutes = 0 40 self.cache.cache = [] 41 self.lastLoggedLine = 0 42 self.lastStartPos = 0 43 self.columnNames = ('dateTime', 'pyDateTime', 'procCpu', 'threadCpu', 'pyMem', 'virtualMem', 'taskletsProcessed', 'taskletsQueued', 'watchdog time', 'spf', 'serviceCalls', 'callsFromClient') 44 45 def _SetStartTime(self): 46 self.startDateTime = FmtDateEng(blue.os.GetWallclockTime(), 'ss') 47 48 def Run(self, memStream = None): 49 Service.Run(self, memStream) 50 self.nodeID = self.machoNet.GetNodeID() 51 if self.nodeID is None: 52 self.nodeID = 0 53 self.nodeIndex = sm.GetService('machoNet').nodeIndex 54 self.computerName = blue.pyos.GetEnv().get('COMPUTERNAME', 'unknown') 55 if boot.role == 'server': 56 machoNet = sm.GetService('machoNet') 57 self._pid = os.getpid() 58 self._nodeID = machoNet.GetNodeID() 59 self._serviceMask = machoNet.serviceMask 60 self._clusterGroup = machoNet.clusterGroup 61 uthread.new(self.RunWorkerProcesses).context = 'svc.processHealth' 62 63 def GetSeriesNames(self): 64 names = [] 65 if len(self.logLines) > 0: 66 names = self.logLines[0].keys() 67 if names.count('dateTime') > 0: 68 names.remove('dateTime') 69 names.extend(['procCpu', 70 'threadCpu', 71 'pyMem', 72 'virtualMem', 73 'taskletsProcessed', 74 'taskletsQueued', 75 'watchdog time', 76 'spf']) 77 return names 78 79 def GetSessionCount(self): 80 allsc = sessions.GetSessions() 81 sc = len(filter(lambda x: x.userid is not None and hasattr(x, 'clientID'), allsc)) 82 return sc 83 84 def FindClosestPythonLine(self, blueLine, startPos = 0): 85 logLinesCopy = copy.copy(self.logLines[startPos:]) 86 if len(logLinesCopy) == 0: 87 return (None, 0) 88 if blueLine['dateTime'] <= logLinesCopy[0]['pyDateTime']: 89 return (logLinesCopy[0], 0) 90 if blueLine['dateTime'] >= logLinesCopy[-1]['pyDateTime']: 91 return (logLinesCopy[-1], len(logLinesCopy) + startPos) 92 for line in xrange(0, len(logLinesCopy) - 1): 93 blue.pyos.BeNice() 94 t1 = logLinesCopy[line]['pyDateTime'] 95 t2 = logLinesCopy[line + 1]['pyDateTime'] 96 if t1 <= blueLine['dateTime'] < t2: 97 return (logLinesCopy[line], line + startPos) 98 99 return (None, 0, 0) 100 101 def GetBlueDataAsDictList(self, minutes = 0): 102 data = bluepy.GetBlueInfo(minutes, isYield=False) 103 ret = [] 104 for i in xrange(0, len(data.timeData)): 105 fps, taskletsProcessed, nrYielders, nrSleepWallclockers, watchDogTime, taskletsQueued = data.schedData[i] 106 spf = 1.0 / fps if fps > 0.1 else 0 107 ret.append({'dateTime': data.timeData[i], 108 'procCpu': data.procCpuData[i], 109 'threadCpu': data.threadCpuData[i], 110 'pyMem': data.pymemData[i], 111 'virtualMem': data.memData[i], 112 'taskletsProcessed': taskletsProcessed, 113 'taskletsQueued': taskletsQueued, 114 'watchdog time': watchDogTime, 115 'spf': spf}) 116 117 return ret 118 119 def GetAllLogs(self, logAll = True): 120 logs = self.GetProcessInfo() 121 return self.FormatLog(logs, logAll) 122 123 def GetProcessInfo(self, minutes = 0, useIncrementalStartPos = False): 124 uthread.Lock(self) 125 try: 126 if blue.os.GetWallclockTime() - self.cache.cacheTime < 25 * const.SEC and self.cache.minutes == minutes: 127 return self.cache.cache 128 startTime = blue.os.GetWallclockTime() 129 blueLines = self.GetBlueDataAsDictList(minutes) 130 lastLine = {} 131 if useIncrementalStartPos: 132 startPos = self.lastStartPos 133 else: 134 startPos = 0 135 for blueLine in blueLines: 136 pyLine, startPos = self.FindClosestPythonLine(blueLine, startPos) 137 if pyLine: 138 lastLine = pyLine 139 blueLine.update(pyLine) 140 else: 141 blueLine.update(lastLine) 142 143 self.lastStartPos = startPos 144 self.cache.minutes = minutes 145 self.cache.cacheTime = blue.os.GetWallclockTime() 146 self.cache.cache = blueLines 147 return blueLines 148 finally: 149 uthread.UnLock(self) 150 151 def RunWorkerProcesses(self): 152 seconds = 0 153 while self.state == SERVICE_RUNNING: 154 if prefs.GetValue('disableProcessHealthService', 0): 155 self.LogWarn('Process Health Service is disabled in prefs. Disabling loop.') 156 return 157 blue.pyos.synchro.SleepWallclock(10000) 158 try: 159 seconds += 10 160 self.DoOnceEvery10Secs() 161 if seconds % 600 == 0: 162 self.DoOnceEvery10Minutes() 163 except: 164 log.LogException() 165 sys.exc_clear() 166 167 def send_to_monolithmetrics(self, net_bytes_rx, net_bytes_tx, net_packets_rx, net_packets_tx, service_calls, calls_from_client): 168 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.net.bytes_rx', value=net_bytes_rx) 169 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.net.bytes_tx', value=net_bytes_tx) 170 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.net.packets_rx', value=net_packets_rx) 171 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.net.packets_tx', value=net_packets_tx) 172 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.macho.service_calls', value=service_calls) 173 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.client.calls', value=calls_from_client) 174 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.tidi', value=blue.os.simDilation) 175 blue_data = bluepy.get_blue_info_last_tick() 176 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.mem.virtual', value=blue_data['virtualmemory']) 177 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.mem.python', value=blue_data['pymemory']) 178 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.mem.working_set', value=blue_data['workingset']) 179 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.mem.pagefaults', value=blue_data['pagefaults']) 180 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.cpu.user.thread_time', value=blue_data['user_thread_time_micro']) 181 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.cpu.user.process_time', value=blue_data['user_process_time_micro']) 182 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.cpu.kernel.thread_time', value=blue_data['kernel_thread_time_micro']) 183 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.cpu.kernel.process_time', value=blue_data['kernel_process_time_micro']) 184 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.tasklets.processed', value=blue_data['tasklets_processed']) 185 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.tasklets.queued', value=blue_data['tasklets_queued']) 186 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.tasklets.scheduler.ticks', value=blue_data['tasklet_scheduler_duration']) 187 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.tasklets.sleeping', value=blue_data['tasklets_sleeping']) 188 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.tasklets.yielding', value=blue_data['tasklets_yielding']) 189 monolithmetrics.gauge(metric=METRIC_PROCESS_HEALTH + '.spf', value=blue_data['spf']) 190 191 def LogCpuMemNet(self): 192 stats = _socket.getstats() 193 netBytesRead = stats['BytesReceived'] 194 netBytesWritten = stats['BytesSent'] 195 netReadCalls = stats['PacketsReceived'] 196 netWriteCalls = stats['PacketsSent'] 197 sessionCount = self.GetSessionCount() 198 serviceCalls = sum(CoreServiceCall.__recvServiceCallCount__.itervalues()) 199 callCounter = sm.GetService('machoNet').callCounter 200 callsFromClient = 0 201 for k in callCounter.iterkeys(): 202 if k[0] == const.ADDRESS_TYPE_CLIENT: 203 callsFromClient = callCounter[k] 204 break 205 206 self.send_to_monolithmetrics(netBytesRead, netBytesWritten, netReadCalls, netWriteCalls, serviceCalls, callsFromClient) 207 logline = {'pyDateTime': blue.os.GetWallclockTime(), 208 'bytesReceived': netBytesRead, 209 'bytesSent': netBytesWritten, 210 'packetsReceived': netReadCalls, 211 'packetsSent': netWriteCalls, 212 'sessionCount': sessionCount, 213 'tidiFactor': blue.os.simDilation, 214 'serviceCalls': serviceCalls, 215 'callsFromClient': callsFromClient} 216 self.logLines.append(logline) 217 218 def DoOnceEvery10Secs(self): 219 self.LogCpuMemNet() 220 221 def DoOnceEvery10Minutes(self): 222 self.WriteLog(20, True) 223 224 def FormatLog(self, logLines, logAll = False, logHeader = False): 225 txt = '' 226 allColumnNames = self.columnNames + tuple(sorted(set(logLines[0].iterkeys()).difference(self.columnNames))) 227 if self.lastLoggedLine == 0 or logAll or logHeader: 228 for name in allColumnNames: 229 txt += '%s\t' % name 230 231 txt += '\n' 232 for l in xrange(0, len(logLines) - 1): 233 logLine = logLines[l] 234 if logLine['dateTime'] > self.lastLoggedLine or logAll: 235 self.lastLoggedLine = logLine['dateTime'] 236 for name in allColumnNames: 237 if name in ('dateTime', 'pyDateTime'): 238 txt += '%s\t' % FmtDateEng(logLine[name]) 239 elif round(logLine[name], 2).is_integer(): 240 txt += '%s\t' % str(logLine[name]) 241 else: 242 txt += '%.4f\t' % logLine[name] 243 244 txt += '\n' 245 246 return txt 247 248 def WriteLog(self, minutes = 0, useIncrementalStartPos = False, useLogNotice = False): 249 logger = self.LogInfo 250 if useLogNotice: 251 logger = self.LogNotice 252 dumpPath = prefs.GetValue('ProcessHealthLogPath', None) 253 if dumpPath is None: 254 logger('Will not dump processhealth info since it is not configured in prefs (ProcessHealthLogPath)') 255 return 256 logger('WriteLog', minutes, useIncrementalStartPos) 257 startTime = blue.os.GetWallclockTime() 258 logLines = self.GetProcessInfo(minutes, useIncrementalStartPos) 259 if not os.path.exists(dumpPath): 260 os.makedirs(dumpPath) 261 fileName = self._GetLogFileName(dumpPath, self.startDateTime) 262 shouldCreateNewFile = not os.path.exists(fileName) 263 txt = self.FormatLog(logLines, logHeader=shouldCreateNewFile) 264 if shouldCreateNewFile: 265 self._SetStartTime() 266 fileName = self._GetLogFileName(dumpPath, self.startDateTime) 267 with open(fileName, 'w') as f: 268 f.write(txt) 269 else: 270 with open(fileName, 'a') as f: 271 f.write(txt) 272 diff = (blue.os.GetWallclockTime() - startTime) / float(const.SEC) 273 logger('Finished writing out %s entries from processHealth into %s in %.3f seconds' % (len(logLines), fileName, diff)) 274 275 def _GetLogFileName(self, dumpPath, time): 276 fileName = 'PHS %s %s %s %s %s %s.txt' % (self.computerName, 277 self.nodeIndex, 278 self.nodeID, 279 boot.role, 280 blue.os.pid, 281 time) 282 fileName = os.path.join(dumpPath, fileName.replace(':', '.').replace(' ', '.')) 283 return fileName 284 285 def DoOnceEveryHour(self): 286 try: 287 self.LogProcessMemoryAsSeenByTheOperatingSystem() 288 except Exception: 289 log.LogException('Failed Log memory') 290 291 def LogProcessMemoryAsSeenByTheOperatingSystem(self): 292 realMemory = self._GetProcessMemory(self._pid) 293 numberOfEvePlayers = sm.GetService('machoNet').GetNumberOfEVEUsersConnected() 294 self.LogNotice('OS Process Memory:', realMemory, 'serverName:', self.computerName, 'nodeID:', self._nodeID, 'serviceMask:', self._serviceMask, 'clusterGroup:', self._clusterGroup, 'nodeSessionCount:', GetNumberOfCharacterSessions(), 'clusterUserCount:', 0 if numberOfEvePlayers is None else numberOfEvePlayers) 295 296 def _GetServerName(self, nodeID): 297 machoNet = sm.GetService('machoNet') 298 return machoNet.serverNames[nodeID] 299 300 def _GetProcessMemory(self, pid): 301 line = subprocess.Popen('tasklist /FO csv /FI "PID eq %s" /NH' % self._pid, stdout=subprocess.PIPE) 302 memory = line.stdout.read().split('"')[9] 303 return int(memory.split(' ')[0].replace(',', '').replace('.', '')) * 1024