Brad Bishop | c342db3 | 2019-05-15 21:57:59 -0400 | [diff] [blame] | 1 | # |
| 2 | # SPDX-License-Identifier: MIT |
| 3 | # |
| 4 | |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 5 | import os |
| 6 | |
| 7 | from subprocess import check_output |
| 8 | from shutil import rmtree |
| 9 | from oeqa.runtime.case import OERuntimeTestCase |
| 10 | from oeqa.core.decorator.depends import OETestDepends |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 11 | from oeqa.core.decorator.data import skipIfDataVar |
| 12 | from oeqa.runtime.decorator.package import OEHasPackage |
| 13 | |
| 14 | #in the future these lists could be moved outside of module |
| 15 | errors = ["error", "cannot", "can\'t", "failed"] |
| 16 | |
| 17 | common_errors = [ |
| 18 | "(WW) warning, (EE) error, (NI) not implemented, (??) unknown.", |
| 19 | "dma timeout", |
| 20 | "can\'t add hid device:", |
| 21 | "usbhid: probe of ", |
| 22 | "_OSC failed (AE_ERROR)", |
| 23 | "_OSC failed (AE_SUPPORT)", |
| 24 | "AE_ALREADY_EXISTS", |
| 25 | "ACPI _OSC request failed (AE_SUPPORT)", |
| 26 | "can\'t disable ASPM", |
| 27 | "Failed to load module \"vesa\"", |
| 28 | "Failed to load module vesa", |
| 29 | "Failed to load module \"modesetting\"", |
| 30 | "Failed to load module modesetting", |
| 31 | "Failed to load module \"glx\"", |
| 32 | "Failed to load module \"fbdev\"", |
| 33 | "Failed to load module fbdev", |
| 34 | "Failed to load module glx", |
| 35 | "[drm] Cannot find any crtc or sizes - going 1024x768", |
| 36 | "_OSC failed (AE_NOT_FOUND); disabling ASPM", |
| 37 | "Open ACPI failed (/var/run/acpid.socket) (No such file or directory)", |
| 38 | "NX (Execute Disable) protection cannot be enabled: non-PAE kernel!", |
| 39 | "hd.: possibly failed opcode", |
| 40 | 'NETLINK INITIALIZATION FAILED', |
| 41 | 'kernel: Cannot find map file', |
| 42 | 'omap_hwmod: debugss: _wait_target_disable failed', |
| 43 | 'VGA arbiter: cannot open kernel arbiter, no multi-card support', |
| 44 | 'Failed to find URL:http://ipv4.connman.net/online/status.html', |
| 45 | 'Online check failed for', |
| 46 | 'netlink init failed', |
| 47 | 'Fast TSC calibration', |
| 48 | "BAR 0-9", |
| 49 | "Failed to load module \"ati\"", |
| 50 | "controller can't do DEVSLP, turning off", |
| 51 | "stmmac_dvr_probe: warning: cannot get CSR clock", |
| 52 | "error: couldn\'t mount because of unsupported optional features", |
| 53 | "GPT: Use GNU Parted to correct GPT errors", |
| 54 | "Cannot set xattr user.Librepo.DownloadInProgress", |
Brad Bishop | 1a4b7ee | 2018-12-16 17:11:34 -0800 | [diff] [blame] | 55 | "Failed to read /var/lib/nfs/statd/state: Success", |
| 56 | "error retry time-out =", |
| 57 | "logind: cannot setup systemd-logind helper (-61), using legacy fallback", |
| 58 | "Error changing net interface name 'eth0' to " |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 59 | ] |
| 60 | |
| 61 | video_related = [ |
| 62 | "uvesafb", |
| 63 | ] |
| 64 | |
| 65 | x86_common = [ |
| 66 | '[drm:psb_do_init] *ERROR* Debug is', |
| 67 | 'wrong ELF class', |
| 68 | 'Could not enable PowerButton event', |
| 69 | 'probe of LNXPWRBN:00 failed with error -22', |
| 70 | 'pmd_set_huge: Cannot satisfy', |
| 71 | 'failed to setup card detect gpio', |
| 72 | 'amd_nb: Cannot enumerate AMD northbridges', |
| 73 | 'failed to retrieve link info, disabling eDP', |
| 74 | 'Direct firmware load for iwlwifi', |
Brad Bishop | 1932369 | 2019-04-05 15:28:33 -0400 | [diff] [blame] | 75 | 'Direct firmware load for regulatory.db', |
| 76 | 'failed to load regulatory.db', |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 77 | ] + common_errors |
| 78 | |
| 79 | qemux86_common = [ |
| 80 | 'wrong ELF class', |
| 81 | "fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.", |
| 82 | "can't claim BAR ", |
| 83 | 'amd_nb: Cannot enumerate AMD northbridges', |
| 84 | 'uvesafb: 5000 ms task timeout, infinitely waiting', |
| 85 | 'tsc: HPET/PMTIMER calibration failed', |
| 86 | ] + common_errors |
| 87 | |
| 88 | ignore_errors = { |
| 89 | 'default' : common_errors, |
| 90 | 'qemux86' : [ |
| 91 | 'Failed to access perfctr msr (MSR', |
| 92 | 'pci 0000:00:00.0: [Firmware Bug]: reg 0x..: invalid BAR (can\'t size)', |
| 93 | ] + qemux86_common, |
| 94 | 'qemux86-64' : qemux86_common, |
| 95 | 'qemumips' : [ |
| 96 | 'Failed to load module "glx"', |
| 97 | 'pci 0000:00:00.0: [Firmware Bug]: reg 0x..: invalid BAR (can\'t size)', |
Brad Bishop | d7bf8c1 | 2018-02-25 22:55:05 -0500 | [diff] [blame] | 98 | 'cacheinfo: Failed to find cpu0 device node', |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 99 | ] + common_errors, |
| 100 | 'qemumips64' : [ |
| 101 | 'pci 0000:00:00.0: [Firmware Bug]: reg 0x..: invalid BAR (can\'t size)', |
Brad Bishop | d7bf8c1 | 2018-02-25 22:55:05 -0500 | [diff] [blame] | 102 | 'cacheinfo: Failed to find cpu0 device node', |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 103 | ] + common_errors, |
| 104 | 'qemuppc' : [ |
| 105 | 'PCI 0000:00 Cannot reserve Legacy IO [io 0x0000-0x0fff]', |
| 106 | 'host side 80-wire cable detection failed, limiting max speed', |
| 107 | 'mode "640x480" test failed', |
| 108 | 'Failed to load module "glx"', |
| 109 | 'can\'t handle BAR above 4GB', |
| 110 | 'Cannot reserve Legacy IO', |
| 111 | ] + common_errors, |
| 112 | 'qemuarm' : [ |
| 113 | 'mmci-pl18x: probe of fpga:05 failed with error -22', |
| 114 | 'mmci-pl18x: probe of fpga:0b failed with error -22', |
| 115 | 'Failed to load module "glx"', |
| 116 | 'OF: amba_device_add() failed (-19) for /amba/smc@10100000', |
| 117 | 'OF: amba_device_add() failed (-19) for /amba/mpmc@10110000', |
| 118 | 'OF: amba_device_add() failed (-19) for /amba/sctl@101e0000', |
| 119 | 'OF: amba_device_add() failed (-19) for /amba/watchdog@101e1000', |
| 120 | 'OF: amba_device_add() failed (-19) for /amba/sci@101f0000', |
Brad Bishop | 1932369 | 2019-04-05 15:28:33 -0400 | [diff] [blame] | 121 | 'OF: amba_device_add() failed (-19) for /amba/spi@101f4000', |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 122 | 'OF: amba_device_add() failed (-19) for /amba/ssp@101f4000', |
| 123 | 'OF: amba_device_add() failed (-19) for /amba/fpga/sci@a000', |
| 124 | 'Failed to initialize \'/amba/timer@101e3000\': -22', |
| 125 | 'jitterentropy: Initialization failed with host not compliant with requirements: 2', |
| 126 | ] + common_errors, |
| 127 | 'qemuarm64' : [ |
| 128 | 'Fatal server error:', |
| 129 | '(EE) Server terminated with error (1). Closing log file.', |
| 130 | 'dmi: Firmware registration failed.', |
| 131 | 'irq: type mismatch, failed to map hwirq-27 for /intc', |
| 132 | ] + common_errors, |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 133 | 'intel-core2-32' : [ |
| 134 | 'ACPI: No _BQC method, cannot determine initial brightness', |
| 135 | '[Firmware Bug]: ACPI: No _BQC method, cannot determine initial brightness', |
| 136 | '(EE) Failed to load module "psb"', |
| 137 | '(EE) Failed to load module psb', |
| 138 | '(EE) Failed to load module "psbdrv"', |
| 139 | '(EE) Failed to load module psbdrv', |
| 140 | '(EE) open /dev/fb0: No such file or directory', |
| 141 | '(EE) AIGLX: reverting to software rendering', |
| 142 | 'dmi: Firmware registration failed.', |
| 143 | 'ioremap error for 0x78', |
| 144 | ] + x86_common, |
| 145 | 'intel-corei7-64' : [ |
| 146 | 'can\'t set Max Payload Size to 256', |
| 147 | 'intel_punit_ipc: can\'t request region for resource', |
| 148 | '[drm] parse error at position 4 in video mode \'efifb\'', |
| 149 | 'ACPI Error: Could not enable RealTimeClock event', |
| 150 | 'ACPI Warning: Could not enable fixed event - RealTimeClock', |
| 151 | 'hci_intel INT33E1:00: Unable to retrieve gpio', |
| 152 | 'hci_intel: probe of INT33E1:00 failed', |
| 153 | 'can\'t derive routing for PCI INT A', |
| 154 | 'failed to read out thermal zone', |
| 155 | 'Bluetooth: hci0: Setting Intel event mask failed', |
| 156 | 'ttyS2 - failed to request DMA', |
Brad Bishop | d7bf8c1 | 2018-02-25 22:55:05 -0500 | [diff] [blame] | 157 | 'Bluetooth: hci0: Failed to send firmware data (-38)', |
| 158 | 'atkbd serio0: Failed to enable keyboard on isa0060/serio0', |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 159 | ] + x86_common, |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 160 | 'genericx86' : x86_common, |
| 161 | 'genericx86-64' : [ |
| 162 | 'Direct firmware load for i915', |
| 163 | 'Failed to load firmware i915', |
| 164 | 'Failed to fetch GuC', |
| 165 | 'Failed to initialize GuC', |
| 166 | 'Failed to load DMC firmware', |
| 167 | 'The driver is built-in, so to load the firmware you need to', |
| 168 | ] + x86_common, |
| 169 | 'edgerouter' : [ |
Brad Bishop | 1932369 | 2019-04-05 15:28:33 -0400 | [diff] [blame] | 170 | 'not creating \'/sys/firmware/fdt\'', |
| 171 | 'Failed to find cpu0 device node', |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 172 | 'Fatal server error:', |
Brad Bishop | 1932369 | 2019-04-05 15:28:33 -0400 | [diff] [blame] | 173 | 'Server terminated with error', |
| 174 | ] + common_errors, |
| 175 | 'beaglebone-yocto' : [ |
| 176 | 'Direct firmware load for regulatory.db', |
| 177 | 'failed to load regulatory.db', |
| 178 | 'l4_wkup_cm', |
| 179 | 'Failed to load module "glx"', |
| 180 | 'Failed to make EGL context current', |
| 181 | 'glamor initialization failed', |
| 182 | ] + common_errors, |
| 183 | 'mpc8315e-rdb' : [ |
| 184 | 'of_irq_parse_pci: failed with', |
| 185 | 'Fatal server error:', |
| 186 | 'Server terminated with error', |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 187 | ] + common_errors, |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 188 | } |
| 189 | |
| 190 | log_locations = ["/var/log/","/var/log/dmesg", "/tmp/dmesg_output.log"] |
| 191 | |
| 192 | class ParseLogsTest(OERuntimeTestCase): |
| 193 | |
| 194 | @classmethod |
| 195 | def setUpClass(cls): |
| 196 | cls.errors = errors |
| 197 | |
| 198 | # When systemd is enabled we need to notice errors on |
| 199 | # circular dependencies in units. |
| 200 | if 'systemd' in cls.td.get('DISTRO_FEATURES', ''): |
| 201 | cls.errors.extend([ |
| 202 | 'Found ordering cycle on', |
| 203 | 'Breaking ordering cycle by deleting job', |
| 204 | 'deleted to break ordering cycle', |
| 205 | 'Ordering cycle found, skipping', |
| 206 | ]) |
| 207 | |
| 208 | cls.ignore_errors = ignore_errors |
| 209 | cls.log_locations = log_locations |
| 210 | cls.msg = '' |
| 211 | is_lsb, _ = cls.tc.target.run("which LSB_Test.sh") |
| 212 | if is_lsb == 0: |
| 213 | for machine in cls.ignore_errors: |
| 214 | cls.ignore_errors[machine] = cls.ignore_errors[machine] \ |
| 215 | + video_related |
| 216 | |
| 217 | def getMachine(self): |
| 218 | return self.td.get('MACHINE', '') |
| 219 | |
| 220 | def getWorkdir(self): |
| 221 | return self.td.get('WORKDIR', '') |
| 222 | |
| 223 | # Get some information on the CPU of the machine to display at the |
| 224 | # beginning of the output. This info might be useful in some cases. |
| 225 | def getHardwareInfo(self): |
| 226 | hwi = "" |
| 227 | cmd = ('cat /proc/cpuinfo | grep "model name" | head -n1 | ' |
| 228 | " awk 'BEGIN{FS=\":\"}{print $2}'") |
| 229 | _, cpu_name = self.target.run(cmd) |
| 230 | |
| 231 | cmd = ('cat /proc/cpuinfo | grep "cpu cores" | head -n1 | ' |
| 232 | "awk {'print $4'}") |
| 233 | _, cpu_physical_cores = self.target.run(cmd) |
| 234 | |
| 235 | cmd = 'cat /proc/cpuinfo | grep "processor" | wc -l' |
| 236 | _, cpu_logical_cores = self.target.run(cmd) |
| 237 | |
| 238 | _, cpu_arch = self.target.run('uname -m') |
| 239 | |
| 240 | hwi += 'Machine information: \n' |
| 241 | hwi += '*******************************\n' |
| 242 | hwi += 'Machine name: ' + self.getMachine() + '\n' |
| 243 | hwi += 'CPU: ' + str(cpu_name) + '\n' |
| 244 | hwi += 'Arch: ' + str(cpu_arch)+ '\n' |
| 245 | hwi += 'Physical cores: ' + str(cpu_physical_cores) + '\n' |
| 246 | hwi += 'Logical cores: ' + str(cpu_logical_cores) + '\n' |
| 247 | hwi += '*******************************\n' |
| 248 | |
| 249 | return hwi |
| 250 | |
| 251 | # Go through the log locations provided and if it's a folder |
| 252 | # create a list with all the .log files in it, if it's a file |
| 253 | # just add it to that list. |
| 254 | def getLogList(self, log_locations): |
| 255 | logs = [] |
| 256 | for location in log_locations: |
| 257 | status, _ = self.target.run('test -f ' + str(location)) |
| 258 | if status == 0: |
| 259 | logs.append(str(location)) |
| 260 | else: |
| 261 | status, _ = self.target.run('test -d ' + str(location)) |
| 262 | if status == 0: |
| 263 | cmd = 'find ' + str(location) + '/*.log -maxdepth 1 -type f' |
| 264 | status, output = self.target.run(cmd) |
| 265 | if status == 0: |
| 266 | output = output.splitlines() |
| 267 | for logfile in output: |
| 268 | logs.append(os.path.join(location, str(logfile))) |
| 269 | return logs |
| 270 | |
| 271 | # Copy the log files to be parsed locally |
| 272 | def transfer_logs(self, log_list): |
| 273 | workdir = self.getWorkdir() |
| 274 | self.target_logs = workdir + '/' + 'target_logs' |
| 275 | target_logs = self.target_logs |
| 276 | if os.path.exists(target_logs): |
| 277 | rmtree(self.target_logs) |
| 278 | os.makedirs(target_logs) |
| 279 | for f in log_list: |
| 280 | self.target.copyFrom(str(f), target_logs) |
| 281 | |
| 282 | # Get the local list of logs |
| 283 | def get_local_log_list(self, log_locations): |
| 284 | self.transfer_logs(self.getLogList(log_locations)) |
| 285 | list_dir = os.listdir(self.target_logs) |
| 286 | dir_files = [os.path.join(self.target_logs, f) for f in list_dir] |
| 287 | logs = [f for f in dir_files if os.path.isfile(f)] |
| 288 | return logs |
| 289 | |
| 290 | # Build the grep command to be used with filters and exclusions |
| 291 | def build_grepcmd(self, errors, ignore_errors, log): |
| 292 | grepcmd = 'grep ' |
| 293 | grepcmd += '-Ei "' |
| 294 | for error in errors: |
Brad Bishop | 08902b0 | 2019-08-20 09:16:51 -0400 | [diff] [blame] | 295 | grepcmd += '\<' + error + '\>' + '|' |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 296 | grepcmd = grepcmd[:-1] |
| 297 | grepcmd += '" ' + str(log) + " | grep -Eiv \'" |
| 298 | |
| 299 | try: |
| 300 | errorlist = ignore_errors[self.getMachine()] |
| 301 | except KeyError: |
| 302 | self.msg += 'No ignore list found for this machine, using default\n' |
| 303 | errorlist = ignore_errors['default'] |
| 304 | |
| 305 | for ignore_error in errorlist: |
| 306 | ignore_error = ignore_error.replace('(', '\(') |
| 307 | ignore_error = ignore_error.replace(')', '\)') |
| 308 | ignore_error = ignore_error.replace("'", '.') |
| 309 | ignore_error = ignore_error.replace('?', '\?') |
| 310 | ignore_error = ignore_error.replace('[', '\[') |
| 311 | ignore_error = ignore_error.replace(']', '\]') |
| 312 | ignore_error = ignore_error.replace('*', '\*') |
| 313 | ignore_error = ignore_error.replace('0-9', '[0-9]') |
| 314 | grepcmd += ignore_error + '|' |
| 315 | grepcmd = grepcmd[:-1] |
| 316 | grepcmd += "\'" |
| 317 | |
| 318 | return grepcmd |
| 319 | |
| 320 | # Grep only the errors so that their context could be collected. |
| 321 | # Default context is 10 lines before and after the error itself |
| 322 | def parse_logs(self, errors, ignore_errors, logs, |
| 323 | lines_before = 10, lines_after = 10): |
| 324 | results = {} |
| 325 | rez = [] |
| 326 | grep_output = '' |
| 327 | |
| 328 | for log in logs: |
| 329 | result = None |
| 330 | thegrep = self.build_grepcmd(errors, ignore_errors, log) |
| 331 | |
| 332 | try: |
| 333 | result = check_output(thegrep, shell=True).decode('utf-8') |
| 334 | except: |
| 335 | pass |
| 336 | |
| 337 | if result is not None: |
Brad Bishop | 1a4b7ee | 2018-12-16 17:11:34 -0800 | [diff] [blame] | 338 | results[log] = {} |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 339 | rez = result.splitlines() |
| 340 | |
| 341 | for xrez in rez: |
| 342 | try: |
| 343 | cmd = ['grep', '-F', xrez, '-B', str(lines_before)] |
| 344 | cmd += ['-A', str(lines_after), log] |
| 345 | grep_output = check_output(cmd).decode('utf-8') |
| 346 | except: |
| 347 | pass |
Brad Bishop | 1a4b7ee | 2018-12-16 17:11:34 -0800 | [diff] [blame] | 348 | results[log][xrez]=grep_output |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 349 | |
| 350 | return results |
| 351 | |
| 352 | # Get the output of dmesg and write it in a file. |
| 353 | # This file is added to log_locations. |
| 354 | def write_dmesg(self): |
| 355 | (status, dmesg) = self.target.run('dmesg > /tmp/dmesg_output.log') |
| 356 | |
Brad Bishop | 6e60e8b | 2018-02-01 10:27:11 -0500 | [diff] [blame] | 357 | @OETestDepends(['ssh.SSHTest.test_ssh']) |
| 358 | def test_parselogs(self): |
| 359 | self.write_dmesg() |
| 360 | log_list = self.get_local_log_list(self.log_locations) |
| 361 | result = self.parse_logs(self.errors, self.ignore_errors, log_list) |
| 362 | print(self.getHardwareInfo()) |
| 363 | errcount = 0 |
| 364 | for log in result: |
| 365 | self.msg += 'Log: ' + log + '\n' |
| 366 | self.msg += '-----------------------\n' |
| 367 | for error in result[log]: |
| 368 | errcount += 1 |
| 369 | self.msg += 'Central error: ' + str(error) + '\n' |
| 370 | self.msg += '***********************\n' |
| 371 | self.msg += result[str(log)][str(error)] + '\n' |
| 372 | self.msg += '***********************\n' |
| 373 | self.msg += '%s errors found in logs.' % errcount |
| 374 | self.assertEqual(errcount, 0, msg=self.msg) |