66
77from collections import deque
88from io import TextIOWrapper
9- from os import close , getcwd , rename , symlink , unlink
9+ from os import close , environ , getcwd , rename , symlink , unlink
1010from os .path import (abspath , basename , exists , isfile , islink ,
1111 join as joinpath , realpath , splitext )
1212from shutil import copyfile
1313from subprocess import Popen , PIPE , TimeoutExpired
1414from sys import stderr
1515from tempfile import mkstemp
16- from threading import Thread
16+ from threading import Event , Thread
1717from time import sleep , time as now
1818from traceback import format_exc
1919from typing import NamedTuple , Optional , Union
2828
2929from . import DEFAULT_TIMEOUT
3030from .filemgr import VtorFileManager
31+ from .spi import VtorSpiBridge
3132from .vcp import VtorVcpManager
3233
3334
@@ -58,6 +59,9 @@ class VtorExecuter:
5859 START_TIMEOUT = 2.0
5960 """Initial timeout to load and query Verilator."""
6061
62+ TERMINATION_TIMEOUT = 2.0
63+ """Delay for Verilator to quit on request, before being force-killed."""
64+
6165 def __init__ (self , vfm : VtorFileManager , verilator : str ,
6266 profile : Optional [str ], debug : bool = False ):
6367 self ._log = logging .getLogger ('vtor.exec' )
@@ -67,12 +71,17 @@ def __init__(self, vfm: VtorFileManager, verilator: str,
6771 self ._verilator = verilator
6872 self ._fm = vfm
6973 self ._artifact_name : Optional [str ] = None
74+ self ._generate_spi_log = False
7075 self ._save_xlog = False
7176 self ._link_xlog = False
7277 self ._gen_wave = False
7378 # parsed communication ports from Verilator
7479 self ._ports : dict [str , Union [int , str ]] = {}
7580 self ._vcp = VtorVcpManager ()
81+ self ._spi_event = Event ()
82+ self ._spi = VtorSpiBridge (debug )
83+ # where Verilator stores the SPI device log file
84+ self ._spilog_path : Optional [str ] = None
7685 # where Verilator stores the execution log file
7786 self ._xlog_path : Optional [str ] = None
7887 self ._resume = False
@@ -160,10 +169,19 @@ def secret_file(self, file_path: str) -> None:
160169 raise FileNotFoundError (f'No such secret file { file_path } ' )
161170 self ._secret_file = file_path
162171
172+ def create_spi_device_brige (self , spi_port : int ) -> None :
173+ """Create a fake QEMU SPI device server to bridge Verilator SPI device.
174+
175+ :param spi_port: optional TCP port to create a SPI device bridge
176+ """
177+ self ._spi .create (spi_port , self ._spi_event )
178+ self ._generate_spi_log = True
179+
163180 def verilate (self , rom_files : list [str ], ram_files : list [str ],
164181 flash_files : list [str ], app_files : list [str ],
165182 otp : Optional [str ], timeout : float = None ,
166- cycles : Optional [int ] = None ) -> int :
183+ cycles : Optional [int ] = None , ) \
184+ -> int :
167185 """Execute a Verilator simulation.
168186
169187 :param rom_files: optional list of files to load in ROMs
@@ -172,7 +190,7 @@ def verilate(self, rom_files: list[str], ram_files: list[str],
172190 :param app_files: optional list of application ELF files to execute
173191 :param otp: optional file to load as OTP image
174192 :param timeout: optional max execution delay in seconds
175- :paran cycles: optional max execution cycles
193+ :param cycles: optional max execution cycles
176194 """
177195 workdir = self ._fm .tmp_dir
178196 self ._log .debug ('Work dir: %s' , workdir )
@@ -221,9 +239,13 @@ def verilate(self, rom_files: list[str], ram_files: list[str],
221239 args .append (f'--trace={ wave_name } ' )
222240 self ._log .debug ('Executing Verilator as %s' ,
223241 self ._simplifly_cli (args ))
242+ env = dict (environ )
243+ if self ._generate_spi_log :
244+ # 'P': log SPI PTY protocol (do not use M': SPI "monitor")
245+ env ['VERILATOR_SPI_LOG' ] = 'P'
224246 # pylint: disable=consider-using-with
225247 proc = Popen (args ,
226- bufsize = 1 , cwd = workdir ,
248+ bufsize = 1 , cwd = workdir , env = env ,
227249 stdout = PIPE , stderr = PIPE ,
228250 encoding = 'utf-8' , errors = 'ignore' , text = True )
229251 try :
@@ -234,10 +256,10 @@ def verilate(self, rom_files: list[str], ram_files: list[str],
234256 ret = proc .returncode
235257 self ._log .error ('Verilator bailed out: %d' , ret )
236258 raise OSError ()
237- # if execution starts and the execution log should be generated
238- # discards any previous file to avoid leaving a previous version of
239- # this file that would not match the current session
240- self ._discard_exec_log ()
259+ # if execution starts and the log file should be generated, discards
260+ # any previous file to avoid leaving a previous version of such file
261+ # that would not match the current session
262+ self ._discard_logs ()
241263 log_q = deque ()
242264 self ._resume = True
243265 for pos , stream in enumerate (('out' , 'err' )):
@@ -250,6 +272,23 @@ def verilate(self, rom_files: list[str], ram_files: list[str],
250272 thread .start ()
251273 abstimeout = float (timeout ) + now ()
252274 while now () < abstimeout :
275+ if self ._spi_event .is_set ():
276+ match self ._spi .exception :
277+ case TimeoutError ():
278+ reason = 'no response from Verilator'
279+ case BrokenPipeError () | ConnectionResetError ():
280+ reason = 'host disconnected'
281+ case Exception ():
282+ reason = str (self ._spi .exception )
283+ case _:
284+ reason = 'unknown'
285+ if not ret :
286+ ret = proc .poll ()
287+ if not ret :
288+ ret = 1
289+ self ._log .error ('Exiting on %s SPI bridge event, code %d' ,
290+ reason , ret )
291+ break
253292 while log_q :
254293 err , qline = log_q .popleft ()
255294 if err :
@@ -266,6 +305,13 @@ def verilate(self, rom_files: list[str], ram_files: list[str],
266305 self ._vcp .connect ({
267306 k : v for k , v in self ._ports .items ()
268307 if k .startswith ('uart' )}, 2.0 )
308+ spi_ptys = sorted ([v for p , v in self ._ports .items ()
309+ if p .startswith ('spi' )])
310+ if spi_ptys :
311+ self ._spi .connect_pty (spi_ptys [0 ])
312+ # only support a single SPI device bridge
313+ if len (spi_ptys ) > 1 :
314+ self ._log .warning ('Too many SPI devices' )
269315 self ._log .info ('Simulation begins' )
270316 else :
271317 self ._parse_verilator_info (qline )
@@ -280,6 +326,7 @@ def verilate(self, rom_files: list[str], ram_files: list[str],
280326 if xret is None :
281327 xret = self ._vcp .process ()
282328 if xret is not None :
329+ self ._log .debug ('Verilator exited with code %d' , xret )
283330 if xend is None :
284331 xend = now ()
285332 ret = xret
@@ -294,11 +341,12 @@ def verilate(self, rom_files: list[str], ram_files: list[str],
294341 else :
295342 ret = self .DEADLOCK
296343 finally :
344+ self ._spi .disconnect ()
297345 self ._vcp .disconnect ()
298346 if proc :
299347 # leave some for Verilator to cleanly complete and flush its
300348 # streams
301- wait = 0.5
349+ wait = self . TERMINATION_TIMEOUT
302350 if xend is None :
303351 xend = now ()
304352 waited_time = now ()
@@ -348,11 +396,15 @@ def verilate(self, rom_files: list[str], ram_files: list[str],
348396 if log_q :
349397 # should never happen
350398 self ._vlog .error ('Lost traces' )
351- self ._save_exec_log ()
399+ self ._save_logs ()
352400 tmp_profile = joinpath (workdir , 'profile.vlt' )
353401 if isfile (tmp_profile ) and profile_file :
354402 self ._log .info ('Saving profile file as %s' , profile_file )
355403 copyfile (tmp_profile , profile_file )
404+ if ret :
405+ self ._log .error ("Verilator failed: %s" , ret )
406+ else :
407+ self ._log .info ("Success" )
356408 return abs (ret or 0 )
357409
358410 def _vtor_logger (self , stream : TextIOWrapper , queue : deque , err : bool ) \
@@ -508,6 +560,12 @@ def _parse_verilator_info(self, line: str) -> None:
508560 parts = line .split ('.' )[0 ].split (' ' )
509561 self ._ports [parts [- 1 ]] = parts [- 3 ]
510562 return
563+ spi_prefix = 'SPI: PTY output file created at '
564+ if line .startswith (spi_prefix ):
565+ spi_log_line = line .removeprefix (spi_prefix )
566+ self ._spilog_path = spi_log_line .rsplit ('.' , 1 )[0 ]
567+ self ._log .debug ('SPI PTY log path: %s' , self ._spilog_path )
568+ return
511569
512570 def _parse_verilator_log (self , line : str ) -> bool :
513571 """Parse verilator log mesage.
@@ -554,18 +612,23 @@ def _parse_verilator_output(self, line: str, err: bool) -> str:
554612 return ''
555613 return line
556614
557- def _discard_exec_log (self ) -> None :
615+ def _discard_logs (self ) -> None :
558616 if not self ._artifact_name :
559617 return
560- log_path = f'{ self ._artifact_name } .log'
561- if log_path or not isfile (log_path ):
562- return
563- try :
564- unlink (log_path )
565- self ._log .debug ('Old execution log file discarded' )
566- except OSError as exc :
567- self ._log .error ('Cannot remove previous execution log file: %s' ,
568- exc )
618+ for log_suffix in ('' , 'spi.' ):
619+ log_path = f'{ self ._artifact_name } .{ log_suffix } log'
620+ if not isfile (log_path ):
621+ continue
622+ try :
623+ unlink (log_path )
624+ self ._log .debug ('Old execution log file discarded' )
625+ except OSError as exc :
626+ self ._log .error ('Cannot remove previous execution log file: %s' ,
627+ exc )
628+
629+ def _save_logs (self ) -> None :
630+ self ._save_exec_log ()
631+ self ._save_spi_log ()
569632
570633 def _save_exec_log (self ) -> None :
571634 if not self ._save_xlog :
@@ -584,6 +647,20 @@ def _save_exec_log(self) -> None:
584647 self ._log .debug ('Saving execution log as %s' , log_path )
585648 copyfile (self ._xlog_path , log_path )
586649
650+ def _save_spi_log (self ) -> None :
651+ if not self ._generate_spi_log :
652+ return
653+ if not self ._spilog_path :
654+ self ._log .error ('No SPI log file found' )
655+ return
656+ if not isfile (self ._spilog_path ):
657+ self ._log .error ('Missing SPI log file' )
658+ return
659+ assert self ._artifact_name is not None
660+ log_path = f'{ self ._artifact_name } .spi.log'
661+ self ._log .debug ('Saving SPI log as %s' , log_path )
662+ copyfile (self ._spilog_path , log_path )
663+
587664 def _convert_rom_file (self , file_kind : str , file_path : str , size : int ,
588665 rom_idx : int ) -> str :
589666 if file_kind in ('hex' , 'svmem' ):
0 commit comments