apache error logs contain lines (spam) about DUT state transitions |
||||||
Issue descriptionExample pulled from chromeos-server28. We should silence this logging from the rpc layer (bizarre the rpc handler should call into anything that produces it at all...) INFO:root:chromeos4-row11-rack5-host22 -> Running [Thu May 18 17:23:52.356011 2017] [:error] [pid 15384] INFO:root:chromeos2-row11-rack5-host4 -> Resetting [Thu May 18 17:23:57.294654 2017] [:error] [pid 15363] INFO:root:chromeos4-row4-rack6-host10 -> Provisioning [Thu May 18 17:24:00.085660 2017] [:error] [pid 15394] INFO:root:chromeos4-row3-rack4-host15 -> Repairing [Thu May 18 17:24:03.108236 2017] [:error] [pid 15434] INFO:root:chromeos4-row13-rack9-host3 -> Repairing [Thu May 18 17:24:03.163651 2017] [:error] [pid 15434] INFO:root:chromeos2-row11-rack7-host5 -> Resetting [Thu May 18 17:24:03.233320 2017] [:error] [pid 15434] INFO:root:chromeos6-row1-rack3-host21 -> Repairing [Thu May 18 17:24:03.266717 2017] [:error] [pid 15434] INFO:root:chromeos6-row1-rack3-host11 -> Repairing [Thu May 18 17:24:03.295180 2017] [:error] [pid 15434] INFO:root:chromeos6-row1-rack4-host11 -> Repairing [Thu May 18 17:24:03.306580 2017] [:error] [pid 15434] INFO:root:chromeos6-row1-rack4-host13 -> Repairing [Thu May 18 17:24:03.321550 2017] [:error] [pid 15434] INFO:root:chromeos6-row1-rack4-host17 -> Repairing [Thu May 18 17:24:03.341642 2017] [:error] [pid 15434] INFO:root:chromeos6-row2-rack10-host11 -> Repairing [Thu May 18 17:24:03.392301 2017] [:error] [pid 15434] INFO:root:chromeos6-row2-rack10-host17 -> Repairing [Thu May 18 17:24:03.421161 2017] [:error] [pid 15434] INFO:root:chromeos6-row2-rack11-host2 -> Repairing [Thu May 18 17:24:09.275671 2017] [:error] [pid 15360] INFO:root:chromeos4-row9-rack9-host1 -> Resetting [Thu May 18 17:24:09.284194 2017] [:error] [pid 15360] INFO:root:chromeos4-row9-rack9-host2 -> Repairing [Thu May 18 17:24:09.335850 2017] [:error] [pid 15360] INFO:root:chromeos4-row9-rack10-host11 -> Running [Thu May 18 17:24:09.400294 2017] [:error] [pid 15360] INFO:root:chromeos2-row6-rack5-host3 -> Resetting [Thu May 18 17:24:09.430965 2017] [:error] [pid 15360] INFO:root:chromeos4-row9-rack9-host22 -> Ready [Thu May 18 17:24:09.460648 2017] [:error] [pid 15360] INFO:root:chromeos4-row9-rack10-host16 -> Running [Thu May 18 17:24:09.483254 2017] [:error] [pid 15360] INFO:root:chromeos4-row9-rack11-host14 -> Resetting [Thu May 18 17:24:09.540044 2017] [:error] [pid 15360] INFO:root:chromeos2-row8-rack9-host3 -> Running [Thu May 18 17:24:09.555498 2017] [:error] [pid 15360] INFO:root:chromeos2-row8-rack9-host2 -> Running [Thu May 18 17:24:09.646009 2017] [:error] [pid 15360] INFO:root:chromeos9-row1-cart2-host2 -> Running [Thu May 18 17:24:09.658919 2017] [:error] [pid 15360] INFO:root:chromeos7-row1-rack3-host3 -> Repairing [Thu May 18 17:24:09.694935 2017] [:error] [pid 15360] INFO:root:chromeos2-row8-rack1-host6 -> Repairing [Thu May 18 17:24:11.123529 2017] [:error] [pid 15440] INFO:root:chromeos4-row2-rack11-host2 -> Verifying [Thu May 18 17:24:11.144744 2017] [:error] [pid 15440] INFO:root:chromeos4-row2-rack11-host4 -> Verifying [Thu May 18 17:24:11.159369 2017] [:error] [pid 15440] INFO:root:chromeos4-row13-rack10-host3 -> Verifying [Thu May 18 17:24:11.204092 2017] [:error] [pid 15426] INFO:root:chromeos4-row10-rack9-host1 -> Running [Thu May 18 17:24:11.222350 2017] [:error] [pid 15426] INFO:root:chromeos4-row10-rack10-host3 -> Running [Thu May 18 17:24:11.233562 2017] [:error] [pid 15426] INFO:root:chromeos4-row10-rack10-host5 -> Resetting [Thu May 18 17:24:11.255885 2017] [:error] [pid 15440] INFO:root:chromeos4-row13-rack12-host11 -> Verifying [Thu May 18 17:24:11.293637 2017] [:error] [pid 15440] INFO:root:chromeos4-row2-rack11-host11 -> Verifying [Thu May 18 17:24:11.309294 2017] [:error] [pid 15440] INFO:root:chromeos4-row2-rack11-host13 -> Verifying [Thu May 18 17:24:11.332749 2017] [:error] [pid 15440] INFO:root:chromeos4-row2-rack11-host18 -> Verifying [Thu May 18 17:24:11.364200 2017] [:error] [pid 15440] INFO:root:chromeos9-row1-cart4-host3 -> Resetting [Thu May 18 17:24:11.720513 2017] [:error] [pid 15359] INFO:root:chromeos4-row10-rack6-host1 -> Running [Thu May 18 17:24:11.788446 2017] [:error] [pid 15359] INFO:root:chromeos4-row10-rack5-host7 -> Repairing [Thu May 18 17:24:11.877898 2017] [:error] [pid 15359] INFO:root:chromeos4-row10-rack8-host13 -> Verifying [Thu May 18 17:24:12.029502 2017] [:error] [pid 15359] INFO:root:chromeos4-row12-rack2-host13 -> Verifying [Thu May 18 17:24:12.050401 2017] [:error] [pid 15359] INFO:root:chromeos4-row12-rack3-host9 -> Repairing [Thu May 18 17:24:12.075301 2017] [:error] [pid 15359] INFO:root:chromeos4-row12-rack3-host11 -> Verifying [Thu May 18 17:24:12.092480 2017] [:error] [pid 15359] INFO:root:chromeos4-row12-rack2-host12 -> Verifying [Thu May 18 17:24:12.105741 2017] [:error] [pid 15359] INFO:root:chromeos4-row12-rack2-host10 -> Verifying [Thu May 18 17:24:12.136547 2017] [:error] [pid 15359] INFO:root:chromeos9-audiobox4-host1 -> Resetting [Thu May 18 17:24:12.144931 2017] [:error] [pid 15359] INFO:root:chromeos6-row2-rack13-host7 -> Verifying [Thu May 18 17:24:12.153385 2017] [:error] [pid 15359] INFO:root:chromeos6-row2-rack13-host1 -> Verifying [Thu May 18 17:24:12.180086 2017] [:error] [pid 15359] INFO:root:chromeos6-row2-rack13-host3 -> Verifying [Thu May 18 17:24:12.309143 2017] [:error] [pid 15390] INFO:root:chromeos3-row1-rack2-host8 -> Repair Failed [Thu May 18 17:24:14.180975 2017] [:error] [pid 15382] INFO:root:chromeos4-row6-rack6-host11 -> Repairing
,
May 19 2017
we don't need that logging, but why it ends up in error log?
,
May 19 2017
Not sure, either we are shelling out to something from an rpc handler, and piping its stdout to error log (dumb) or just all info-level logging is somehow ending up in error.log (also dumb)
,
May 19 2017
I don't see any import path from rpc_interface to scheduler_models. And rpc_interface_unittest works even if I add an assert False to scheduler models. Makes me suspect that we're shelling out to something inside an rpc handler.
,
May 19 2017
I recall seeing similarly formatted logs in the dev_server code.
,
May 23 2017
Is this being actively investigated?
,
May 23 2017
I am looking into it.
,
May 24 2017
,
May 30 2017
,
Aug 15 2017
Dropping priority to p3
,
Sep 14 2017
|
||||||
►
Sign in to add a comment |
||||||
Comment 1 by akes...@chromium.org
, May 19 2017I think this is coming from scheduler_models.py:399 class Host(DBObject): _table_name = 'afe_hosts' # TODO(ayatane): synch_id is not used, remove after fixing DB. _fields = ('id', 'hostname', 'locked', 'synch_id', 'status', 'invalid', 'protection', 'locked_by_id', 'lock_time', 'dirty', 'leased', 'shard_id', 'lock_reason') def set_status(self,status): logging.info('%s -> %s', self.hostname, status) self.update_field('status',status) def platform_and_labels(self): """ Returns a tuple (platform_name, list_of_all_label_names). """ rows = _db.execute(""" SELECT afe_labels.name, afe_labels.platform FROM afe_labels INNER JOIN afe_hosts_labels ON afe_labels.id = afe_hosts_labels.label_id WHERE afe_hosts_labels.host_id = %s ORDER BY afe_labels.name """, (self.id,)) platform = None all_labels = [] for label_name, is_platform in rows: if is_platform: platform = label_name all_labels.append(label_name) return platform, all_labels _ALPHANUM_HOST_RE = re.compile(r'^([a-z-]+)(\d+)$', re.IGNORECASE)