How to benchmark scanning time with anchore

19 Nov 2018 - Christopher McArthur

Mission:

Successfully get a timestamp for how long it takes to scan an image.

This is a preliminary “theoretical” pass on how I will try this later on…

Good news is, it is possible to subscribe to analysis updates with the subscription… Unfortunately for me this is a RESTful appliation and send webhooks ovet HTTP POST formatted as JSON.

I will most likely have to re-use my webserver to capture these and report something meaningful…

CLI:

anchore-cli subscription activate <SUBSCRIPTION_TYPE> <SUBSCRIPTION_KEY>
SUBSCRIPTION_TYPE: analysis_update
SUBSCRIPTION_KEY: princechrismc/ping-test

Validate config.yml

general:
    url: 'http://localhost:9090/general/<notification_type>/<userId>'

---

Update:

I managed to setup my little web server, It created the directoires but there are no files =( I susspect they are specifying a trailing slash or there’s a bug in my file servlet. I just want know what my webhooks are doing.

My backup solution is to look into the log files.. I’ll havew to go through a huge dump and find a better way….

To get the worker log docker exec -t -i aevolume_anchore-engine_1 cat /var/log/anchore/anchore-worker.log

---

UPDATE:

So I finally got my web server accepting webhooks and backing up the old files…

{
    "created_at": 1542774444,
    "userId": "admin",
    "tries": 0,
    "record_state_val": null,
    "last_updated": 1542774444,
    "dataId": "775a0bd2-5e48-4ac8-9f78-6f0396f10c70",
    "queueId": "analysis_update",
    "max_tries": 1542774474,
    "data": {
        "notification_user": "admin",
        "notification_user_email": "admin@myemail.com",
        "notification_type": "analysis_update",
        "notification_payload": {
            "curr_eval": {
                "analysis_status": "analyzed",
                "annotations": {},
                "imageDigest": "sha256:de7b4aa864bf0b698edc497cb3e4a92a0ac6bae97056ae79e51d617c3f1eb0e2"
            },
            "last_eval": {
                "analysis_status": "analyzing",
                "annotations": {},
                "imageDigest": "sha256:de7b4aa864bf0b698edc497cb3e4a92a0ac6bae97056ae79e51d617c3f1eb0e2"
            },
            "notificationId": "775a0bd2-5e48-4ac8-9f78-6f0396f10c70",
            "subscription_key": "docker.io/princechrismc/go-exploitdb:latest",
            "userId": "admin"
        }
    },
    "record_state_key": "active"
}

The problem… there’s only one notification for the completion and it’s comming about 30-45s after the CLI reports that its complete… looks like im going to be greping the logs

So I got lucky, looking over and reading the log from above, I notices two lines were taged “INFO” and not “DEBUD like the waste majority… After some screwing around I found the configuration to change the logging. Only logging “INFO” produced the following

2018-11-21 04:59:07+0000 [-] [Thread-50] [anchore_engine.services.analyzer/process_analyzer_job()] [INFO] image dequeued for analysis: admin : sha256:de7b4aa864bf0b698edc497cb3e4a92a0ac6bae97056ae79e51d617c3f1eb0e2
2018-11-21 04:59:07+0000 [-] [Thread-50] [anchore_engine.services.analyzer/perform_analyze_nodocker()] [INFO] performing analysis on image: ['admin', 'docker.io/princechrismc/go-exploitdb@sha256:de7b4aa864bf0b698edc497cb3e4a92a0ac6bae97056ae79e51d617c3f1eb0e2', 'docker.io/princechrismc/go-exploitdb:latest']
2018-11-21 04:59:07+0000 [-] [Thread-50] [anchore_engine.clients.localanchore_standalone/get_anchorelock()] [INFO] copying new config into place: /config/analyzer_config.yaml -> /root/.anchore/conf/analyzer_config.yaml
2018-11-21 04:59:20+0000 [-] [Thread-50] [anchore_engine.services.analyzer/perform_analyze_nodocker()] [INFO] performing analysis on image complete: docker.io/princechrismc/go-exploitdb@sha256:de7b4aa864bf0b698edc497cb3e4a92a0ac6bae97056ae79e51d617c3f1eb0e2
2018-11-21 04:59:21+0000 [-] [Thread-50] [anchore_engine.services.analyzer/process_analyzer_job()] [INFO] Loading image into policy engine: admin 58d024bca5f2998bdd94eec33d3663226b4bc4fe6a570e1bf9ef70ea5ca18af8
2018-11-21 04:59:27+0000 [-] [Thread-50] [anchore_engine.services.analyzer/process_analyzer_job()] [INFO] analysis complete: admin : sha256:de7b4aa864bf0b698edc497cb3e4a92a0ac6bae97056ae79e51d617c3f1eb0e2

This is exactly the kind of information I need !

Now I can finally start benchmarking this !