def logging_callback(self, ch, method, properties, body):
#@defer.inlineCallbacks
# Show Raw Body:
logger.debug("Raw body: %r" % body)
# Decode the message as json
rcvd_task = json.loads(body.decode("utf-8"))
logger.debug("Raw task: %s", rcvd_task)
# Set some fields used in the response (uuid, receieve time, etc)
rcvd_task[GC_Utility.GC_CLIENTID] = self.uuid
rcvd_task[GC_Utility.GC_RECEIVE_TIME] = GC_Utility.currentZuluDT()
logger.debug("GC_CLIENTID: %s", rcvd_task[GC_Utility.GC_CLIENTID])
logger.debug("GC_RECEIVE_TIME: %s", rcvd_task[GC_Utility.GC_RECEIVE_TIME])
logger.info("Received task %s at %s", rcvd_task[GC_Utility.GC_TASKREF], rcvd_task[GC_Utility.GC_RECEIVE_TIME])
# This isn't used yet... someday...
# TODO: Use the create time from the received task.
create_time = datetime.utcnow() #dateutil.parser.parse(rcvd_task[GC_Utility.GC_RECEIVE_TIME])
logger.debug("create_time: %s", create_time)
# Figure out which module... key/value pair on moduleid with objects....
if rcvd_task[GC_Utility.GC_MODULEID] in self.gc_modules:
# Check create time + 5min, throw it away if it's too old
# TODO: use create time!!
if (datetime.utcnow() - create_time) < timedelta(seconds=(60*5)):
try:
# If the ModuleID matches a built-in function, create a response object, call the function and store the results
# else pass the task to the matched GC_CModule
if (inspect.ismethod(self.gc_modules[rcvd_task[GC_Utility.GC_MODULEID]])):
response = {}
response['startTime'] = GC_Utility.currentZuluDT()
response['result'] = self.gc_modules[rcvd_task[GC_Utility.GC_MODULEID]]()
self.sendResult(rcvd_task, response)
else:
self.gc_modules[rcvd_task[GC_Utility.GC_MODULEID]].handleTask(rcvd_task)
except Exception as e:
logger.warn("GCClient.logging_callback caught exception", exc_info=True)
#traceback.print_exc(file=sys.stdout)
# Task was too old
else:
logger.info(rcvd_task[GC_Utility.GC_TASK_ID] + " create time > 5 min old ")
# Module ID no found
else:
logger.warn(rcvd_task[GC_Utility.GC_MODULEID] + " not found in ", exc_info=True)
# TODO: Automatic diagnostics or logging every 100 tasks
if (self.numTasks % 100):
logger.debug("At some point this will send memory info.")
def log(self, log_level, msg):
if (log_level < self.logging_level):
return;
log_msg = {}
log_msg[GC_Utility.GC_LOG_DATETIME] = GC_Utility.currentZuluDT()
log_msg[GC_Utility.GC_CLIENTID] = self.uuid
log_msg[GC_Utility.GC_LOG_MSG] = msg
log_msg[GC_Utility.GC_VERSION] = self.version
curframe = inspect.currentframe()
calframe = inspect.getouterframes(curframe, 2)
log_msg['caller'] = "%s:%s:%s" % (calframe[1][1], calframe[1][3], calframe[1][2])
if (log_level == GC_Utility.DEBUG):
log_msg['level'] = "DEBUG"
elif (log_level == GC_Utility.WARN):
log_msg['level'] = "WARNING"
else:
log_msg['level'] = "INFO"
if self.ENABLE_COMMS:
self.comms.publish(exchange_name = self.log_exchange, routing_key=self.log_key, type='direct', message = json.dumps(log_msg))
else:
logger.info(log_msg)
def handleTask(self, gccommand) :
#self.gcclient.log(GC_Utility.DEBUG, "handleTask - [%s:%s] " % (gccommand[GC_Utility.GC_MODULEID], gccommand[GC_Utility.GC_TASKREF]) )
logger.debug('handleTask - [%s:%s]' % (gccommand[GC_Utility.GC_MODULEID], gccommand[GC_Utility.GC_TASKREF]))
# Initialize response
startTime = GC_Utility.currentZuluDT()
response = {}
response['startTime'] = startTime
# Initialize local variables
taskingObj = gccommand[GC_Utility.GC_CMD_DATA]
waitTime = float(taskingObj['timer'])
cmd = taskingObj['cmdline']
#self.gcclient.log(GC_Utility.DEBUG, 'execute: [%s for %s sec]' % (taskingObj['cmdline'], taskingObj['timer']))
logger.debug('execute: [%s for %s sec]' % (taskingObj['cmdline'], taskingObj['timer']))
try:
# Execute the command
p = subprocess.check_call(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, timeout=waitTime)
# Record stderr and stderr to the response
response['stdout'] = p.stdout.read()
response['stderr'] = p.stderr.read()
# Catch and log any errors
except Exception as e:
#self.gcclient.log(GC_Utility.WARN, 'Caught an exception while executing %s [%s]' % (cmd, e))
logger.warn('Caught an exception while executing %s' % (cmd), exc_info=True)
self.gcclient.sendResult(gccommand, response);
def downloadFile(self, gccommand):
# Initialize response object
startTime = GC_Utility.currentZuluDT()
response = {}
response['startTime'] = startTime
# Initialize local variables
taskingObj = gccommand[GC_Utility.GC_CMD_DATA]
request = taskingObj['url']
saveas = taskingObj['saveas']
#self.gcclient.log(GC_Utility.DEBUG, 'downloadFile: [%s as %s]' % (taskingObj['url'], taskingObj['saveas']))
logger.debug('downloadFile: [%s as %s]' %
(taskingObj['url'], taskingObj['saveas']))
# Check for existing file, move it to back up
GC_Utility.handleBackup(saveas, self.gcclient)
try:
# Download the file
f = urllib.request.urlopen(request)
data = f.read()
# Save the file
saveme = open(saveas, "wb")
with saveme as code:
code.write(data)
saveme.close()
# Send the file hash back
saveme = open(saveas, 'rb')
response['MD5'] = hashlib.md5(saveme.read()).hexdigest()
saveme.close()
# Connection errors are recorded into the response
except Exception as e:
response['ERROR'] = "HTTP Error " + e.strerror
#self.gcclient.log(GC_Utility.DEBUG, 'downloadFile : Sending result...');
logger.debug('downloadFile : Sending result...')
self.gcclient.sendResult(gccommand, response)
def sendOneOffResult(self, moduleId, respData):
# 2. ModuleID: Integer Associated with command module<br>
# 3. TaskRef: Integer defined by module<br>
# 4. RecieveTime: String (YYYYMMDDZHHMMSS.SSS) <br>
# 5. CompleteTime: String (YYYYMMDDZHHMMSS.SSS) <br>
# 6. ResponseData: Key Value array, defined by module<br>
taskObj = {}
taskObj[GC_Utility.GC_MODULEID] = moduleId
taskObj[GC_Utility.GC_COMPLETE_TIME] = GC_Utility.currentZuluDT()
taskObj[GC_Utility.GC_RESP_DATA] = respData
taskObj[GC_Utility.GC_VERSION] = self.version
logger.debug("Printing TaskObj: %r" % pprint.pformat(json.dumps(taskObj)))
if self.ENABLE_COMMS:
self.comms.publish(routing_key=self.resp_key, message = json.dumps(taskObj))
def sendResult(self, taskObj, respData):
# Set assemble the task and response objects.
taskObj[GC_Utility.GC_COMPLETE_TIME] = GC_Utility.currentZuluDT()
taskObj[GC_Utility.GC_RESP_DATA] = respData
taskObj[GC_Utility.GC_VERSION] = self.version
# delete unnecessary command data before returning the results
if GC_Utility.GC_CMD_DATA in taskObj:
del taskObj[GC_Utility.GC_CMD_DATA]
# Print and/or send the compiled response
logger.debug("Printing TaskObj: %r" % pprint.pformat(json.dumps(taskObj)))
if self.ENABLE_COMMS:
self.comms.publish(routing_key=self.resp_key, message = json.dumps(taskObj))
else:
logger.info("Result: %r" % pprint.pformat(json.dumps(taskObj)))
def handleTask(self, gccommand) :
#self.gcclient.log(GC_Utility.DEBUG, "handleTask - [%s:%s] " % (gccommand[GC_Utility.GC_MODULEID], gccommand[GC_Utility.GC_TASKREF]) )
logger.debug('handleTask - [%s:%s] ' % (gccommand[GC_Utility.GC_MODULEID], gccommand[GC_Utility.GC_TASKREF]))
startTime = GC_Utility.currentZuluDT()
taskingObj = gccommand[GC_Utility.GC_CMD_DATA]
response = {}
response['startTime'] = startTime
if (taskingObj['cmd'] == 'sendemail'):
self.sendEmail(taskingObj['msg'], taskingObj['sender'], taskingObj['receivers'], gccommand[GC_Utility.GC_TASKREF] )
#self.gcclient.log(GC_Utility.DEBUG, 'handleTask :: email :: Sending result...');
logger.debug('email :: Sending result...')
self.gcclient.sendResult(gccommand, response);
def execTask(self, gccommand):
logger.debug('handleTask - [%s:%s]' %
(gccommand[GC_Utility.GC_MODULEID],
gccommand[GC_Utility.GC_TASKREF]))
startTime = GC_Utility.currentZuluDT()
# Initialize local copies of the task
taskingObj = gccommand[GC_Utility.GC_CMD_DATA]
cmd = taskingObj['cmd']
url = taskingObj['url']
timer = taskingObj['timer']
# Initialize response object
response = {}
response['startTime'] = startTime
response['browserVersion'] = self.driver.capabilities['browserVersion']
logger.info('excuteCmd : [%s:%s(%s)]' %
(gccommand[GC_Utility.GC_MODULEID], cmd, url))
# Command the browser to load the URL
try:
self.loadAndParse(url, response, gccommand, timer)
except WebDriverException as e:
logger.warn("Caught an WebDriverException in Selenium.")
response['Title'] = 'Error'
response['page_md5'] = 'Error'
response['links_md5'] = 'Error'
response['error'] = 'WebDriverException'
response['exception'] = str(e.__str__)
except Exception as e:
logger.warn("Caught an Generic Exception in Selenium.")
response['Title'] = 'Error'
response['page_md5'] = 'Error'
response['links_md5'] = 'Error'
response['error'] = 'Generic Exception'
response['exception'] = str(e.__str__)
logger.debug('sendResult :[%s:%s] ' %
(gccommand[GC_Utility.GC_MODULEID],
gccommand[GC_Utility.GC_TASKREF]))
self.gcclient.sendResult(gccommand, response)
def handleTask(self, gccommand) :
#self.gcclient.log(GC_Utility.DEBUG, "handleTask - [%s:%s] " % (gccommand[GC_Utility.GC_MODULEID], gccommand[GC_Utility.GC_TASKREF]) )
logger.debug('handleTask - [%s:%s]' % (gccommand[GC_Utility.GC_MODULEID], gccommand[GC_Utility.GC_TASKREF]))
startTime = GC_Utility.currentZuluDT()
taskingObj = gccommand[GC_Utility.GC_CMD_DATA]
response = {}
response['startTime'] = startTime
#self.gcclient.log(GC_Utility.DEBUG, 'execute: [%s for %s sec]' % (taskingObj['cmdline'], taskingObj['timer']))
logger.debug('execute: [%s for %s sec]' % (taskingObj['cmdline'], taskingObj['timer']))
stdout = ""
waitTime = float(taskingObj['timer'])
cmd = taskingObj['cmdline']
try:
p = subprocess.Popen(shlex.split(cmd), close_fds=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
time.sleep(waitTime)
if (p.poll() is None):
#self.gcclient.log(GC_Utility.WARN, 'Command [%s] did not terminate after %s. Killing...' % (cmd, waitTime))
logger.warn('Command [%s] did not terminate after %s. Killing...' % (cmd, waitTime), exc_info=True)
p.kill()
response['stdout'] = p.stdout.read()
response['stderr'] = p.stderr.read()
except Exception as e:
#self.gcclient.log(GC_Utility.WARN, 'Caught an exception while executing %s [%s]' % (cmd, e))
logger.warn('Caught an exception while executing %s [%s]' % (cmd, e), exc_info=True)
#self.gcclient.log(GC_Utility.DEBUG, 'execute : Sending result...');
logger.debug('execute : Sending result...')
self.gcclient.sendResult(gccommand, response);
def inboxPoll(self):
self.count = 0
while self.Running:
#self.gcclient.log(GC_Utility.DEBUG, 'emailClient : Polling imap server');
logger.debug('emailClient : Polling imap server')
self.mail.select()
result, data = self.mail.search(None, '(UNSEEN)')
ids = data[0] # data is a list.
id_list = ids.split() # ids is a space separated string
for num in id_list:
result, data = self.mail.fetch(num, "(RFC822)") # fetch the email body (RFC822) for the given ID
typ, data2 = self.mail.store(num,'+FLAGS','\\Seen')
mail = email.message_from_string(data[0][1]) # here's the body, which is raw text of the whole email
#self.gcclient.log(GC_Utility.INFO, "Received email subject %s" % mail['subject'])
logger.info('Received email subject %s' % mail['subject'])
response = {}
response['cmd'] = 'receivedEmail'
#response['msg'] = data[0][1]
response['subject'] = mail['subject']
# f = open('mail.txt', 'w')
# f.write(data[0][1])
# f.close()
if mail.get_content_maintype() == 'multipart':
#self.gcclient.log(GC_Utility.DEBUG, "Processing multipart email")
logger.debug('Processing multipart email')
for part in mail.walk():
# multipart are just containers, so we skip them
if part.get_content_maintype() == 'multipart':
#self.gcclient.log(GC_Utility.DEBUG, "Nested Multipart")
logger.debug('Nested Multipart')
continue
# is this part an attachment ?
elif part.get('Content-Disposition') is None:
#print part
logger.debug('Part: '+part)
#self.gcclient.log(GC_Utility.DEBUG, "Not a Content-Disposition")
logger.debug('Not a Content-Disposition')
continue
# self.gcclient.log(GC_Utility.DEBUG, "Content-Disposition: %s" % part.get('Content-Disposition'))
filename = part.get_filename()
counter = 1
#self.gcclient.log(GC_Utility.DEBUG, "Processing email attachment %s" % filename)
logger.debug('Processing email attachment %s' % filename)
# if there is no filename, we create one with a counter to avoid duplicates
if not filename:
filename = 'part-%03d%s' % (counter, 'bin')
counter += 1
att_path = os.path.join(GC_EMAIL_ATTACHMENT_DIR, filename)
#Check if its already there
if not os.path.isdir(GC_EMAIL_ATTACHMENT_DIR):
#self.gcclient.log(GC_Utility.DEBUG, 'creating ' + GC_EMAIL_ATTACHMENT_DIR)
logger.debug('creating ' + GC_EMAIL_ATTACHMENT_DIR)
os.mkdir(GC_EMAIL_ATTACHMENT_DIR)
elif os.path.isfile(att_path) :
GC_Utility.handleBackup(att_path, self.gcclient)
# finally write the stuff
fp = open(att_path, 'wb')
fp.write(part.get_payload(decode=True))
fp.close()
self.gcclient.sendOneOffResult(self.MODULE_ID, response)
time.sleep(GC_EMAIL_POLL_INTERVAL)