Project: chromium Issues People Development process History Sign in
New issue
Advanced search Search tips
Starred by 1 user
Status: Untriaged
Owner: ----
Cc:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment
peppy-paladin failed to run generic_RebootTest
Project Member Reported by shuqianz@chromium.org, Feb 17 2017 Back to list
https://uberchromegw.corp.google.com/i/chromeos/builders/peppy-paladin/builds/14280

Failed test:http://cautotest/tko/retrieve_logs.cgi?job=/results/101657234-chromeos-test/

Error:
02/16 16:57:22.667 DEBUG|          ssh_host:0284| Running (ssh) 'nohup /tmp/sysinfo/autoserv-jROxfV/bin/autotestd /tmp/autoserv-S0iB9n -H autoserv --verbose --hostname=chromeos4-row9-rack11-host3 --user=chromeos-test /tmp/sysinfo/autoserv-jROxfV/control.autoserv >/dev/null 2>/dev/null &'
02/16 16:57:22.970 DEBUG|          ssh_host:0284| Running (ssh) '/tmp/sysinfo/autoserv-jROxfV/bin/autotestd_monitor /tmp/autoserv-S0iB9n 0 0'
02/16 16:57:23.317 DEBUG|     site_autotest:0194| AUTOTEST_STATUS::START	----	----	timestamp=1487293042	localtime=Feb 16 16:57:22	
02/16 16:57:23.319 INFO |        server_job:0184| 	START	----	----	timestamp=1487293042	localtime=Feb 16 16:57:22	
02/16 16:57:23.320 DEBUG|     site_autotest:0194| AUTOTEST_STATUS::END ABORT	----	----	timestamp=1487293042	localtime=Feb 16 16:57:22	Unhandled OSError: [Errno 17] File exists: '/tmp/autoserv-zggX7u/results'
02/16 16:57:23.321 INFO |        server_job:0184| 	END ABORT	----	----	timestamp=1487293042	localtime=Feb 16 16:57:22	Unhandled OSError: [Errno 17] File exists: '/tmp/autoserv-zggX7u/results'
02/16 16:57:23.322 DEBUG|     site_autotest:0194| AUTOTEST_STATUS::  Traceback (most recent call last):
02/16 16:57:23.323 DEBUG|     site_autotest:0194| AUTOTEST_STATUS::    File "/tmp/sysinfo/autoserv-jROxfV/bin/job.py", line 1034, in step_engine
02/16 16:57:23.323 DEBUG|     site_autotest:0194| AUTOTEST_STATUS::      execfile(self.control, global_control_vars, global_control_vars)
02/16 16:57:23.324 DEBUG|     site_autotest:0194| AUTOTEST_STATUS::    File "/tmp/sysinfo/autoserv-jROxfV/control.autoserv", line 5, in <module>
02/16 16:57:23.324 DEBUG|     site_autotest:0194| AUTOTEST_STATUS::      mytest = test.test(job, '', '/tmp/autoserv-zggX7u')
02/16 16:57:23.324 DEBUG|     site_autotest:0194| AUTOTEST_STATUS::    File "/tmp/sysinfo/autoserv-jROxfV/common_lib/test.py", line 39, in __init__
02/16 16:57:23.325 DEBUG|     site_autotest:0194| AUTOTEST_STATUS::      os.mkdir(self.resultsdir)
02/16 16:57:23.325 DEBUG|     site_autotest:0194| AUTOTEST_STATUS::  OSError: [Errno 17] File exists: '/tmp/autoserv-zggX7u/results'
02/16 16:57:23.325 DEBUG|     site_autotest:0194| Entered autotestd_monitor.
02/16 16:57:23.326 INFO |          autotest:1139| Entered autotestd_monitor.
02/16 16:57:23.326 DEBUG|     site_autotest:0194| Finished launching tail subprocesses.

I login to the DUT, checked the /var/log/messages, and find:
2017-02-16T16:57:26.488481-08:00 INFO sshd[3432]: Accepted publickey for root from 172.24.26.11 port 57598 ssh2: RSA SHA256:Fp1qWjFLyK1cTpiI5rdk7iEJwoK9lcnYAgbQtGC3jzU
2017-02-16T16:57:26.536373-08:00 NOTICE ag[3435]: autotest server[stack::close|close|close] -> ssh_run(rm -rf "/tmp/autoserv-zggX7u")

So, the DUT removed this file at 16:57:26, but the mkdir cmd happened at 16:57:22, which is 4 seconds earlier. This is race condition here. Is this just a rare case?
 
Comment 1 by ihf@chromium.org, Feb 17 2017
The rm -rf at 16:57:26 is part of the cleanup after the job fails. So unrelated to the failure.

02/16 16:57:26.042 ERROR|         traceback:0013| AutotestRunError: client job was aborted
02/16 16:57:26.043 DEBUG|          ssh_host:0284| Running (ssh) 'rm -rf /tmp/sysinfo/autoserv-jROxfV'
02/16 16:57:26.365 DEBUG|          ssh_host:0284| Running (ssh) 'rm -rf "/tmp/sysinfo/autoserv-jROxfV"'
02/16 16:57:26.675 DEBUG|          ssh_host:0284| Running (ssh) 'rm -rf "/tmp/autoserv-zggX7u"'
Comment 2 by ihf@chromium.org, Feb 17 2017
I don't know where the directory is coming from.
Sign in to add a comment