def process_analyzer_job(system_user_auth, qobj, layer_cache_enable):
global servicename #current_avg, current_avg_count
timer = int(time.time())
analysis_events = []
userId = None
imageDigest = None
localconfig = anchore_engine.configuration.localconfig.get_config()
myconfig = localconfig['services']['analyzer']
try:
logger.debug('dequeued object: {}'.format(qobj))
record = qobj['data']
userId = record['userId']
imageDigest = record['imageDigest']
manifest = record['manifest']
parent_manifest = record.get('parent_manifest', None)
# check to make sure image is still in DB
catalog_client = internal_client_for(CatalogClient, userId)
try:
image_record = catalog_client.get_image(imageDigest)
if not image_record:
raise Exception("empty image record from catalog")
except Exception as err:
logger.warn(
"dequeued image cannot be fetched from catalog - skipping analysis ("
+ str(imageDigest) + ") - exception: " + str(err))
return (True)
logger.info("image dequeued for analysis: " + str(userId) + " : " +
str(imageDigest))
if image_record[
'analysis_status'] != anchore_engine.subsys.taskstate.base_state(
'analyze'):
logger.debug(
"dequeued image is not in base state - skipping analysis")
return (True)
try:
logger.spew("TIMING MARK0: " + str(int(time.time()) - timer))
last_analysis_status = image_record['analysis_status']
image_record[
'analysis_status'] = anchore_engine.subsys.taskstate.working_state(
'analyze')
rc = catalog_client.update_image(imageDigest, image_record)
# actually do analysis
registry_creds = catalog_client.get_registry()
try:
image_data = perform_analyze(
userId,
manifest,
image_record,
registry_creds,
layer_cache_enable=layer_cache_enable,
parent_manifest=parent_manifest)
except AnchoreException as e:
event = events.ImageAnalysisFailed(user_id=userId,
image_digest=imageDigest,
error=e.to_dict())
analysis_events.append(event)
raise
imageId = None
try:
imageId = image_data[0]['image']['imageId']
except Exception as err:
logger.warn(
"could not get imageId after analysis or from image record - exception: "
+ str(err))
logger.info(
"adding image analysis data to catalog: userid={} imageId={} imageDigest={}"
.format(userId, imageId, imageDigest))
try:
logger.debug("archiving analysis data")
rc = catalog_client.put_document('analysis_data', imageDigest,
image_data)
except Exception as e:
err = CatalogClientError(
msg='Failed to upload analysis data to catalog', cause=e)
event = events.SaveAnalysisFailed(user_id=userId,
image_digest=imageDigest,
error=err.to_dict())
analysis_events.append(event)
raise err
if rc:
try:
logger.debug("extracting image content data locally")
image_content_data = {}
all_content_types = localconfig.get(
'image_content_types', []) + localconfig.get(
'image_metadata_types', [])
for content_type in all_content_types:
try:
image_content_data[
content_type] = anchore_engine.common.helpers.extract_analyzer_content(
image_data,
content_type,
manifest=manifest)
except Exception as err:
logger.warn("ERR: {}".format(err))
image_content_data[content_type] = {}
if image_content_data:
logger.debug("adding image content data to archive")
rc = catalog_client.put_document(
'image_content_data', imageDigest,
image_content_data)
try:
logger.debug(
"adding image analysis data to image_record")
anchore_engine.common.helpers.update_image_record_with_analysis_data(
image_record, image_data)
except Exception as err:
raise err
except Exception as err:
import traceback
traceback.print_exc()
logger.warn(
"could not store image content metadata to archive - exception: "
+ str(err))
logger.info(
"adding image to policy engine: userid={} imageId={} imageDigest={}"
.format(userId, imageId, imageDigest))
try:
if not imageId:
raise Exception(
"cannot add image to policy engine without an imageId"
)
#localconfig = anchore_engine.configuration.localconfig.get_config()
verify = localconfig['internal_ssl_verify']
pe_client = internal_client_for(PolicyEngineClient, userId)
try:
logger.debug(
"clearing any existing image record in policy engine: {} / {} / {}"
.format(userId, imageId, imageDigest))
rc = pe_client.delete_image(user_id=userId,
image_id=imageId)
except Exception as err:
logger.warn("exception on pre-delete - exception: " +
str(err))
client_success = False
last_exception = None
for retry_wait in [1, 3, 5, 0]:
try:
logger.debug(
'loading image into policy engine: {} / {} / {}'
.format(userId, imageId, imageDigest))
image_analysis_fetch_url = 'catalog://' + str(
userId) + '/analysis_data/' + str(imageDigest)
logger.debug("policy engine request: " +
image_analysis_fetch_url)
resp = pe_client.ingress_image(
userId, imageId, image_analysis_fetch_url)
logger.debug("policy engine image add response: " +
str(resp))
client_success = True
break
except Exception as e:
logger.warn(
"attempt failed, will retry - exception: {}".
format(e))
last_exception = e
time.sleep(retry_wait)
if not client_success:
raise last_exception
except Exception as err:
newerr = PolicyEngineClientError(
msg='Adding image to policy-engine failed',
cause=str(err))
event = events.PolicyEngineLoadAnalysisFailed(
user_id=userId,
image_digest=imageDigest,
error=newerr.to_dict())
analysis_events.append(event)
raise newerr
logger.debug("updating image catalog record analysis_status")
last_analysis_status = image_record['analysis_status']
image_record[
'analysis_status'] = anchore_engine.subsys.taskstate.complete_state(
'analyze')
image_record['analyzed_at'] = int(time.time())
rc = catalog_client.update_image(imageDigest, image_record)
try:
annotations = {}
try:
if image_record.get('annotations', '{}'):
annotations = json.loads(
image_record.get('annotations', '{}'))
except Exception as err:
logger.warn(
"could not marshal annotations from json - exception: "
+ str(err))
for image_detail in image_record['image_detail']:
fulltag = image_detail['registry'] + "/" + image_detail[
'repo'] + ":" + image_detail['tag']
last_payload = {
'imageDigest': imageDigest,
'analysis_status': last_analysis_status,
'annotations': annotations
}
curr_payload = {
'imageDigest': imageDigest,
'analysis_status': image_record['analysis_status'],
'annotations': annotations
}
npayload = {
'last_eval': last_payload,
'curr_eval': curr_payload,
}
if annotations:
npayload['annotations'] = annotations
#original method
#rc = anchore_engine.subsys.notifications.queue_notification(userId, fulltag, 'analysis_update', npayload)
# new method
npayload['subscription_type'] = 'analysis_update'
event = events.UserAnalyzeImageCompleted(
user_id=userId, full_tag=fulltag, data=npayload)
analysis_events.append(event)
except Exception as err:
logger.warn(
"failed to enqueue notification on image analysis state update - exception: "
+ str(err))
else:
err = CatalogClientError(
msg='Failed to upload analysis data to catalog',
cause='Invalid response from catalog API - {}'.format(
str(rc)))
event = events.SaveAnalysisFailed(user_id=userId,
image_digest=imageDigest,
error=err.to_dict())
analysis_events.append(event)
raise err
logger.info("analysis complete: " + str(userId) + " : " +
str(imageDigest))
logger.spew("TIMING MARK1: " + str(int(time.time()) - timer))
try:
run_time = float(time.time() - timer)
anchore_engine.subsys.metrics.histogram_observe(
'anchore_analysis_time_seconds',
run_time,
buckets=[
1.0, 5.0, 10.0, 30.0, 60.0, 120.0, 300.0, 600.0,
1800.0, 3600.0
],
status="success")
except Exception as err:
logger.warn(str(err))
pass
except Exception as err:
run_time = float(time.time() - timer)
logger.exception("problem analyzing image - exception: " +
str(err))
anchore_engine.subsys.metrics.histogram_observe(
'anchore_analysis_time_seconds',
run_time,
buckets=[
1.0, 5.0, 10.0, 30.0, 60.0, 120.0, 300.0, 600.0, 1800.0,
3600.0
],
status="fail")
image_record[
'analysis_status'] = anchore_engine.subsys.taskstate.fault_state(
'analyze')
image_record[
'image_status'] = anchore_engine.subsys.taskstate.fault_state(
'image_status')
rc = catalog_client.update_image(imageDigest, image_record)
if userId and imageDigest:
for image_detail in image_record['image_detail']:
fulltag = image_detail['registry'] + "/" + image_detail[
'repo'] + ":" + image_detail['tag']
event = events.UserAnalyzeImageFailed(user_id=userId,
full_tag=fulltag,
error=str(err))
analysis_events.append(event)
finally:
if analysis_events:
for event in analysis_events:
try:
catalog_client.add_event(event)
except:
logger.error('Ignoring error sending event')
except Exception as err:
logger.warn("job processing bailed - exception: " + str(err))
raise err
return (True)
def import_image(operation_id, account,
import_manifest: InternalImportManifest):
"""
The main thread of exec for importing an image
:param operation_id:
:param account:
:param import_manifest:
:return:
"""
timer = int(time.time())
analysis_events = []
config = localconfig.get_config()
all_content_types = config.get("image_content_types", []) + config.get(
"image_metadata_types", [])
image_digest = import_manifest.digest
try:
catalog_client = internal_client_for(CatalogClient, account)
# check to make sure image is still in DB
catalog_client = internal_client_for(CatalogClient, account)
try:
image_record = catalog_client.get_image(image_digest)
if not image_record:
raise Exception("empty image record from catalog")
except Exception as err:
logger.debug_exception("Could not get image record")
logger.warn(
"dequeued image cannot be fetched from catalog - skipping analysis ("
+ str(image_digest) + ") - exception: " + str(err))
return True
if image_record["analysis_status"] != taskstate.base_state("analyze"):
logger.info(
"dequeued image to import is not in base 'not_analyzed' state - skipping import"
)
return True
try:
last_analysis_status = image_record["analysis_status"]
image_record = update_analysis_started(catalog_client,
image_digest, image_record)
logger.info("Loading content from import")
sbom_map = get_content(import_manifest, catalog_client)
manifest = sbom_map.get("manifest")
try:
logger.info("processing image import data")
image_data, analysis_manifest = process_import(
image_record, sbom_map, import_manifest)
except AnchoreException as e:
event = events.ImageAnalysisFailed(user_id=account,
image_digest=image_digest,
error=e.to_dict())
analysis_events.append(event)
raise
# Store the manifest in the object store
logger.info("storing image manifest")
catalog_client.put_document(bucket="manifest_data",
name=image_digest,
inobj=json.dumps(manifest))
# Save the results to the upstream components and data stores
logger.info("storing import result")
store_analysis_results(
account,
image_digest,
image_record,
image_data,
manifest,
analysis_events,
all_content_types,
)
logger.info("updating image catalog record analysis_status")
last_analysis_status = image_record["analysis_status"]
image_record = update_analysis_complete(catalog_client,
image_digest, image_record)
try:
analysis_events.extend(
notify_analysis_complete(image_record,
last_analysis_status))
except Exception as err:
logger.warn(
"failed to enqueue notification on image analysis state update - exception: "
+ str(err))
logger.info("analysis complete: " + str(account) + " : " +
str(image_digest))
try:
catalog_client.update_image_import_status(operation_id,
status="complete")
except Exception as err:
logger.debug_exception(
"failed updating import status success, will continue and rely on expiration for GC later"
)
try:
metrics.counter_inc(name="anchore_import_success")
run_time = float(time.time() - timer)
metrics.histogram_observe(
"anchore_import_time_seconds",
run_time,
buckets=IMPORT_TIME_SECONDS_BUCKETS,
status="success",
)
except Exception as err:
logger.warn(str(err))
except Exception as err:
run_time = float(time.time() - timer)
logger.exception("problem importing image - exception: " +
str(err))
analysis_failed_metrics(run_time)
# Transition the image record to failure status
image_record = update_analysis_failed(catalog_client, image_digest,
image_record)
try:
catalog_client.update_image_import_status(operation_id,
status="failed")
except Exception as err:
logger.debug_exception(
"failed updating import status failure, will continue and rely on expiration for GC later"
)
if account and image_digest:
for image_detail in image_record["image_detail"]:
fulltag = (image_detail["registry"] + "/" +
image_detail["repo"] + ":" +
image_detail["tag"])
event = events.UserAnalyzeImageFailed(user_id=account,
full_tag=fulltag,
error=str(err))
analysis_events.append(event)
finally:
if analysis_events:
emit_events(catalog_client, analysis_events)
except Exception as err:
logger.debug_exception("Could not import image")
logger.warn("job processing bailed - exception: " + str(err))
raise err
return True
def process_analyzer_job(request: AnalysisQueueMessage, layer_cache_enable):
"""
Core logic of the analysis process
:param request:
:param layer_cache_enable:
:return:
"""
timer = int(time.time())
analysis_events = []
loaded_config = get_config()
all_content_types = loaded_config.get("image_content_types",
[]) + loaded_config.get(
"image_metadata_types", [])
try:
account = request.account
image_digest = request.image_digest
manifest = request.manifest
parent_manifest = request.parent_manifest
# check to make sure image is still in DB
catalog_client = internal_client_for(CatalogClient, account)
try:
image_record = catalog_client.get_image(image_digest)
if not image_record:
raise Exception("empty image record from catalog")
except Exception as err:
logger.warn(
"dequeued image cannot be fetched from catalog - skipping analysis ("
+ str(image_digest) + ") - exception: " + str(err))
return True
logger.info("image dequeued for analysis: " + str(account) + " : " +
str(image_digest))
if image_record[
"analysis_status"] != anchore_engine.subsys.taskstate.base_state(
"analyze"):
logger.debug(
"dequeued image is not in base state - skipping analysis")
return True
try:
logger.spew("TIMING MARK0: " + str(int(time.time()) - timer))
last_analysis_status = image_record["analysis_status"]
image_record = update_analysis_started(catalog_client,
image_digest, image_record)
# actually do analysis
registry_creds = catalog_client.get_registry()
try:
image_data = perform_analyze(
account,
manifest,
image_record,
registry_creds,
layer_cache_enable=layer_cache_enable,
parent_manifest=parent_manifest,
)
except AnchoreException as e:
event = events.ImageAnalysisFailed(user_id=account,
image_digest=image_digest,
error=e.to_dict())
analysis_events.append(event)
raise
# Save the results to the upstream components and data stores
store_analysis_results(
account,
image_digest,
image_record,
image_data,
manifest,
analysis_events,
all_content_types,
)
logger.debug("updating image catalog record analysis_status")
last_analysis_status = image_record["analysis_status"]
image_record = update_analysis_complete(catalog_client,
image_digest, image_record)
try:
notify_analysis_complete(image_record, last_analysis_status)
except Exception as err:
logger.warn(
"failed to enqueue notification on image analysis state update - exception: "
+ str(err))
logger.info("analysis complete: " + str(account) + " : " +
str(image_digest))
logger.spew("TIMING MARK1: " + str(int(time.time()) - timer))
try:
anchore_engine.subsys.metrics.counter_inc(
name="anchore_analysis_success")
run_time = float(time.time() - timer)
anchore_engine.subsys.metrics.histogram_observe(
"anchore_analysis_time_seconds",
run_time,
buckets=ANALYSIS_TIME_SECONDS_BUCKETS,
status="success",
)
except Exception as err:
logger.warn(str(err))
pass
except Exception as err:
run_time = float(time.time() - timer)
logger.exception("problem analyzing image - exception: " +
str(err))
analysis_failed_metrics(run_time)
# Transition the image record to failure status
image_record = update_analysis_failed(catalog_client, image_digest,
image_record)
if account and image_digest:
for image_detail in image_record["image_detail"]:
fulltag = (image_detail["registry"] + "/" +
image_detail["repo"] + ":" +
image_detail["tag"])
event = events.UserAnalyzeImageFailed(user_id=account,
full_tag=fulltag,
error=str(err))
analysis_events.append(event)
finally:
if analysis_events:
emit_events(catalog_client, analysis_events)
except Exception as err:
logger.warn("job processing bailed - exception: " + str(err))
raise err
return True
