def FormatLog(self, logLines, logAll = False):
"""
Generate the formatted log (tab-delimited).
"""
txt = ''
allColumnNames = self.columnNames + tuple(sorted(set(logLines[0].iterkeys()).difference(self.columnNames)))
if self.lastLoggedLine == 0 or logAll:
for name in allColumnNames:
txt += '%s\t' % name
txt += '\n'
for l in xrange(0, len(logLines) - 1):
logLine = logLines[l]
if logLine['dateTime'] > self.lastLoggedLine or logAll:
self.lastLoggedLine = logLine['dateTime']
for name in allColumnNames:
if name in ('dateTime', 'pyDateTime'):
txt += '%s\t' % util.FmtDateEng(logLine[name])
elif round(logLine[name], 2).is_integer():
txt += '%s\t' % str(logLine[name])
else:
txt += '%.4f\t' % logLine[name]
txt += '\n'
return txt
def PrepareStatsPackage(self, event, stats):
try:
charid = session.charid or 0
except AttributeError:
charid = 0
try:
userid = session.userid or 0
blue.SetCrashUserId(userid)
except AttributeError:
userid = 0
try:
sid = session.sid
blue.SetCrashSessionId(sid)
except AttributeError:
sid = 0
package = [event,
charid,
userid,
sid,
util.FmtDateEng(blue.os.GetWallclockTime(), 'sl'),
stats.values()]
return package
def __init__(self, *args):
service.Service.__init__(self, *args)
self.logLines = []
self.startDateTime = util.FmtDateEng(blue.os.GetWallclockTime(), 'ss')
self.cache = util.KeyVal
self.cache.cacheTime = 0
self.cache.minutes = 0
self.cache.cache = []
self.lastLoggedLine = 0
self.lastStartPos = 0
self.columnNames = ('dateTime', 'pyDateTime', 'procCpu', 'threadCpu', 'blueMem', 'pyMem', 'virtualMem', 'runnable1', 'runnable2', 'watchdog time', 'spf', 'serviceCalls', 'callsFromClient', 'crestRequests')
def PersistToFile_Thread_Json(self, logEvents):
"""
This runs on a separate hardware thread so that we do not block on IO
A file is created if it does not exist of the (default) name events_[date] [time]_[nodeID].json
where [time] is [hh].00. A new file is created every hour
"""
if len(logEvents) > self.numPersistEventsWarningThreshold:
self.broker.LogWarn('I am going to persist', len(logEvents),
'events which is above the warning threshold')
maxEventLength = self.maxEventLength
delimeter = self.delimeter.replace('\\t', '\t')
nodeID = self.broker.machoNet.GetNodeID()
try:
charID = session.charid
except:
charID = None
startTime = blue.os.GetWallclockTimeNow()
dateAndHour, minutes = util.FmtDateEng(startTime, 'ss').split(':')
fileNameDateTime = dateAndHour + '.%02d' % (
int(minutes) - int(minutes) % self.logFileCycleMinutes)
fileNameDatePart = fileNameDateTime.split(' ')[0]
fileName = os.path.join(
self.logPath, self.logFileNameFormatJson % {
'dateTime': fileNameDateTime,
'nodeID': nodeID,
'charID': charID
})
with open(fileName, 'a') as logFile:
for timestamp, event in logEvents:
dt = FmtEventLogDate(timestamp)
if dt.split(' ')[0] != fileNameDatePart:
self.broker.LogInfo(
'Logline falls on a different day than file', dt, 'vs',
fileNameDateTime, 'fudging it.')
dt = fileNameDatePart + ' 00:00:00.000'
try:
try:
txt = json.dumps(event)
except:
txt = json.dumps(event, ensure_ascii=False)
except Exception as e:
self.broker.LogError('Error dumping to json. Error was ',
e, 'Event Skipped', event)
continue
txt = txt.replace('\r', '\\r').replace('\n', '\\n')
txt += '\n'
logFile.write(txt)
duration = (blue.os.GetWallclockTimeNow() - startTime) / const.MSEC
self.broker.LogInfo('Done persisting', len(logEvents), 'events to',
fileName, 'in', duration, 'ms')
def GetHtmlStateDetails(self, k, v, detailed):
import htmlwriter
if k == 'cachedObjects':
if detailed:
hd = [
'ObjectID', 'Time Stamp', 'Version', 'Shared', 'NodeID',
'Size'
]
li = []
for ik, iv in v.iteritems():
l = '???'
if iv.pickle:
l = '%d' % len(iv.pickle)
if iv.compressed:
l += ' (compressed)'
li.append([
iv.objectID,
util.FmtDateEng(iv.version[0]), iv.version[1],
iv.shared, iv.nodeID, l
])
return ('Object Cache',
htmlwriter.GetTable(hd, li, useFilter=True))
else:
return ('Object Cache', '%d entries' % len(v))
elif k == 'cachedObjectReturnStatistics':
if detailed:
hd = ['ObjectID', 'Count', 'Bytes']
li = []
for ik, iv in v.iteritems():
if type(ik) == types.TupleType and len(
ik) == 2 and ik[0] in sm.services:
ik = '%s::%s' % ik
li.append([htmlwriter.Swing(str(ik)), iv[0], iv[1]])
li.sort()
return ('Object Cache Statistics',
htmlwriter.GetTable(hd, li, useFilter=True))
else:
totCalls = 0
totBytes = 0
for each in v.itervalues():
totCalls += each[0]
totBytes += each[1]
return (
'Object Cache Statistics',
'%d distinct objects returned via %d calls, totalling %d bytes'
% (len(v), totCalls, totBytes))
def GenCodeAccessor(pw, goldName='GoldenCD.pikl', bluekeyName='bluekey.h'):
c = TmpContext()
timeStamp = util.FmtDateEng(blue.os.GetWallclockTime())
pwkey = KeyFromPassword(c, pw)
siglen = 1024
sig = CryptGenKey(c, AT_SIGNATURE, siglen << 16 | CRYPT_EXPORTABLE)
public = CryptExportKey(sig, None, PUBLICKEYBLOB, 0)
private = CryptExportKey(sig, pwkey, PRIVATEKEYBLOB, 0)
cryptlen = 168
crypt = CryptGenKey(c, CALG_3DES, cryptlen << 16 | CRYPT_EXPORTABLE)
crypt = ExportPlainSessionBlob(c, crypt)
f = file(bluekeyName, 'w')
WriteBlueSrc(f, timeStamp, public, crypt)
f.close()
gold = {
'timeStamp': timeStamp,
'codeSignaturePublic': public,
'codeSignaturePrivate': private,
'codeEncryption': crypt,
'date': util.FmtDateEng(blue.os.GetWallclockTime())
}
f = file(goldName, 'w')
cPickle.dump(gold, f)
f.close()
def ValidateCrashData(self, crashData, sid):
"""
Validates crash data read from a session file.
Returns normalized crash data if valid, otherwise None.
"""
try:
crashKwd = crashData[0]
if crashKwd == 'shutdown':
return ['shutdown']
userid = crashData[1]
clientid = crashData[2]
timeStamp = crashData[3]
build = crashData[4]
dumpId = crashData[5]
uploadResult = crashData[6]
if crashKwd != 'crashed':
return None
if build < 0:
return None
if build > 999999:
return None
if len(dumpId) != 36:
return None
parts = dumpId.split('-')
if len(parts) != 5:
return None
if len(parts[0]) != 8:
return None
if len(parts[1]) != 4:
return None
if len(parts[2]) != 4:
return None
if len(parts[3]) != 4:
return None
if len(parts[4]) != 12:
return None
if uploadResult < -1 or uploadResult > 3:
return None
crashInfo = self.BuildCrashInfo(build, uploadResult, sid)
return [dumpId,
userid,
clientid,
util.FmtDateEng(timeStamp, 'sl'),
crashInfo]
except:
return None
def PersistToFile_Thread(self, logEvents):
if len(logEvents) > self.numPersistEventsWarningThreshold:
self.broker.LogWarn('I am going to persist', len(logEvents),
'events which is above the warning threshold')
maxEventLength = self.maxEventLength
delimeter = self.delimeter.replace('\\t', '\t')
nodeID = self.broker.machoNet.GetNodeID()
try:
charID = session.charid
except:
charID = None
startTime = blue.os.GetWallclockTimeNow()
dateAndHour, minutes = util.FmtDateEng(startTime, 'ss').split(':')
fileNameDateTime = dateAndHour + '.%02d' % (
int(minutes) - int(minutes) % self.logFileCycleMinutes)
fileNameDatePart = fileNameDateTime.split(' ')[0]
self.currFileName = fileName = os.path.join(
self.logPath, self.logFileNameFormat % {
'dateTime': fileNameDateTime,
'nodeID': nodeID,
'charID': charID
})
with open(fileName, 'a') as logFile:
for timestamp, line in logEvents:
dt = FmtEventLogDate(timestamp)
if dt.split(' ')[0] != fileNameDatePart:
self.broker.LogInfo(
'Logline falls on a different day than file', dt, 'vs',
fileNameDateTime, 'fudging it.')
dt = fileNameDatePart + ' 00:00:00.000'
txt = '%s%s' % (dt, delimeter)
txt += delimeter.join(map(strx, line))
txt = txt.replace('\r', '\\r').replace('\n', '\\n')
if len(txt) > maxEventLength:
txt = txt[:maxEventLength]
self.broker.LogWarn('Event too long. Cutting it to',
self.maxEventLength, 'characters', txt)
txt += '\n'
logFile.write(txt)
duration = (blue.os.GetWallclockTimeNow() - startTime) / const.MSEC
self.broker.LogInfo('Done persisting', len(logEvents), 'events to',
fileName, 'in', duration, 'ms')
def ValidateCrashData(self, crashData, sid):
try:
crashKwd = crashData[0]
if crashKwd == 'shutdown':
return ['shutdown']
userid = crashData[1]
clientid = crashData[2]
timeStamp = crashData[3]
build = crashData[4]
dumpId = crashData[5]
uploadResult = crashData[6]
if crashKwd != 'crashed':
return None
if build < 0:
return None
if len(dumpId) != 36:
return None
parts = dumpId.split('-')
if len(parts) != 5:
return None
if len(parts[0]) != 8:
return None
if len(parts[1]) != 4:
return None
if len(parts[2]) != 4:
return None
if len(parts[3]) != 4:
return None
if len(parts[4]) != 12:
return None
if uploadResult < -1 or uploadResult > 3:
return None
crashInfo = self.BuildCrashInfo(build, uploadResult, sid)
return [dumpId,
userid,
clientid,
util.FmtDateEng(timeStamp, 'sl'),
crashInfo]
except:
return None
def GetSysInfo(self):
pyinfo = [('pythonver', sys.version)]
env = blue.pyos.GetEnv()
hd, li = blue.pyos.GetThreadTimes()
created = li[hd.index('created')]
kernel = li[hd.index('kernel')]
user = li[hd.index('user')]
cputime = kernel + user
uptime = blue.os.GetWallclockTime() - created
cpu = float(cputime) / uptime
hd, li = blue.pyos.ProbeStuff()
hd = list(hd)
workingSetSize = li[hd.index('workingSetSize')]
pagefileUsage = li[hd.index('pagefileUsage')]
ram = 1 + blue.win32.GlobalMemoryStatus()['TotalPhys'] / 1024 / 1024
hostinfo = [('hostname', env.get('COMPUTERNAME', '?')),
('domain', env.get('USERDNSDOMAIN', '?')),
('cpuid', env.get('PROCESSOR_IDENTIFIER', '?')),
('cpucount', env.get('NUMBER_OF_PROCESSORS', '?')),
('cpuspeed', '%s GHz' % round(blue.os.GetCycles()[1] / 1000000000.0, 1)),
('starttime', util.FmtDateEng(created)),
('uptime', util.FmtTimeEng(uptime)),
('cputime', util.FmtTimeEng(cputime)),
('kerneltime', util.FmtTimeEng(kernel)),
('usertime', util.FmtTimeEng(user)),
('currentcpu', '%.1f%%' % (self.GetCPULoad(35) * 100.0)),
('ram', '%s MB' % ram),
('memusage', '%s K' % util.FmtAmtEng(workingSetSize / 1024)),
('vmsize', '%s K' % util.FmtAmtEng(pagefileUsage / 1024)),
('nodeid', sm.services['machoNet'].nodeID)]
buildinfo = [('version', boot.version),
('build', boot.build),
('codename', str(boot.codename)),
('region', str(boot.region)),
('role', macho.mode)]
return pyinfo + hostinfo + buildinfo
def Startup(servicesToRun,
startInline=[],
serviceManagerClass='ServiceManager'):
import blue
args = blue.pyos.GetArg()[1:]
autoexec_common.LogStarting('Server')
import nasty
additionalScriptDirs = [
'script:/../../../carbon/backend/script/',
'script:/../../backend/script/'
]
telemetryStarted = False
for argument in args:
if argument.startswith('/telemetryServer='):
tmServer = str(argument[17:])
print 'Telemetry starting up on %s (from cmdline)' % tmServer
blue.statistics.StartTelemetry(tmServer)
blue.pyos.taskletTimer.telemetryOn = 1
telemetryStarted = True
if not telemetryStarted:
telemetryServer = prefs.GetValue('startupTelemetryServer', None)
if telemetryServer is not None:
print 'Telemetry starting up on %s (from prefs)' % telemetryServer
blue.statistics.StartTelemetry(telemetryServer)
blue.pyos.taskletTimer.telemetryOn = 1
telemetryStarted = True
if '/jessica' in args:
additionalScriptDirs.extend(
['script:/../../../carbon/tools/jessica/script/'])
useExtensions = '/noJessicaExtensions' not in args
if useExtensions:
additionalScriptDirs.extend([
'script:/../../../carbon/tools/jessicaExtensions/script/',
'script:/../../tools/jessicaExtensions/script/'
])
nasty.Startup(additionalScriptDirs)
import util
import types
print 'Nasty was started @ -', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() - nastyStarted))
import localization
localization.LoadLanguageData()
t0 = blue.os.GetWallclockTimeNow()
t00 = t0
import gc
gc.disable()
autoexec_common.LogStarted('Server')
for i in args:
if len(i) > 0 and i[0] != '-' and i[0] != '/':
print 'Executing', strx(i)
blue.pyos.ExecFile(i, globals())
import service
smClass = getattr(service, serviceManagerClass)
srvMng = smClass(startInline=['DB2', 'machoNet'] + startInline)
log.general.Log('Startup: Starting Core Services...', log.LGNOTICE)
print 'Core Services Starting @', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() - t0))
startServices = ('machoNet', 'alert', 'objectCaching', 'debug')
srvMng.Run(startServices)
macho = sm.services['machoNet']
DB2 = sm.services['DB2']
dbzcluster = DB2.GetSchema('zcluster')
dbzsystem = DB2.GetSchema('zsystem')
while True:
r = macho.AreTheseServicesRunning(startServices)
if r is None:
break
log.general.Log('Startup: Waiting for %s' % r, log.LGNOTICE)
print 'Startup: Waiting for', strx(r)
blue.pyos.synchro.SleepWallclock(3000)
print 'Database: ' + DB2.GetConnectionString()
blue.os.SetAppTitle(
'[%s %s.%s] %s %s %s.%s pid=%s' %
(macho.GetNodeID(), macho.GetBasePortNumber(), boot.region.upper(),
boot.codename, boot.role, boot.version, boot.build, blue.os.pid))
startupInfo = dbzcluster.Cluster_StartupInfo()[0]
dbClusterMode = startupInfo.clusterMode
if dbClusterMode != prefs.clusterMode:
s = 'DB / Server disagree on cluster mode. Server says %s, but DB says %s' % (
prefs.clusterMode, dbClusterMode)
log.general.Log('###', log.LGERR)
log.general.Log('### ' + s, log.LGERR)
log.general.Log('###', log.LGERR)
log.Quit(s)
print '...'
log.general.Log('Server Configuration:', log.LGNOTICE)
log.general.Log(' NodeID: %s' % macho.GetNodeID(), log.LGNOTICE)
log.general.Log(' NodeName: %s' % macho.GetNodeName(), log.LGNOTICE)
log.general.Log(' Base Port: %s' % macho.GetBasePortNumber(), log.LGNOTICE)
log.general.Log(' Region: %s' % boot.region.upper(), log.LGNOTICE)
log.general.Log(' CodeName: %s' % boot.codename, log.LGNOTICE)
log.general.Log(' Role: %s' % boot.role, log.LGNOTICE)
log.general.Log(' Version: %s.%s' % (boot.version, boot.build),
log.LGNOTICE)
log.general.Log(' ProcessID: %s' % blue.os.pid, log.LGNOTICE)
log.general.Log(' clusterMode: %s' % startupInfo.clusterMode, log.LGNOTICE)
log.general.Log(' Host: %s' % blue.pyos.GetEnv().get('COMPUTERNAME', '?'),
log.LGNOTICE)
log.general.Log('Startup: Synchronizing Clock with DB...', log.LGNOTICE)
originalNow = blue.os.GetWallclockTimeNow()
timediff = 0
for i in xrange(20):
now1 = blue.os.GetWallclockTimeNow()
dbnow = dbzsystem.DateTime()[0].dateTime
now2 = blue.os.GetWallclockTimeNow()
now = (now1 + now2) / 2
if abs(dbnow - now) < (i + 1) * const.SEC:
break
reason = 'DB / Server time horribly out of synch, DB says now=%s but server thinks now=%s' % (
util.FmtDateEng(dbnow), util.FmtDateEng(now))
log.general.Log(reason, 2)
if prefs.clusterMode != 'LIVE':
newnow = dbnow + (now2 - now1) / 2
log.general.Log(
'Resetting clock, setting time: ' + util.FmtDateEng(newnow),
log.LGNOTICE)
print 'Correcting clock to match DB ... advancing ', float(
newnow - now2) / float(const.SEC), ' secs'
t0 += newnow - now2
blue.pyos.synchro.ResetClock(newnow)
elif i < 10:
log.general.Log('Retrying clock check to prevent node death',
log.LGERR)
continue
else:
log.Quit(
'DB / Server time horriby out of synch on live cluster. Please perform a manual time synch.'
)
finalNow = blue.os.GetWallclockTimeNow()
sm.ScatterEvent('OnTimeReset', originalNow, finalNow)
nasty.nasty.OnTimeReset(originalNow, finalNow)
log.general.Log(
'Startup: Marking myself as ready for connectivity establishment in zcluster.nodes',
log.LGNOTICE)
print 'Server Ready @', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() - t0))
dbzcluster.Nodes_SetStatus(macho.GetNodeID(), -4)
macho.SetStatusKeyValuePair('clusterStatus', -400)
macho.SetStatusKeyValuePair('clusterStatusText',
'Ready for connectivity establishment')
log.general.Log('Startup: Establishing Connectivity...', log.LGNOTICE)
print 'Establishing Connectivity @', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() - t0))
if prefs.GetValue('skipConnectivity', 0):
log.general.Log(
'Startup: skipConnectivity has been set, skipping connectivity tests...'
)
if not macho.IsResurrectedNode() and not prefs.GetValue(
'skipConnectivity', 0):
offsetClock = None
if macho.GetNodeID() == macho.GetNodeFromAddress(
const.cluster.SERVICE_POLARIS, 0):
offsetClock = t0 - t00
macho.readyToConnect = True
startConnectivityCheck = blue.os.GetWallclockTime()
while 1:
try:
log.general.Log('Startup: Refreshing Connectivity...',
log.LGINFO)
macho.RefreshConnectivity()
except StandardError:
log.general.Log('Startup: Error refreshing connectivity...',
log.LGWARN)
log.LogException(toConsole=1,
toLogServer=1,
severity=log.LGWARN)
sys.exc_clear()
blue.pyos.synchro.SleepWallclock(500)
try:
log.general.Log(
'Startup: Performing cluster readiness test...',
log.LGINFO)
now = blue.os.GetWallclockTimeNow()
if now > startConnectivityCheck + LOG_CONNECTIVITY_ERROR_TIME:
log.general.Log(
'I have been checking the network connectivity for a long time.... Should we go and check out why?',
log.LGERR)
startConnectivityCheck = now
ready = dbzcluster.Cluster_Ready(-4)
if type(ready) == types.IntType:
if not ready:
print 'More Nodes Starting, pausing and retrying'
log.general.Log('Startup: More nodes starting',
log.LGNOTICE)
blue.pyos.synchro.SleepWallclock(5000)
continue
elif ready[0].readyWhen is None:
log.Quit(
'The DB says that even I am not ready, but I have already passed my ready marker! Shutting down.'
)
else:
ready = ready[0]
until = ready.readyWhen + const.SEC * 70 * 5
if until > now:
s = min(70000 / 4,
(until - now) / const.SEC * 1000 + 1000)
log.general.Log(
'Startup: Last startup was at %s. Waiting %s before retrying, now=%s'
% (util.FmtDateEng(ready.readyWhen),
util.FmtDateEng(until), util.FmtDateEng(now)),
log.LGWARN)
else:
print 'Only %d nodes have registered themselves in zcluster.nodes and the safetytime has been passed by far...' % ready.nodeCount
log.general.Log(
'Startup: Only %d nodes have registered in zcluster.nodes, but the safetytime has been passed by far...'
% ready.nodeCount, log.LGERR)
s = 70000
print 'Waiting ', s, ' millisecs prior to rechecking'
blue.pyos.synchro.SleepWallclock(s)
continue
startupInfo = dbzcluster.Cluster_StartupInfo()[0]
log.general.Log(
'Startup: Connectivity test - calling all proxies...',
log.LGINFO)
p = macho.session.ConnectToAllProxyServerServices(
'machoNet').ConnectivityTest(
offsetClock,
startupInfo.proxyNodeCount - 1,
startupInfo.serverNodeCount -
startupInfo.unexpectServerNodeCount,
uberMachoRaise=True)
if len(p) != startupInfo.proxyNodeCount:
log.general.Log(
'Startup: %d proxy nodes available, %d proxy nodes expected...'
% (len(p), startupInfo.proxyNodeCount), log.LGINFO)
print '%d proxy nodes available, %d proxy nodes expected...' % (
len(p), startupInfo.proxyNodeCount)
blue.pyos.synchro.SleepWallclock(500)
continue
for isexception, nodeID, ret in p:
if not ret:
log.general.Log(
'Startup: Proxy %d failed its connectivity test' %
nodeID, log.LGINFO)
raise UberMachoException(
'Proxy failed connectivity test')
minimumProxyCount = prefs.GetValue(
'machoNet.minimumProxyCount', 0) or max(
1, int(startupInfo.proxyNodeCount * 0.8))
if len(p) < minimumProxyCount:
print 'Too few proxy nodes succeeded in starting to make this run worthwhile'
log.general.Log(
'Too few proxy nodes succeeded in starting to make this run worthwhile',
log.LGERR)
log.general.Log(
'Minimum=%d, Actual=%d' % (minimumProxyCount, len(p)),
log.LGERR)
blue.pyos.synchro.SleepWallclock(10000)
continue
log.general.Log(
'Startup: Connectivity test - calling all sols...',
log.LGINFO)
s = macho.session.ConnectToAllSolServerServices(
'machoNet').ConnectivityTest(
offsetClock,
startupInfo.proxyNodeCount,
startupInfo.serverNodeCount - 1 -
startupInfo.unexpectServerNodeCount,
uberMachoRaise=True)
if len(
s
) != startupInfo.serverNodeCount - startupInfo.unexpectServerNodeCount:
log.general.Log(
'Startup: %d server nodes available, %d server nodes expected...'
% (len(s), startupInfo.serverNodeCount), log.LGINFO)
print '%d server nodes available, %d server nodes expected...' % (
len(s), startupInfo.serverNodeCount)
blue.pyos.synchro.SleepWallclock(500)
continue
for isexception, nodeID, ret in s:
if not ret:
log.general.Log(
'Startup: Server %d failed its connectivity test'
% nodeID, log.LGINFO)
raise UberMachoException(
'Server failed connectivity test')
minimumSolCount = prefs.GetValue(
'machoNet.minimumSolCount', 0) or max(
1, int(startupInfo.serverNodeCount * 0.8))
if len(s) < minimumSolCount:
print 'Too few sol nodes succeeded in starting to make this run worthwhile'
log.general.Log(
'Too few sol nodes succeeded in starting to make this run worthwhile',
log.LGERR)
log.general.Log(
'Minimum=%d, Actual=%d' % (minimumSolCount, len(s)),
log.LGERR)
blue.pyos.synchro.SleepWallclock(10000)
continue
break
except UberMachoException as e:
log.general.Log('Startup: network connectivity not achieved',
log.LGINFO)
sys.exc_clear()
except UnMachoDestination as e:
log.general.Log(
'Startup: network connectivity not yet achieved (%s)' %
e.payload, 2)
sys.exc_clear()
except:
log.LogException(
'Exception while pinging all proxies and sols')
sys.exc_clear()
print 'Connectivity achieved @', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() - t0))
if 'waitForPremapping' in startupInfo.__columns__ and int(
startupInfo.waitForPremapping) == 1:
polarisID = macho.GetNodeFromAddress(const.cluster.SERVICE_POLARIS, 0)
while macho.GetNodeID() != polarisID and dbzcluster.Nodes_Status(
polarisID) < -3:
print 'Waiting for Polaris to reach premapping stage.. sleeping 5 seconds..'
blue.pyos.synchro.SleepWallclock(5000)
if prefs.clusterMode in ('TEST', 'LIVE'):
if macho.GetNodeID() == macho.GetNodeFromAddress(
const.cluster.SERVICE_POLARIS, 0):
if not macho.IsResurrectedNode():
dbzcluster.Cluster_PreMap()
log.general.Log(
'Startup: Marking myself as ready for distributed startup phase in zcluster.nodes',
log.LGNOTICE)
dbzcluster.Nodes_SetStatus(macho.GetNodeID(), -3)
macho.SetStatusKeyValuePair('clusterStatus', -300)
macho.SetStatusKeyValuePair('clusterStatusText',
'Ready for distributed setup')
log.general.Log('Startup: Priming address cache...', log.LGNOTICE)
while 1:
try:
if macho.IsResurrectedNode():
print 'Priming address cache directly @', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() -
t0))
log.general.Log('Startup: Priming address cache directly...',
log.LGINFO)
macho.PrimeAddressCache(dbzcluster.Addresses_PrimeCache())
elif macho.GetNodeID() == macho.GetNodeFromAddress(
const.cluster.SERVICE_POLARIS, 0):
print 'Orchestrating priming of address cache @', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() -
t0))
log.general.Log(
'Startup: Orchestrating priming of address cache...',
log.LGINFO)
macho.session.ConnectToAllSolServerServices(
'machoNet').PrimeAddressCache(
dbzcluster.Addresses_PrimeCache(), uberMachoRaise=True)
else:
print 'Waiting for completion of priming of address cache @', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() -
t0))
if macho.GetNodeID() == macho.GetNodeFromAddress(
const.cluster.SERVICE_POLARIS, 0):
print "Polaris has died, and I have resumed it's responsibilities"
log.general.Log(
"Polaris has died, and I have resumed it's responsibilities",
log.LGERR)
continue
break
except:
print 'Priming address cache failure, retrying...'
log.LogException(
'Exception while priming address cachep. I am%s Polaris' %
[' NOT', ''][macho.GetNodeID() == macho.GetNodeFromAddress(
const.cluster.SERVICE_POLARIS, 0)])
sys.exc_clear()
log.general.Log(
'Startup: Marking myself as ready for starting user service phase in zcluster.nodes',
log.LGNOTICE)
dbzcluster.Nodes_SetStatus(macho.GetNodeID(), -2)
macho.SetStatusKeyValuePair('clusterStatus', -200)
macho.SetStatusKeyValuePair('clusterStatusText', 'Starting user services')
log.general.Log('Startup: Starting User Services...', log.LGNOTICE)
print 'User Services Starting @', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() - t0))
blue.pyos.taskletTimer.Reset()
sys.clearmemcontexts()
blue.pyos.taskletTimer.active = 1
srvMng.Run(servicesToRun)
import ttimerutil
timers = ttimerutil.TaskletSnapshot()
blue.pyos.taskletTimer.active = 0
sys.setmemcontextsactive(False)
sys.clearmemcontexts()
totalCPUTime = 0
totalWallClockTime = 0
for timer in timers:
if timer.startswith('StartService::ServiceStartRun::') and timer.find(
'^') == -1:
serviceName = timer[31:]
if serviceName in srvMng.startupTimes:
serviceWallClockTime = srvMng.startupTimes[serviceName]
totalWallClockTime += serviceWallClockTime
else:
serviceWallClockTime = -1
serviceCPUTime = timers[timer].GetTime()
totalCPUTime += serviceCPUTime
log.general.Log(
'Startup: Service %s took %.4fs wallclock and %.4fs cpu time to startup'
% (serviceName, serviceWallClockTime, serviceCPUTime),
log.LGNOTICE)
log.general.Log(
'Startup: Estimated serial execution time: %.4fs Total CPU time spent %.4fs '
% (totalWallClockTime, totalCPUTime), log.LGNOTICE)
log.general.Log(
'Startup: Marking myself as ready for cluster startup tests in zcluster.nodes',
log.LGNOTICE)
dbzcluster.Nodes_SetStatus(macho.GetNodeID(), -1)
macho.SetStatusKeyValuePair('clusterStatus', -100)
macho.SetStatusKeyValuePair('clusterStatusText', 'Startup test phase')
if macho.IsResurrectedNode():
loop = True
while loop:
loop = False
try:
ret = macho.AreTheseServicesRunning(startServices)
if ret:
log.general.Log('Startup: Waiting for %s' % ret,
log.LGERR)
print 'Startup: Waiting for %s' % strx(ret)
loop = True
except:
log.LogException(
'Exception while performing distributed startup. I am%s Polaris'
%
[' NOT', ''][macho.GetNodeID() == macho.GetNodeFromAddress(
const.cluster.SERVICE_POLARIS, 0)])
sys.exc_clear()
log.Quit('Failed to determine service running state')
if loop:
blue.pyos.synchro.SleepWallclock(3000)
macho.readyToConnect = True
try:
log.general.Log('Startup: Refreshing Connectivity...',
log.LGNOTICE)
macho.RefreshConnectivity()
except StandardError:
log.general.Log('Startup: Error refreshing connectivity...',
log.LGWARN)
log.LogException(toConsole=1, toLogServer=1, severity=log.LGWARN)
sys.exc_clear()
sm.ScatterEvent(
'OnClusterStarting',
macho.GetNodeFromAddress(const.cluster.SERVICE_POLARIS, 0))
else:
sent = False
while not macho.clusterStartupPhase:
if not sent and macho.GetNodeID() == macho.GetNodeFromAddress(
const.cluster.SERVICE_POLARIS, 0):
print 'Cluster User Service Startup tests beginning @', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() -
t0))
loop = True
while loop:
loop = False
r = macho.session.ConnectToAllSolServerServices(
'machoNet').AreTheseServicesRunning(
startServices, uberMachoRaise=True)
for isexception, nodeID, ret in r:
if ret:
log.general.Log(
'Startup: Node %d waiting for %s' %
(nodeID, ret), log.LGERR)
print 'Startup: Node %d waiting for %s' % (
nodeID, strx(ret))
loop = True
break
if loop:
blue.pyos.synchro.SleepWallclock(3000)
if len(r) < minimumSolCount:
print 'Too few sol nodes succeeded in starting to make this run worthwhile'
raise UberMachoException(
'Too few sol nodes succeeded in starting to make this run worthwhile'
)
print 'Broadcasting OnClusterStarting'
log.general.Log('Startup: Broadcasting OnClusterStarting',
log.LGNOTICE)
macho.ClusterBroadcast('OnClusterStarting', macho.GetNodeID())
sent = True
blue.pyos.synchro.SleepWallclock(1000)
else:
print 'Waiting for OnClusterStarting...'
log.general.Log('Startup: Waiting for OnClusterStarting...',
log.LGNOTICE)
blue.pyos.synchro.SleepWallclock(3000)
log.general.Log(
"Startup: Marking myself as ready to rock'n'roll in zcluster.nodes",
log.LGNOTICE)
dbzcluster.Nodes_SetStatus(macho.GetNodeID(), 0)
macho.SetStatusKeyValuePair('clusterStatus', -50)
macho.SetStatusKeyValuePair('clusterStatusText', 'Ready in DB')
print '--------------------------------------------------------------'
if macho.GetNodeID() == macho.GetNodeFromAddress(
const.cluster.SERVICE_POLARIS, 0):
print 'Polaris - Cluster ready @', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() - t0))
else:
print 'Not Polaris - Server ready @', strx(
util.FmtTimeIntervalEng(blue.os.GetWallclockTimeNow() - t0))
ram = blue.win32.GetProcessMemoryInfo()['PagefileUsage'] / 1024 / 1024
msg = 'Memory Usage (virtual mem) : %sMb upon startup' % ram
macho.LogNotice(msg)
print msg
sm.ScatterEvent('OnServerStartupCompleted')
macho.SetStatusKeyValuePair('clusterStatus', 0)
macho.SetStatusKeyValuePair('clusterStatusText', 'Ready')
if bluepy.IsRunningStartupTest():
bluepy.TerminateStartupTest()
def ExportToFile(self, *args):
if self.isCorp:
orders = sm.GetService('marketQuote').GetCorporationOrders()
else:
orders = sm.GetService('marketQuote').GetMyOrders()
if len(orders) == 0:
eve.Message(
'CustomInfo', {
'info':
localization.GetByLabel(
'UI/Market/MarketWindow/ExportNoData')
})
return
date = util.FmtDateEng(blue.os.GetWallclockTime())
f = blue.classes.CreateInstance('blue.ResFile')
directory = blue.win32.SHGetFolderPath(
blue.win32.CSIDL_PERSONAL) + '\\EVE\\logs\\Marketlogs\\'
filename = '%s-%s.txt' % ([
localization.GetByLabel('UI/Market/Orders/MyOrders'),
localization.GetByLabel('UI/Market/Orders/CorporationOrders')
][self.isCorp], util.FmtDateEng(blue.os.GetWallclockTime(),
'ls').replace(':', ''))
filename = uiutil.SanitizeFilename(filename)
if not f.Open(directory + filename, 0):
f.Create(directory + filename)
first = 1
dateIdx = -1
numSell = numBuy = 0
for order in orders:
if first:
for key in order.__columns__:
f.Write('%s,' % key)
if key == 'charID':
f.Write('charName,')
elif key == 'regionID':
f.Write('regionName,')
elif key == 'stationID':
f.Write('stationName,')
elif key == 'solarSystemID':
f.Write('solarSystemName,')
f.Write('\r\n')
first = 0
for key in order.__columns__:
o = getattr(order, key, None)
if key == 'bid':
if o > 0:
numBuy += 1
else:
numSell += 1
if key == 'issueDate':
f.Write('%s,' % util.FmtDateEng(o, 'el').replace('T', ' '))
elif key == 'charID':
f.Write(
'%s,%s,' %
(o, str(cfg.eveowners.Get(o).name.encode('utf-8'))))
elif key in ('stationID', 'regionID', 'solarSystemID'):
f.Write('%s,%s,' %
(o, cfg.evelocations.Get(o).name.encode('utf-8')))
else:
f.Write('%s,' % o)
f.Write('\r\n')
f.Close()
eve.Message(
'PersonalMarketExportInfo', {
'sell': numSell,
'buy': numBuy,
'filename': '<b>' + filename + '</b>',
'directory': '<b>%s</b>' % directory
})
def SendSimpleEmailAlert(self, message, recipients = None, subject = None, sysinfo = 1, html = 0, attachments = [], subjectonly = 0):
self.LogInfo('SendSimpleEmailAlert ', (len(message),
recipients,
subject,
sysinfo,
html))
if recipients is None:
recipients = self.mail_defaultrecpt
elif type(recipients) in types.StringTypes:
recipients = [recipients]
elif type(recipients) != types.ListType:
raise RuntimeError("SendSimpleEmailAlert: 'recipients' must be a list of strings")
if not recipients:
self.LogInfo('Not sending alert, no recipient specified', subject)
return
timestamp = util.FmtDateEng(blue.os.GetWallclockTime(), 'ns')
if subject is None:
subject = 'Server Alert: Alert from node %s on %s at %s' % (sm.services['machoNet'].nodeID, self.computername, timestamp)
elif subjectonly == 0:
subject = 'Server Alert: %s at %s' % (subject, timestamp)
if sysinfo:
if html:
message += '<br>\n<br>\nSysinfo:<br><table border=1>\n'
for k, v in self.GetSysInfo():
message += '<tr><td>%s</td><td>%s</td></tr>\n' % (k, v)
else:
message += '\n\n' + '-' * 78 + '\n'
for k, v in self.GetSysInfo():
message += '%-15s%s\n' % (k + ':', v)
from email.MIMEText import MIMEText
from email.MIMEMultipart import MIMEMultipart
from email.MIMEBase import MIMEBase
from email import encoders
msg = MIMEMultipart()
if html:
subtype = 'html'
charset = 'iso8859'
else:
subtype = 'plain'
charset = 'us-ascii'
if type(message) is unicode:
message = message.encode('utf-8')
charset = 'utf-8'
att = MIMEText(message, subtype, charset)
msg.attach(att)
subject = subject.replace('\n', '').replace('\r', '')
msg['Subject'] = subject
msg['From'] = self.mail_sender
msg['To'] = ', '.join(recipients)
for attName, attData in attachments:
io = cStringIO.StringIO()
zipfile = gzip.GzipFile(attName, 'w', 9, io)
zipfile.write(attData)
zipfile.close()
att = MIMEBase('application', 'gz')
att.set_payload(io.getvalue())
encoders.encode_base64(att)
att.add_header('Content-Disposition', 'attachment', filename=attName + '.gz')
msg.attach(att)
self.SendMail(self.mail_sender, recipients, msg.as_string(0))
def DumpOrdersForType(self, typeID):
orders = self.GetOrders(typeID)
sells = orders[0][0]
buys = orders[1][0]
if len(sells) > 0:
dateIdx = sells[0].__columns__.index('issueDate')
elif len(buys) > 0:
dateIdx = buys[0].__columns__.index('issueDate')
else:
eve.Message(
'CustomInfo', {
'info':
localization.GetByLabel(
'UI/Market/MarketWindow/ExportNoData')
})
return
date = util.FmtDate(blue.os.GetWallclockTime())
f = blue.classes.CreateInstance('blue.ResFile')
typeName = cfg.invtypes.Get(typeID).name
fileTypeName = localization.CleanImportantMarkup(typeName)
fileTypeName = fileTypeName.replace('"', '')
fileRegionName = localization.CleanImportantMarkup(
cfg.evelocations.Get(session.regionid).name)
directory = blue.win32.SHGetFolderPath(
blue.win32.CSIDL_PERSONAL) + '\\EVE\\logs\\Marketlogs\\'
sanitizedFileTypeName = uiutil.SanitizeFilename(fileTypeName)
filename = '%s-%s-%s.txt' % (
fileRegionName, sanitizedFileTypeName,
util.FmtDateEng(blue.os.GetWallclockTime()).replace(':', ''))
if not f.Open(directory + filename, 0):
f.Create(directory + filename)
first = 1
for order in sells:
if first:
for key in order.__columns__:
f.Write('%s,' % key)
f.Write('\r\n')
first = 0
for i in range(len(order)):
first = 0
if i == dateIdx:
f.Write('%s,' %
util.FmtDateEng(order[i], 'el').replace('T', ' '))
else:
f.Write('%s,' % order[i])
f.Write('\r\n')
for order in buys:
if first:
for key in order.__columns__:
f.Write('%s,' % key)
f.Write('\r\n')
first = 0
for i in range(len(order)):
if i == dateIdx:
f.Write('%s,' %
util.FmtDateEng(order[i], 'el').replace('T', ' '))
else:
f.Write('%s,' % order[i])
f.Write('\r\n')
f.Close()
eve.Message(
'MarketExportInfo', {
'sell':
len(sells),
'buy':
len(buys),
'typename':
cfg.invtypes.Get(typeID).name,
'filename':
localization.GetByLabel('UI/Map/StarMap/lblBoldName',
name=filename),
'directory':
localization.GetByLabel('UI/Map/StarMap/lblBoldName',
name=directory)
})
def GetOrMakeFile(self, *args):
import os
invalidChars = '\\/:*?"<>| '
timestamp = util.FmtDateEng(blue.os.GetWallclockTime())
for char in invalidChars:
timestamp = timestamp.replace(char, '.')
try:
import benchmark1
platform = benchmark1.GetPlatform()
hostname = platform['hostname']
except:
sys.exc_clear()
hostname = 'None'
filename = settings.public.generic.Get('eveBenchmarkFileName', None)
if not filename:
filename = '%s.%s.%s' % (timestamp, hostname, FILE_BM)
settings.public.generic.Set('eveBenchmarkFileName', filename)
f = blue.classes.CreateInstance('blue.ResFile')
BENCHMARKDIR = os.path.join(blue.win32.SHGetFolderPath(blue.win32.CSIDL_PERSONAL), 'EVE', 'logs', 'Benchmarks')
TARGET = os.path.join(BENCHMARKDIR, filename)
if not f.Open(TARGET, 0):
if f.FileExists(TARGET):
f.Open(TARGET, 0)
else:
if not os.path.exists(BENCHMARKDIR):
os.mkdir(BENCHMARKDIR)
f.Create(TARGET)
f.Write('<?xml version="1.0"?>')
f.Write('\r\n')
f.Write('<eveBenchmarking>')
f.Write('\r\n')
f.Write('\t<platform>')
f.Write('\r\n')
if platform:
for k, v in platform.iteritems():
if v.__class__ in (str, unicode):
v = v.encode()
f.Write('\t\t')
f.Write('<data')
f.Write(' key="%s"' % k)
f.Write(' value="%s"' % v)
f.Write(' />')
f.Write('\r\n')
for dkey, dvalue in self.AppGetTriAppData().iteritems():
f.Write('\t\t')
f.Write('<data')
f.Write(' key="%s"' % dkey)
f.Write(' value="%s"' % dvalue)
f.Write(' />')
f.Write('\r\n')
f.Write('\t</platform>')
f.Write('\r\n')
f.Write('\t<user>')
f.Write('\r\n')
for dkey, dvalue in {'charid': session.charid,
'userid': session.userid,
'transgaming': blue.win32.IsTransgaming()}.iteritems():
f.Write('\t\t')
f.Write('<data')
f.Write(' key="%s"' % dkey)
f.Write(' value="%s"' % dvalue)
f.Write(' />')
f.Write('\r\n')
f.Write('\t</user>')
f.Write('\r\n')
return f
def _SetStartTime(self):
self.startDateTime = util.FmtDateEng(blue.os.GetWallclockTime(), 'ss')
