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