New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 765805 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Sep 2017
Cc:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 0
Type: Bug



Sign in to add a comment

nyan_kitty-paladin failed at the HWTest stage due to the graphics_sanity test failure

Project Member Reported by shuqianz@chromium.org, Sep 15 2017

Issue description

https://uberchromegw.corp.google.com/i/chromeos/builders/nyan_kitty-paladin/builds/2962

From the debug log:
There are no orphaned crashes; deleting /usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/crashinfo.chromeos4-row13-rack9-host7
09/15 12:35:27.444 INFO | site_crashcollect:0100| Trying to generate stack trace locally for /usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123513.32426.dmp
09/15 12:35:27.444 INFO | site_crashcollect:0034| symbol_dir: /usr/local/autotest/server/../../../lib/debug
09/15 12:35:27.444 DEBUG|             utils:0212| Running 'minidump_stackwalk "/usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123513.32426.dmp" "/usr/local/autotest/server/../../../lib/debug" > "/usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123513.32426.dmp.txt"'
09/15 12:35:27.531 INFO | site_crashcollect:0107| Failed to generate stack trace locally for dump /usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123513.32426.dmp (rc=127):
CmdError('minidump_stackwalk "/usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123513.32426.dmp" "/usr/local/autotest/server/../../../lib/debug" > "/usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123513.32426.dmp.txt"', * Command: 
    minidump_stackwalk "/usr/local/autotest/results/142286386-chromeos-test/c
    hromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/c
    rash/python2_7.20170915.123513.32426.dmp"
    "/usr/local/autotest/server/../../../lib/debug" >
    "/usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9
    -host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170
    915.123513.32426.dmp.txt"
Exit status: 127
Duration: 0.00264501571655

stderr:
/bin/bash: minidump_stackwalk: command not found, 'Command returned non-zero exit status')
09/15 12:35:27.533 INFO | site_crashcollect:0111| Generating stack trace using devserver for /usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123513.32426.dmp
09/15 12:35:27.533 DEBUG|        dev_server:2559| Get the least loaded <class 'autotest_lib.client.common_lib.cros.dev_server.CrashServer'>
09/15 12:35:27.534 DEBUG|        dev_server:0678| Pick one healthy devserver from ['http://100.108.1.139:8082', 'http://100.108.1.152:8082', 'http://100.108.1.59:8082', 'http://100.109.175.143:8082', 'http://100.109.175.145:8082', 'http://172.24.190.211:8082', 'http://172.25.61.81:8082', 'http://172.25.65.207:8082', 'http://172.25.66.216:8082']
09/15 12:35:27.534 DEBUG|        dev_server:0682| Check health for http://100.108.1.139:8082
09/15 12:35:27.819 DEBUG|        dev_server:0687| Pick http://100.108.1.139:8082
09/15 12:35:28.058 WARNI|             retry:0228| <class 'urllib2.URLError'>(<urlopen error [Errno 111] Connection refused>)
09/15 12:35:28.060 WARNI|             retry:0183| Retrying in 4.336198 seconds...
09/15 12:35:29.997 DEBUG|        dev_server:0300| RPC call get_load has timed out on devserver 172.25.61.81.
09/15 12:35:29.999 ERROR|        dev_server:0434| Devserver call failed: "http://172.25.61.81:8082/check_health?", timeout: 2.0 seconds, Error: retry exception (label="get_load"), timeout = 2s
09/15 12:35:32.447 WARNI|             retry:0228| <class 'urllib2.URLError'>(<urlopen error [Errno 111] Connection refused>)
09/15 12:35:32.448 ERROR|        dev_server:0434| Devserver call failed: "http://172.25.65.207:8082/check_health?", timeout: 2.0 seconds, Error: <class 'urllib2.URLError'>: <urlopen error [Errno 111] Connection refused>
09/15 12:35:32.464 DEBUG|        dev_server:2497| CPU load of devserver http://100.109.175.143:8082 is at 100.0%, which is higher than the threshold of 80.0%
09/15 12:35:32.465 DEBUG|        dev_server:2497| CPU load of devserver http://100.109.175.145:8082 is at 100.0%, which is higher than the threshold of 80.0%
09/15 12:35:32.466 DEBUG|        dev_server:2497| CPU load of devserver http://100.108.1.59:8082 is at 93.1%, which is higher than the threshold of 80.0%
09/15 12:35:32.482 INFO |    connectionpool:0207| Starting new HTTP connection (1): 172.24.190.211
09/15 12:36:10.669 DEBUG|    connectionpool:0387| "POST /symbolicate_dump?archive_url=gs://chromeos-image-archive/nyan_kitty-paladin/R63-9945.0.0-rc1 HTTP/1.1" 500 1627
09/15 12:36:10.676 INFO | site_crashcollect:0128| Failed to generate stack trace on devserver for dump /usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123513.32426.dmp:
DevServerException('\n\n\n    \n    500 Internal Server Error\n    \n    #powered_by {\n        margin-top: 20px;\n        border-top: 2px solid black;\n        font-style: italic;\n    }\n\n    #traceback {\n        color: red;\n    }\n    \n\n    \n        500 Internal Server Error\n        The server encountered an unexpected condition which prevented it from fulfilling the request.\n        Traceback (most recent call last):\n  File "/usr/lib/python2.7/dist-packages/cherrypy/_cprequest.py", line 656, in respond\n    response.body = self.handler()\n  File "/usr/lib/python2.7/dist-packages/cherrypy/lib/encoding.py", line 188, in __call__\n    self.body = self.oldhandler(*args, **kwargs)\n  File "/usr/lib/python2.7/dist-packages/cherrypy/_cpdispatch.py", line 34, in __call__\n    return self.callable(*self.args, **self.kwargs)\n  File "/usr/local/google/home/chromeos-test/chromiumos/src/platform/dev/devserver.py", line 1112, in symbolicate_dump\n    file_name = kwargs[\'file_name\']\n  File "/usr/lib/python2.7/subprocess.py", line 710, in __init__\n    errread, errwrite)\n  File "/usr/lib/python2.7/subprocess.py", line 1327, in _execute_child\n    raise child_exception\nOSError: [Errno 2] No such file or directory\n\n    \n    Powered by CherryPy 3.2.2\n    \n    \n\n',)
09/15 12:36:10.677 WARNI| site_crashcollect:0132| Failed to generate stack trace for /usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123513.32426.dmp (see info logs)
09/15 12:36:10.677 INFO | site_crashcollect:0100| Trying to generate stack trace locally for /usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123515.32434.dmp
09/15 12:36:10.678 INFO | site_crashcollect:0034| symbol_dir: /usr/local/autotest/server/../../../lib/debug
09/15 12:36:10.678 DEBUG|             utils:0212| Running 'minidump_stackwalk "/usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123515.32434.dmp" "/usr/local/autotest/server/../../../lib/debug" > "/usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123515.32434.dmp.txt"'
09/15 12:36:10.791 INFO | site_crashcollect:0107| Failed to generate stack trace locally for dump /usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123515.32434.dmp (rc=127):
CmdError('minidump_stackwalk "/usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123515.32434.dmp" "/usr/local/autotest/server/../../../lib/debug" > "/usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170915.123515.32434.dmp.txt"', * Command: 
    minidump_stackwalk "/usr/local/autotest/results/142286386-chromeos-test/c
    hromeos4-row13-rack9-host7/graphics_Sanity/sysinfo/iteration.1/var/spool/c
    rash/python2_7.20170915.123515.32434.dmp"
    "/usr/local/autotest/server/../../../lib/debug" >
    "/usr/local/autotest/results/142286386-chromeos-test/chromeos4-row13-rack9
    -host7/graphics_Sanity/sysinfo/iteration.1/var/spool/crash/python2_7.20170
    915.123515.32434.dmp.txt"
Exit status: 127
Duration: 0.00716590881348

From the test debug log:
 [stderr] /source/core-private/drivers/nvrm/gpu/nvrm_gpu_nvgpu_linux.cpp(484) NvRmGpuNvGpu_IoctlGetCharacteristics: Using GPU capability defaults for ChromeOS kernel.
09/15 12:35:11.507 ERROR|             utils:0280| [stderr] NvRmPrivGetChipPlatform: Could not read platform information 
09/15 12:35:11.515 ERROR|             utils:0280| [stderr] Expected on kernels without fuse support, using silicon
09/15 12:35:14.011 ERROR|             utils:0280| [stderr] Segmentation fault (core dumped)
09/15 12:35:15.211 ERROR|             utils:0280| [stderr] Segmentation fault (core dumped)
09/15 12:35:16.256 DEBUG|             utils:0280| [stdout] # MAX_VIEWPORT_DIMS=(16384, 16384)
09/15 12:35:17.405 DEBUG|             utils:0212| Running 'convert -channel RGB -colorspace RGB -depth 8 -resize '100x100!' /usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated.png /usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated_resized.png'
09/15 12:35:17.418 ERROR|             utils:0280| [stderr] convert: UnableToOpenBlob `/usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated.png': No such file or directory @ error/blob.c/OpenBlob/2701.
09/15 12:35:17.425 ERROR|             utils:0280| [stderr] convert: UnableToOpenFile `/usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated.png' @ error/png.c/ReadPNGImage/3922.
09/15 12:35:17.432 ERROR|             utils:0280| [stderr] convert: NoImagesDefined `/usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated_resized.png' @ error/convert.c/ConvertImageCommand/3258.
09/15 12:35:17.442 DEBUG|              test:0389| Test failed due to Command <convert -channel RGB -colorspace RGB -depth 8 -resize '100x100!' /usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated.png /usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated_resized.png> failed, rc=1, Command returned non-zero exit status
* Command: 
    convert -channel RGB -colorspace RGB -depth 8 -resize '100x100!' /usr/loc
    al/autotest/results/default/graphics_Sanity/results/screenshot1_generated.
    png /usr/local/autotest/results/default/graphics_Sanity/results/screenshot
    1_generated_resized.png
Exit status: 1
Duration: 0.0125830173492

stderr:
convert: UnableToOpenBlob `/usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated.png': No such file or directory @ error/blob.c/OpenBlob/2701.
convert: UnableToOpenFile `/usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated.png' @ error/png.c/ReadPNGImage/3922.
convert: NoImagesDefined `/usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated_resized.png' @ error/convert.c/ConvertImageCommand/3258.. Exception log follows the after_iteration_hooks.
09/15 12:35:17.443 DEBUG|              test:0392| starting after_iteration_hooks
09/15 12:35:17.444 DEBUG|             utils:0212| Running 'mkdir -p /usr/local/autotest/results/default/graphics_Sanity/sysinfo/iteration.1/var/spool'
09/15 12:35:17.460 DEBUG|             utils:0212| Running 'rsync --no-perms --chmod=ugo+r -a --safe-links --exclude=/crash/**autoserv* --exclude=/crash/*.core /var/spool/crash /usr/local/autotest/results/default/graphics_Sanity/sysinfo/iteration.1/var/spool'
09/15 12:35:17.480 DEBUG|             utils:0212| Running 'rm -rf /var/spool/crash/*'
09/15 12:35:17.521 DEBUG|             utils:0212| Running 'logger "autotest finished iteration /usr/local/autotest/results/default/graphics_Sanity/sysinfo/iteration.1"'
09/15 12:35:17.540 DEBUG|              test:0395| after_iteration_hooks completed
09/15 12:35:17.540 WARNI|              test:0612| The test failed with the following exception
Traceback (most recent call last):
  File "/usr/local/autotest/common_lib/test.py", line 606, in _exec
    _call_test_function(self.execute, *p_args, **p_dargs)
  File "/usr/local/autotest/common_lib/test.py", line 806, in _call_test_function
    return func(*args, **dargs)
  File "/usr/local/autotest/common_lib/test.py", line 470, in execute
    dargs)
  File "/usr/local/autotest/common_lib/test.py", line 347, in _call_run_once_with_retry
    postprocess_profiled_run, args, dargs)
  File "/usr/local/autotest/common_lib/test.py", line 380, in _call_run_once
    self.run_once(*args, **dargs)
  File "/usr/local/autotest/tests/graphics_Sanity/graphics_Sanity.py", line 95, in run_once
    utils.system(convert_cmd % (screenshot1_generated, screenshot1_resized))
  File "/usr/local/autotest/common_lib/utils.py", line 1009, in system
    stdout_tee=TEE_TO_LOGS, stderr_tee=TEE_TO_LOGS).exit_status
  File "/usr/local/autotest/common_lib/utils.py", line 738, in run
    "Command returned non-zero exit status")
CmdError: Command <convert -channel RGB -colorspace RGB -depth 8 -resize '100x100!' /usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated.png /usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated_resized.png> failed, rc=1, Command returned non-zero exit status
* Command: 
    convert -channel RGB -colorspace RGB -depth 8 -resize '100x100!' /usr/loc
    al/autotest/results/default/graphics_Sanity/results/screenshot1_generated.
    png /usr/local/autotest/results/default/graphics_Sanity/results/screenshot
    1_generated_resized.png
Exit status: 1
Duration: 0.0125830173492

stderr:
convert: UnableToOpenBlob `/usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated.png': No such file or directory @ error/blob.c/OpenBlob/2701.
convert: UnableToOpenFile `/usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated.png' @ error/png.c/ReadPNGImage/3922.
convert: NoImagesDefined `/usr/local/autotest/results/default/graphics_Sanity/results/screenshot1_generated_resized.png' @ error/convert.c/ConvertImageCommand/3258.
09/15 12:35:17.550 DEBUG|              test:0617| Running cleanup for test.

As for the debug log, the 500 Internal Server Error seems to indicate an issue with the devserver itself.

As for the test debug log, it seems like a test flake. 

pwang@, can you take a look?
 

Comment 2 by pwang@chromium.org, Sep 15 2017

Cc: gurcheta...@chromium.org
It seems screenshot is failing to capture images by the gbm library.
I looked the CL changed during 9944.0.0 and 9945.0.0,
gurchetansingh@, is it possible that the minigbm change breaks the screenshot?
I will mark that CL as -1 for now until the owner confirms that this is not the cause.
#2, crrev.com/c/662919 could cause problems on Tegra.

Comment 5 by pwang@chromium.org, Sep 18 2017

Status: Fixed (was: Untriaged)
Builder is passing now.
https://uberchromegw.corp.google.com/i/chromeos/builders/nyan_kitty-paladin/builds/2989

Sign in to add a comment