Clair: updater can't finish his work

[ghost]

Hi,

I'm a student who is looking to do some "testing" with clair to understand a little more of container's security.
I'm able to boot up a Clair instance through docker-compose based approach mentioned in the main README file and I also successfully setup "analyze-local-images" tool and make it working.

When i start with "docker-compose up" command, i see these logs:

Starting clair_postgres
Starting clair_clair
Attaching to clair_postgres, clair_clair
postgres_1 | LOG: database system was shut down at 2016-11-23 15:55:14 UTC
postgres_1 | LOG: MultiXact member wraparound protections are now enabled
postgres_1 | LOG: database system is ready to accept connections
postgres_1 | LOG: autovacuum launcher started
clair_1 | 2016-11-27 17:26:22.680236 I | pgsql: running database migrations
clair_1 | goose: no migrations to run. current version: 20151222113213
clair_1 | 2016-11-27 17:26:23.365718 I | pgsql: database migration ran successfully
clair_1 | 2016-11-27 17:26:23.383605 I | api: starting main API on port 6060.
clair_1 | 2016-11-27 17:26:23.388903 I | notifier: notifier service is disabled
clair_1 | 2016-11-27 17:26:23.389279 I | api: starting health API on port 6061.
clair_1 | 2016-11-27 17:26:23.406446 I | updater: updater service started. lock identifier: 9c75e437-1172-4104-916d-5f99dc777dde
clair_1 | 2016-11-27 17:26:23.649199 I | updater: updating vulnerabilities
clair_1 | 2016-11-27 17:26:23.649361 I | updater: fetching vulnerability updates
clair_1 | 2016-11-27 17:26:23.649650 I | updater/fetchers/ubuntu: fetching Ubuntu vulnerabilities
clair_1 | 2016-11-27 17:26:23.650361 I | updater/fetchers/debian: fetching Debian vulnerabilities
clair_1 | 2016-11-27 17:26:23.651867 I | updater/fetchers/rhel: fetching Red Hat vulnerabilities

STDOUTS stops here.

All seems working, but if i use the "analyze-local-images" tool on a local image, clair says "image is safe" (i'm testing on images that i know have some vulnerabilities)
So, at this point, i wait because in clair's logs seems the updater has not finished(not mentioned anywhere).
In about 13/15 minutes appears a new log, this one:

clair_1 | 2016-11-27 17:41:10.307595 I | updater: adding metadata to vulnerabilities

If i try again when this appears, the same image i analyzed before is now finding vulnerabilities and all works. The problem is that i never see the "updater: finished" log(also if a wait for hours), so i miss some vulnerabilities and my analysis are incomplete.
I read in OTHER issues that perhaps my connection is too slow, so I tried with the university connection, which is very good, but I did not get results.

I tried to use the local tool with the clair image on quay.io to do some confrontations with "the clair instance" that as i understood, is working and scanning for quay registry.
With this last test i found about 112 vulnerabilities, meanwhile quay finds about 130. So i guess that i'm missing only the NVD vulnerabilities.

PS: I'm using the last versions of clair, docker, and docker-compose.

[HackToday]

I also hit such issue when tried to run with docker

https://github.com/coreos/clair#docker

It seems it is too slow. and always hang that status. Is it possible to fix such slow issue ?

[Quentin-M]

Hi,

When clair_1 | 2016-11-27 17:41:10.307595 I | updater: adding metadata to vulnerabilities appears, Clair finished to fetch vulnerabilities from all registered sources (in your case Ubuntu/Debian/RHEL) and start adding metadata to them using the NVD database. After this task, vulnerabilities are inserted into the database.

On a specific Clair instance, the first run of some vulnerability/metadata fetchers (i.e. Ubuntu, NVD) takes a relatively long time because the data for every years must be checked out. Subsequent loops only fetch the difference (if any). More generally, the first update run takes a while because every available vulnerabilities have to be inserted into the database.

If the updater appears to never end - which we never encountered before, I'd monitor the network. You'd either see one/some fetchers running or Clair communicating with the database.

[ghost]

First of all, thanks for your quick reply. I think i understood log meaning (approximately)
So, i restarted my docker-compose service and i waited the canonical 15 minutes to see the "metadata" log.

clair_1 | 2016-11-30 12:52:29.586957 I | updater/fetchers/rhel: fetching Red Hat vulnerabilities
clair_1 | 2016-11-30 13:07:50.219216 I | updater: adding metadata to vulnerabilities

At this point i took your advice and i tried to check if Clair and the database were in communication.

If the updater appears to never end - which we never encountered before, I'd monitor the network. You'd either see one/some fetchers running or Clair communicating with the database.

I caught with tcpdump this pcap file, where i can see that the 2 container (172.18.0.2=postgres; 172.18.0.3=clair) are in communication. Then i tried to understand what were they saying with WireShark, but i'm not very good with it, so i didn't get nothing more.

I guess it's all working and the problem can be my slow connection. I will try again to start Clair at my university tomorrow, but i tried once without results.

[Quentin-M]

According to the pcap file, it looks like it was still inserting in the database.

[ghost]

Yes, this morning i tried at my university and finally i got the "update finished" logs in about 2 hours. then i tried again and in about 1 hour and half i got the same. I think now all is working as expected, just i was wondering a method to improve the update routing. As i understand the only way is to have a fast connection, right?

PS: Anyway, thank you for your help. I will follow the development of clair with great interest.

[Quentin-M]

When you reached updater: adding metadata to vulnerabilities (which you said you did after 15min), every downloads already finished. The rest of the time was just database work.

Thanks, glad to hear that!

[HackToday]

@Quentin-M I got many errors during that insert into database steps as below:

{epoch:0, version:"", revision:""}}
2016-11-29 08:23:34.321724 E | updater: an error occured when inserting vulnerabilities for update: database: an error occured when querying the backend
2016-11-29 08:23:34.333413 I | updater: updating vulnerabilities
2016-11-29 08:23:34.333473 I | updater: fetching vulnerability updates
2016-11-29 08:23:34.333571 I | updater/fetchers/ubuntu: fetching Ubuntu vulnerabilities
2016-11-29 08:23:34.333688 I | updater/fetchers/debian: fetching Debian vulnerabilities
2016-11-29 08:23:34.333752 I | updater/fetchers/rhel: fetching Red Hat vulnerabilities
2016-11-29 08:38:57.365479 E | updater/fetchers/rhel: could not decode RHEL's XML: unexpected EOF
2016-11-29 08:38:57.365546 E | updater: an error occured when fetching update 'Red Hat': updater/fetchers: could not parse.
2016-11-29 11:07:17.785251 I | updater: adding metadata to vulnerabilities
2016-11-29 12:13:40.800767 W | updater: fetcher note: Ubuntu yakkety is not mapped to any version number (eg. trusty->14.04). Please update me.
2016-11-29 12:13:40.800813 I | updater: update finished
2016-11-29 12:13:40.808747 I | updater: updating vulnerabilities
2016-11-29 12:13:40.808828 I | updater: fetching vulnerability updates
2016-11-29 12:13:40.808920 I | updater/fetchers/ubuntu: fetching Ubuntu vulnerabilities
2016-11-29 12:13:40.809030 I | updater/fetchers/rhel: fetching Red Hat vulnerabilities
2016-11-29 12:13:40.809206 I | updater/fetchers/debian: fetching Debian vulnerabilities
2016-11-29 15:00:21.802168 I | updater: adding metadata to vulnerabilities
2016-11-29 15:43:09.496466 E | pgsql: insertVulnerabilityFixedInFeature: pq: duplicate key value violates unique constraint "vulnerability_fixedin_feature_vulnerability_id_feature_id_key"
database.Vulnerability{Model:database.Model{ID:0}, Name:"RHSA-2009:0382", Namespace:database.Namespace{Model:database.Model{ID:0}, Name:"centos:5"}, Description:"libvirt is a C API for managing and interacting with the virtualization capabilities of Linux and other operating systems. libvirt also provides tools for remotely managing virtualized systems. The libvirtd daemon was discovered to not properly check user connection permissions before performing certain privileged actions, such as requesting migration of an unprivileged guest domain to another system. A local user able to establish a read-only connection to libvirtd could use this flaw to perform actions that should be restricted to read-write connections. (CVE-2008-5086) libvirt_proxy, a setuid helper application allowing non-privileged users to communicate with the hypervisor, was discovered to not properly validate user requests. Local users could use this flaw to cause a stack-based buffer overflow in libvirt_proxy, possibly allowing them to run arbitrary code with root privileges. (CVE-2009-0036) All users are advised to upgrade to these updated packages, which contain backported patches which resolve these issues. After installing the update, libvirtd must be restarted manually (for example, by issuing a \"service libvirtd restart\" command), and guest systems rebooted, for this change to take effect.", Link:"https://rhn.redhat.com/errata/RHSA-2009-0382.html", Severity:"Medium", Metadata:database.MetadataMap(nil), FixedIn:[]database.FeatureVersion{database.FeatureVersion{Model:database.Model{ID:0}, Feature:database.Feature{Model:database.Model{ID:0}, Name:"libvirt-devel", Namespace:database.Namespace{Model:database.Model{ID:0}, Name:"centos:5"}}, Version:types.Version{epoch:0, version:"0.3.3", revision:"14.el5_3.1"}, AffectedBy:[]database.Vulnerability(nil), AddedBy:database.Layer{Model:database.Model{ID:0}, Name:"", EngineVersion:0, Parent:(*database.Layer)(nil), Namespace:(*database.Namespace)(nil), Features:[]database.FeatureVersion(nil)}}, database.FeatureVersion{Model:database.Model{ID:0}, Feature:database.Feature{Model:database.Model{ID:0}, Name:"libvirt", Namespace:database.Namespace{Model:database.Model{ID:0}, Name:"centos:5"}}, Version:types.Version{epoch:0, version:"0.3.3", revision:"14.el5_3.1"}, AffectedBy:[]database.Vulnerability(nil), AddedBy:database.Layer{Model:database.Model{ID:0}, Name:"", EngineVersion:0, Parent:(*database.Layer)(nil), Namespace:(*database.Namespace)(nil), Features:[]database.FeatureVersion(nil)}}, database.FeatureVersion{Model:database.Model{ID:0}, Feature:database.Feature{Model:database.Model{ID:0}, Name:"libvirt-python", Namespace:database.Namespace{Model:database.Model{ID:0}, Name:"centos:5"}}, Version:types.Version{epoch:0, version:"0.3.3", revision:"14.el5_3.1"}, AffectedBy:[]database.Vulnerability(nil), AddedBy:database.Layer{Model:database.Model{ID:0}, Name:"", EngineVersion:0, Parent:(*database.Layer)(nil), Namespace:(*database.Namespace)(nil), Features:[]database.FeatureVersion(nil)}}, database.FeatureVersion{Model:database.Model{ID:0}, Feature:database.Feature{Model:database.Model{ID:0}, Name:"libvirt-devel", Namespace:database.Namespace{Model:database.Model{ID:0}, Name:"centos:5"}}, Version:types.Version{epoch:0, version:"0.3.3", revision:"14.el5_3.1"}, AffectedBy:[]database.Vulnerability(nil), AddedBy:database.Layer{Model:database.Model{ID:0}, Name:"", EngineVersion:0, Parent:(*database.Layer)(nil), Namespace:(*database.Namespace)(nil), Features:[]database.FeatureVersion(nil)}}, database.FeatureVersion{Model:database.Model{ID:0}, Feature:database.Feature{Model:database.Model{ID:0}, Name:"libvirt", Namespace:database.Namespace{Model:database.Model{ID:0}, Name:"centos:5"}}, Version:types.Version{epoch:0, version:"0.3.3", revision:"14.el5_3.1"}, AffectedBy:[]database.Vulnerability(nil), AddedBy:database.Layer{Model:database.Model{ID:0}, Name:"", EngineVersion:0, Parent:(*database.Layer)(nil), Namespace:(*database.Namespace)(nil), Features:[]database.FeatureVersion(nil)}}, database.FeatureVersion{Model:database.Model{ID:0}, Feature:database.Feature{Model:database.Model{ID:0}, Name:"libvirt-python", Namespace:database.Namespace{Model:database.Model{ID:0}, Name:"centos:5"}}, Version:types.Version{epoch:0, version:"0.3.3", revision:"14.el5_3.1"}, AffectedBy:[]database.Vulnerability(nil), AddedBy:database.Layer{Model:database.Model{ID:0}, Name:"", EngineVersion:0, Parent:(*database.Layer)(nil), Namespace:(*database.Namespace)(nil), Features:[]database.FeatureVersion(nil)}}}, LayersIntroducingVulnerability:[]database.Layer(nil), FixedBy:types.Version{epoch:0, version:"", revision:""}}

[Quentin-M]

@HackToday Issue was #238, fixed by #263. Please update to include this patch.

[HackToday]

OK @Quentin-M I will try that new version. It seems this new fix was to ignore duplicated errors in DB, and trust DB unique constraints. Right ?

[Quentin-M]

@HackToday That's pretty much the idea. There's no error anymore, we simply try to create or retrieve the Vulnerability_FixedIn_Feature record, instead of only trying to create it. Then, if it already existed, we skip the Vulnerability_Affects_FeatureVersion linkage.