search

nickg / nvc

VHDL compiler and simulator
https://www.nickg.me.uk/nvc/
GNU General Public License v3.0
637 stars 80 forks source link

Axilite VVC #614

Closed avelure closed 2 months ago

avelure commented 1 year ago

I'm running a testcase with the Axilite VVC from UVVM and I get a different result on NVC vs Modelsim.

library IEEE;
use IEEE.std_logic_1164.all;
use IEEE.numeric_std.all;
-- Opencores model
entity msec_ipcore_axilite is
  generic(
    C_S_AXI_DATA_WIDTH : integer          := 32;
    C_S_AXI_ADDR_WIDTH : integer          := 32
  );
  port(
    core_clk      : in  std_logic;
    S_AXI_ACLK    : in  std_logic;
    S_AXI_ARESETN : in  std_logic;
    S_AXI_AWADDR  : in  std_logic_vector(C_S_AXI_ADDR_WIDTH - 1 downto 0);
    S_AXI_AWVALID : in  std_logic;
    S_AXI_AWREADY : out std_logic;
    S_AXI_WDATA   : in  std_logic_vector(C_S_AXI_DATA_WIDTH - 1 downto 0);
    S_AXI_WVALID  : in  std_logic;
    S_AXI_WREADY  : out std_logic;
    S_AXI_WSTRB   : in  std_logic_vector((C_S_AXI_DATA_WIDTH / 8) - 1 downto 0);
    S_AXI_BVALID  : out std_logic;
    S_AXI_BREADY  : in  std_logic;
    S_AXI_BRESP   : out std_logic_vector(1 downto 0);
    S_AXI_ARADDR  : in  std_logic_vector(C_S_AXI_ADDR_WIDTH - 1 downto 0);
    S_AXI_ARVALID : in  std_logic;
    S_AXI_ARREADY : out std_logic;
    S_AXI_RDATA   : out std_logic_vector(C_S_AXI_DATA_WIDTH - 1 downto 0);
    S_AXI_RVALID  : out std_logic;
    S_AXI_RREADY  : in  std_logic;
    S_AXI_RRESP   : out std_logic_vector(1 downto 0)
  );
end entity msec_ipcore_axilite;

architecture IMP of msec_ipcore_axilite is
  type axi_states is (addr_wait, read_state, write_state, response_state);
  signal state : axi_states;
  signal address : std_logic_vector(C_S_AXI_ADDR_WIDTH - 1 downto 0);
  signal reset   : std_logic;
  signal S_AXI_BVALID_i : std_logic;
  signal cs_array         : std_logic_vector(6 downto 0);
  signal slv_reg_selected : std_logic;
  signal op_mem_selected  : std_logic;
  signal op_sel           : std_logic_vector(1 downto 0);
  signal MNO_sel          : std_logic;
  signal slv_reg              : std_logic_vector(C_S_AXI_DATA_WIDTH - 1 downto 0);
  signal slv_reg_write_enable : std_logic;
  signal load_flags           : std_logic;
  signal write_enable      : std_logic;
  signal core_write_enable : std_logic;
  signal core_fifo_push    : std_logic;
  signal core_data_out     : std_logic_vector(31 downto 0);
  signal core_rw_address   : std_logic_vector(8 downto 0);
  signal core_interrupt     : std_logic;
  signal core_fifo_full     : std_logic;
  signal core_fifo_nopush   : std_logic;
  signal core_ready         : std_logic;
  signal core_mem_collision : std_logic;
  signal core_start          : std_logic;
  signal core_start_bit      : std_logic;
  signal core_start_bit_d    : std_logic;
  signal core_exp_m          : std_logic;
  signal core_p_sel          : std_logic_vector(1 downto 0);
  signal core_dest_op_single : std_logic_vector(1 downto 0);
  signal core_x_sel_single   : std_logic_vector(1 downto 0);
  signal core_y_sel_single   : std_logic_vector(1 downto 0);
  signal core_flags          : std_logic_vector(15 downto 0);
  signal core_modulus_sel    : std_logic;
begin
  S_AXI_BRESP <= "00";
  S_AXI_RRESP <= "00";

  axi_slave_states : process(S_AXI_ACLK)
  begin
    if rising_edge(S_AXI_ACLK) then
      if S_AXI_ARESETN = '0' then
        S_AXI_RVALID   <= '0';
        S_AXI_BVALID_i <= '0';
        S_AXI_ARREADY  <= '0';
        S_AXI_WREADY   <= '0';
        S_AXI_AWREADY  <= '0';
        state          <= addr_wait;
        address        <= (others => '0');
        write_enable   <= '0';
      else
        case state is
          when addr_wait =>
            if S_AXI_ARVALID = '1' then -- read
              state         <= read_state;
              address       <= S_AXI_ARADDR;
              S_AXI_ARREADY <= '1';
            elsif (S_AXI_AWVALID = '1' and S_AXI_WVALID = '1') then -- write
              state   <= write_state;
              address <= S_AXI_AWADDR;
            else
              state <= addr_wait;
            end if;

          when read_state =>
            S_AXI_ARREADY <= '0';
            S_AXI_RVALID  <= '1';
            state         <= response_state;

          when write_state =>
            S_AXI_AWREADY <= '1';
            write_enable  <= '1';
            S_AXI_WREADY  <= '1';
            state         <= response_state;

          when response_state =>
            write_enable   <= '0';
            S_AXI_AWREADY  <= '0';
            S_AXI_WREADY   <= '0';
            S_AXI_BVALID_i <= '1';
            if (S_AXI_RREADY = '1') or (S_AXI_BVALID_i = '1' and S_AXI_BREADY = '1') then
              S_AXI_RVALID   <= '0';
              S_AXI_BVALID_i <= '0';
              state          <= addr_wait;
            else
              state <= response_state;
            end if;

        end case;
      end if;
    end if;
  end process;
  S_AXI_BVALID <= S_AXI_BVALID_i;
  S_AXI_RDATA <= slv_reg when (slv_reg_selected = '1') else
                 core_data_out;

  core_p_sel          <= slv_reg(31 downto 30);
  core_dest_op_single <= slv_reg(29 downto 28);
  core_x_sel_single   <= slv_reg(27 downto 26);
  core_y_sel_single   <= slv_reg(25 downto 24);
  core_start_bit      <= slv_reg(23);
  core_exp_m          <= slv_reg(22);
  core_modulus_sel    <= slv_reg(21);
  reset               <= (not S_AXI_ARESETN);

  SLAVE_REG_WRITE_PROC : process(S_AXI_ACLK) is
    variable slv_reg_to_be_written : std_logic_vector(slv_reg'length - 1 downto 0) := (others => '0');
  begin
    if rising_edge(S_AXI_ACLK) then
      if reset = '1' then
        slv_reg <= (others => '0');
      elsif load_flags = '1' then
        slv_reg <= slv_reg(31 downto 16) & core_flags;
      else
        if (slv_reg_write_enable = '1') then
          for i in 0 to S_AXI_WSTRB'length - 1 loop
            if S_AXI_WSTRB(i) = '1' then
              slv_reg_to_be_written((8 * i) + 7 downto (8 * i)) := S_AXI_WDATA((8 * i) + 7 downto (8 * i));
            else
              slv_reg_to_be_written((8 * i) + 7 downto (8 * i)) := (others => '0');
            end if;
          end loop;
          slv_reg <= slv_reg_to_be_written;
        end if;
      end if;
    end if;
  end process SLAVE_REG_WRITE_PROC;

  START_PULSE : process(S_AXI_ACLK)
  begin
    if rising_edge(S_AXI_ACLK) then
      core_start_bit_d <= core_start_bit;
    end if;
  end process;
  core_start <= core_start_bit and not core_start_bit_d;

  core_interrupt <= '0';

  FLAGS_CNTRL_PROC : process(S_AXI_ACLK, reset) is
  begin
    if reset = '1' then
      core_flags <= (others => '0');
      load_flags <= '0';
    elsif rising_edge(S_AXI_ACLK) then
      if core_start = '1' then
        core_flags <= (others => '0');
      else
        if core_ready = '1' then
          core_flags(15) <= '1';
        else
          core_flags(15) <= core_flags(15);
        end if;
        if core_mem_collision = '1' then
          core_flags(14) <= '1';
        else
          core_flags(14) <= core_flags(14);
        end if;
        if core_fifo_full = '1' then
          core_flags(13) <= '1';
        else
          core_flags(13) <= core_flags(13);
        end if;
        if core_fifo_nopush = '1' then
          core_flags(12) <= '1';
        else
          core_flags(12) <= core_flags(12);
        end if;
      end if;
      load_flags <= core_interrupt;
    end if;
  end process FLAGS_CNTRL_PROC;

  with address(14 downto 12) select cs_array <=
    "0000001" when "000",               -- M
    "0000010" when "001",               -- OP0
    "0000100" when "010",               -- OP1
    "0001000" when "011",               -- OP2
    "0010000" when "100",               -- OP3
    "0100000" when "101",               -- FIFO
    "1000000" when "110",               -- user reg space
    "0000000" when others;

  slv_reg_selected     <= cs_array(6);
  slv_reg_write_enable <= write_enable and slv_reg_selected;
  op_mem_selected <= cs_array(0) or cs_array(1) or cs_array(2) or cs_array(3) or cs_array(4);
  MNO_sel <= cs_array(0);

  with cs_array(4 downto 1) select op_sel <=
    "00" when "0001",
    "01" when "0010",
    "10" when "0100",
    "11" when "1000",
    "00" when others;

  core_rw_address <= MNO_sel & op_sel & address(7 downto 2);
  core_write_enable <= write_enable and op_mem_selected;
  core_fifo_push <= write_enable and cs_array(5);
end IMP;

----------------------------------------------------------------------------------------

library IEEE;
use IEEE.std_logic_1164.all;
use IEEE.numeric_std.all;

library uvvm_util;
context uvvm_util.uvvm_util_context;

library uvvm_vvc_framework;
use uvvm_vvc_framework.ti_vvc_framework_support_pkg.all;

library bitvis_vip_axilite;
context bitvis_vip_axilite.vvc_context;

entity test is
end entity;

architecture beh of test is
  constant C_CLK_PERIOD   : time    := 10 ns;
  constant C_ADDR_WIDTH : natural := 32;
  constant C_DATA_WIDTH : natural := 32;

  signal clk       : std_logic := '0';
  signal clock_ena : boolean   := false;

  signal axilite_if_1 : t_axilite_if(write_address_channel(awaddr(C_ADDR_WIDTH - 1 downto 0)),
                                     write_data_channel(wdata(C_DATA_WIDTH - 1 downto 0),
                                                        wstrb((C_DATA_WIDTH / 8) - 1 downto 0)),
                                     read_address_channel(araddr(C_ADDR_WIDTH - 1 downto 0)),
                                     read_data_channel(rdata(C_DATA_WIDTH - 1 downto 0)));
begin
  i_axilite_slave_1 : entity work.msec_ipcore_axilite
    generic map(
      C_S_AXI_DATA_WIDTH => C_DATA_WIDTH,
      C_S_AXI_ADDR_WIDTH => C_ADDR_WIDTH
    )
    port map(
      core_clk      => clk,
      S_AXI_ACLK    => clk,
      S_AXI_ARESETN => '1',
      S_AXI_AWADDR  => axilite_if_1.write_address_channel.awaddr,
      S_AXI_AWVALID => axilite_if_1.write_address_channel.awvalid,
      S_AXI_AWREADY => axilite_if_1.write_address_channel.awready,
      S_AXI_WDATA   => axilite_if_1.write_data_channel.wdata,
      S_AXI_WVALID  => axilite_if_1.write_data_channel.wvalid,
      S_AXI_WREADY  => axilite_if_1.write_data_channel.wready,
      S_AXI_WSTRB   => axilite_if_1.write_data_channel.wstrb,
      S_AXI_BVALID  => axilite_if_1.write_response_channel.bvalid,
      S_AXI_BREADY  => axilite_if_1.write_response_channel.bready,
      S_AXI_BRESP   => axilite_if_1.write_response_channel.bresp,
      S_AXI_ARADDR  => axilite_if_1.read_address_channel.araddr,
      S_AXI_ARVALID => axilite_if_1.read_address_channel.arvalid,
      S_AXI_ARREADY => axilite_if_1.read_address_channel.arready,
      S_AXI_RDATA   => axilite_if_1.read_data_channel.rdata,
      S_AXI_RVALID  => axilite_if_1.read_data_channel.rvalid,
      S_AXI_RREADY  => axilite_if_1.read_data_channel.rready,
      S_AXI_RRESP   => axilite_if_1.read_data_channel.rresp);

  i1_axilite_vvc : entity bitvis_vip_axilite.axilite_vvc
    generic map(
      GC_ADDR_WIDTH   => C_ADDR_WIDTH,
      GC_DATA_WIDTH   => C_DATA_WIDTH,
      GC_INSTANCE_IDX => 1
    )
    port map(
      clk                   => clk,
      axilite_vvc_master_if => axilite_if_1
    );

  i_ti_uvvm_engine : entity uvvm_vvc_framework.ti_uvvm_engine;
  p_clock : clock_generator(clk, clock_ena, C_CLK_PERIOD, "Axilite CLK");

  p_main : process
    variable v_timestamp     : time;
  begin
    await_uvvm_initialization(VOID);
    shared_axilite_vvc_config(1).bfm_config.clock_period := C_CLK_PERIOD;
    shared_axilite_vvc_config(1).inter_bfm_delay.delay_type    := TIME_START2START;
    shared_axilite_vvc_config(1).inter_bfm_delay.delay_in_time := C_CLK_PERIOD * 50;
    clock_ena <= true;

    wait for C_CLK_PERIOD * 51;
    wait until rising_edge(clk);
    axilite_write(AXILITE_VVCT, 1, x"0000", x"ffff", "Third inter-bfm delay axilite write");
    await_completion(AXILITE_VVCT, 1, (56 * C_CLK_PERIOD));
    v_timestamp := now;
    insert_delay(AXILITE_VVCT, 1, C_CLK_PERIOD);
    insert_delay(AXILITE_VVCT, 1, C_CLK_PERIOD);
    insert_delay(AXILITE_VVCT, 1, C_CLK_PERIOD);
    insert_delay(AXILITE_VVCT, 1, C_CLK_PERIOD);
    axilite_write(AXILITE_VVCT, 1, x"0000", x"abcd", "Fourth inter-bfm delay axilite write");
    await_completion(AXILITE_VVCT, 1, (56 * C_CLK_PERIOD));
    check_value(now - v_timestamp, C_CLK_PERIOD * 54, ERROR, "Checking that inter-bfm delay was upheld");

    std.env.stop;
    wait;
  end process p_main;
end beh;

Output from nvc:

UVVM: ID_CONSTRUCTOR                     0.0 ns  AXILITE_VVC,1                  VVC instantiated.
UVVM: ID_CONSTRUCTOR_SUB                 0.0 ns  AXILITE_VVC,1                  Command queue instantiated and will give a warning when reaching 1000 elements in queue.
UVVM: ID_CONSTRUCTOR_SUB                 0.0 ns  AXILITE_VVC,1                  Result queue instantiated and will give a warning when reaching 1000 elements in queue.
UVVM: ID_CMD_INTERPRETER_WAIT            0.0 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
UVVM: ID_CTRL                            0.0 ns  AXILITE_VVC_SB,1               enable() => SB enabled. 'AXILITE VVC SB Enabled'
UVVM: ID_CTRL                            0.0 ns  AXILITE_VVC_SB,1               config() => config applied to SB.
UVVM: ID_CTRL                            0.0 ns  AXILITE_VVC_SB,1               enable_log_msg() => message id id_data enabled.
UVVM: ID_CMD_EXECUTOR_WAIT               0.0 ns  AXILITE_VVC,1                    ..Executor: Waiting for command
UVVM: ID_CLOCK_GEN                       0.0 ns  TB seq.                        Starting clock Axilite CLK
UVVM: ID_UVVM_SEND_CMD                 510.0 ns  TB seq.(uvvm)                  ->axilite_write(AXILITE_VVC,1, x"0000", x"FFFF"): 'Third inter-bfm delay axilite write'. [1]
UVVM: ID_CMD_INTERPRETER               510.0 ns  AXILITE_VVC,1                    axilite_write(AXILITE_VVC,1, x"0000", x"FFFF"). Command received  [1]
UVVM: ID_UVVM_CMD_ACK                  510.0 ns  TB seq.(uvvm)                      ACK received.   [1]
UVVM: ID_CMD_EXECUTOR                  510.0 ns  AXILITE_VVC,1                    axilite_write(AXILITE_VVC,1, x"0000", x"FFFF") - Will be executed  [1]
UVVM: ID_CMD_INTERPRETER_WAIT          510.0 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
UVVM: ID_AWAIT_COMPLETION              510.0 ns  TB seq.(uvvm)                  await_completion(AXILITE_VVC,1, 560 ns): . [2]
UVVM: ID_AWAIT_COMPLETION_WAIT         510.0 ns  TB seq.(uvvm)                  ..await_completion(AXILITE_VVC,1, 560 ns) - Pending completion.  [2]
UVVM: ID_CMD_EXECUTOR_WAIT             510.0 ns  AXILITE_VVC,1                    ..Executor: Waiting for command
UVVM: ID_BFM                           562.5 ns  AXILITE_VVC_B,1                write_response_channel_check()=> OK. 'Third inter-bfm delay axilite write'  [1]
UVVM: ID_AWAIT_COMPLETION_END          562.5 ns  TB seq.(uvvm)                    await_completion(AXILITE_VVC,1, 560 ns)=> AXILITE_VVC,1 finished.  [2]
UVVM: ID_UVVM_SEND_CMD                 562.5 ns  TB seq.(uvvm)                  ->insert_delay(AXILITE_VVC,1, 10000000 fs): . [3]
UVVM: ID_CMD_INTERPRETER               562.5 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs). Command received  [3]
UVVM: ID_UVVM_CMD_ACK                  562.5 ns  TB seq.(uvvm)                      ACK received.   [3]
UVVM: ID_CMD_EXECUTOR                  562.5 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs) - Will be executed  [3]
UVVM: ID_INSERTED_DELAY                562.5 ns  AXILITE_VVC,1                  Delaying BFM access until time 1010000000 fs.
UVVM: ID_CMD_INTERPRETER_WAIT          562.5 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
UVVM: ID_UVVM_SEND_CMD                 562.5 ns  TB seq.(uvvm)                  ->insert_delay(AXILITE_VVC,1, 10000000 fs): . [4]
UVVM: ID_CMD_INTERPRETER               562.5 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs). Command received  [4]
UVVM: ID_UVVM_CMD_ACK                  562.5 ns  TB seq.(uvvm)                      ACK received.   [4]
UVVM: ID_CMD_INTERPRETER_WAIT          562.5 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
UVVM: ID_UVVM_SEND_CMD                 562.5 ns  TB seq.(uvvm)                  ->insert_delay(AXILITE_VVC,1, 10000000 fs): . [5]
UVVM: ID_CMD_INTERPRETER               562.5 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs). Command received  [5]
UVVM: ID_UVVM_CMD_ACK                  562.5 ns  TB seq.(uvvm)                      ACK received.   [5]
UVVM: ID_CMD_INTERPRETER_WAIT          562.5 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
UVVM: ID_UVVM_SEND_CMD                 562.5 ns  TB seq.(uvvm)                  ->insert_delay(AXILITE_VVC,1, 10000000 fs): . [6]
UVVM: ID_CMD_INTERPRETER               562.5 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs). Command received  [6]
UVVM: ID_UVVM_CMD_ACK                  562.5 ns  TB seq.(uvvm)                      ACK received.   [6]
UVVM: ID_CMD_INTERPRETER_WAIT          562.5 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
UVVM: ID_UVVM_SEND_CMD                 562.5 ns  TB seq.(uvvm)                  ->axilite_write(AXILITE_VVC,1, x"0000", x"ABCD"): 'Fourth inter-bfm delay axilite write'. [7]
UVVM: ID_CMD_INTERPRETER               562.5 ns  AXILITE_VVC,1                    axilite_write(AXILITE_VVC,1, x"0000", x"ABCD"). Command received  [7]
UVVM: ID_UVVM_CMD_ACK                  562.5 ns  TB seq.(uvvm)                      ACK received.   [7]
UVVM: ID_CMD_INTERPRETER_WAIT          562.5 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
UVVM: ID_AWAIT_COMPLETION              562.5 ns  TB seq.(uvvm)                  await_completion(AXILITE_VVC,1, 560 ns): . [8]
UVVM: ID_AWAIT_COMPLETION_WAIT         562.5 ns  TB seq.(uvvm)                  ..await_completion(AXILITE_VVC,1, 560 ns) - Pending completion.  [8]
UVVM: ID_INSERTED_DELAY               1010.0 ns  AXILITE_VVC,1                  Finished delaying BFM access
UVVM: ID_INSERTED_DELAY               1010.0 ns  AXILITE_VVC,1                  Running: insert_delay(AXILITE_VVC,1, 10000000 fs)  [3]
UVVM: ID_CMD_EXECUTOR                 1020.0 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs) - Will be executed  [4]
UVVM: ID_INSERTED_DELAY               1020.0 ns  AXILITE_VVC,1                  Running: insert_delay(AXILITE_VVC,1, 10000000 fs)  [4]
UVVM: ID_CMD_EXECUTOR                 1030.0 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs) - Will be executed  [5]
UVVM: ID_INSERTED_DELAY               1030.0 ns  AXILITE_VVC,1                  Running: insert_delay(AXILITE_VVC,1, 10000000 fs)  [5]
UVVM: ID_CMD_EXECUTOR                 1040.0 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs) - Will be executed  [6]
UVVM: ID_INSERTED_DELAY               1040.0 ns  AXILITE_VVC,1                  Running: insert_delay(AXILITE_VVC,1, 10000000 fs)  [6]
UVVM: ID_CMD_EXECUTOR                 1050.0 ns  AXILITE_VVC,1                    axilite_write(AXILITE_VVC,1, x"0000", x"ABCD") - Will be executed  [7]
UVVM: ID_AWAIT_COMPLETION_END         1050.0 ns  TB seq.(uvvm)                    await_completion(AXILITE_VVC,1, 560 ns)=> AXILITE_VVC,1 finished.  [8]
UVVM:
UVVM: =========================================================================================================================================================================
UVVM: ***  ERROR #1  ***
UVVM:          1050 ns   TB seq.
UVVM:                    check_value() => Failed. time  Was 487500000 fs. Expected 540000000 fs
UVVM:                    Checking that inter-bfm delay was upheld

Output from Modelsim:

# UVVM: ID_CONSTRUCTOR                     0.0 ns  AXILITE_VVC,1                  VVC instantiated.
# UVVM: ID_CONSTRUCTOR_SUB                 0.0 ns  AXILITE_VVC,1                  Command queue instantiated and will give a warning when reaching 1000 elements in queue.
# UVVM: ID_CONSTRUCTOR_SUB                 0.0 ns  AXILITE_VVC,1                  Result queue instantiated and will give a warning when reaching 1000 elements in queue.
# UVVM: ID_CMD_INTERPRETER_WAIT            0.0 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
# UVVM: ID_CTRL                            0.0 ns  AXILITE_VVC_SB,1               enable() => SB enabled. 'AXILITE VVC SB Enabled'
# UVVM: ID_CTRL                            0.0 ns  AXILITE_VVC_SB,1               config() => config applied to SB.
# UVVM: ID_CTRL                            0.0 ns  AXILITE_VVC_SB,1               enable_log_msg() => message id id_data enabled.
# UVVM: ID_CMD_EXECUTOR_WAIT               0.0 ns  AXILITE_VVC,1                    ..Executor: Waiting for command
# UVVM: ID_CLOCK_GEN                       0.0 ns  TB seq.                        Starting clock Axilite CLK
# UVVM: ID_UVVM_SEND_CMD                 510.0 ns  TB seq.(uvvm)                  ->axilite_write(AXILITE_VVC,1, x"0000", x"FFFF"): 'Third inter-bfm delay axilite write'. [1]
# UVVM: ID_CMD_INTERPRETER               510.0 ns  AXILITE_VVC,1                    axilite_write(AXILITE_VVC,1, x"0000", x"FFFF"). Command received  [1]
# UVVM: ID_UVVM_CMD_ACK                  510.0 ns  TB seq.(uvvm)                      ACK received.   [1]
# UVVM: ID_CMD_EXECUTOR                  510.0 ns  AXILITE_VVC,1                    axilite_write(AXILITE_VVC,1, x"0000", x"FFFF") - Will be executed  [1]
# UVVM: ID_CMD_INTERPRETER_WAIT          510.0 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
# UVVM: ID_AWAIT_COMPLETION              510.0 ns  TB seq.(uvvm)                  await_completion(AXILITE_VVC,1, 560 ns): . [2]
# UVVM: ID_AWAIT_COMPLETION_WAIT         510.0 ns  TB seq.(uvvm)                  ..await_completion(AXILITE_VVC,1, 560 ns) - Pending completion.  [2]
# UVVM: ID_CMD_EXECUTOR_WAIT             510.0 ns  AXILITE_VVC,1                    ..Executor: Waiting for command
# UVVM: ID_BFM                           562.5 ns  AXILITE_VVC_B,1                write_response_channel_check()=> OK. 'Third inter-bfm delay axilite write'  [1]
# UVVM: ID_AWAIT_COMPLETION_END          562.5 ns  TB seq.(uvvm)                    await_completion(AXILITE_VVC,1, 560 ns)=> AXILITE_VVC,1 finished.  [2]
# UVVM: ID_UVVM_SEND_CMD                 562.5 ns  TB seq.(uvvm)                  ->insert_delay(AXILITE_VVC,1, 10000000 fs): . [3]
# UVVM: ID_CMD_INTERPRETER               562.5 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs). Command received  [3]
# UVVM: ID_UVVM_CMD_ACK                  562.5 ns  TB seq.(uvvm)                      ACK received.   [3]
# UVVM: ID_CMD_EXECUTOR                  562.5 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs) - Will be executed  [3]
# UVVM: ID_INSERTED_DELAY                562.5 ns  AXILITE_VVC,1                  Delaying BFM access until time 1010000000 fs.
# UVVM: ID_CMD_INTERPRETER_WAIT          562.5 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
# UVVM: ID_UVVM_SEND_CMD                 562.5 ns  TB seq.(uvvm)                  ->insert_delay(AXILITE_VVC,1, 10000000 fs): . [4]
# UVVM: ID_CMD_INTERPRETER               562.5 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs). Command received  [4]
# UVVM: ID_UVVM_CMD_ACK                  562.5 ns  TB seq.(uvvm)                      ACK received.   [4]
# UVVM: ID_CMD_INTERPRETER_WAIT          562.5 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
# UVVM: ID_UVVM_SEND_CMD                 562.5 ns  TB seq.(uvvm)                  ->insert_delay(AXILITE_VVC,1, 10000000 fs): . [5]
# UVVM: ID_CMD_INTERPRETER               562.5 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs). Command received  [5]
# UVVM: ID_UVVM_CMD_ACK                  562.5 ns  TB seq.(uvvm)                      ACK received.   [5]
# UVVM: ID_CMD_INTERPRETER_WAIT          562.5 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
# UVVM: ID_UVVM_SEND_CMD                 562.5 ns  TB seq.(uvvm)                  ->insert_delay(AXILITE_VVC,1, 10000000 fs): . [6]
# UVVM: ID_CMD_INTERPRETER               562.5 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs). Command received  [6]
# UVVM: ID_UVVM_CMD_ACK                  562.5 ns  TB seq.(uvvm)                      ACK received.   [6]
# UVVM: ID_CMD_INTERPRETER_WAIT          562.5 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
# UVVM: ID_UVVM_SEND_CMD                 562.5 ns  TB seq.(uvvm)                  ->axilite_write(AXILITE_VVC,1, x"0000", x"ABCD"): 'Fourth inter-bfm delay axilite write'. [7]
# UVVM: ID_CMD_INTERPRETER               562.5 ns  AXILITE_VVC,1                    axilite_write(AXILITE_VVC,1, x"0000", x"ABCD"). Command received  [7]
# UVVM: ID_UVVM_CMD_ACK                  562.5 ns  TB seq.(uvvm)                      ACK received.   [7]
# UVVM: ID_CMD_INTERPRETER_WAIT          562.5 ns  AXILITE_VVC,1                    ..Interpreter: Waiting for command
# UVVM: ID_AWAIT_COMPLETION              562.5 ns  TB seq.(uvvm)                  await_completion(AXILITE_VVC,1, 560 ns): . [8]
# UVVM: ID_AWAIT_COMPLETION_WAIT         562.5 ns  TB seq.(uvvm)                  ..await_completion(AXILITE_VVC,1, 560 ns) - Pending completion.  [8]
# UVVM: ID_INSERTED_DELAY               1010.0 ns  AXILITE_VVC,1                  Finished delaying BFM access
# UVVM: ID_INSERTED_DELAY               1010.0 ns  AXILITE_VVC,1                  Running: insert_delay(AXILITE_VVC,1, 10000000 fs)  [3]
# UVVM: ID_CMD_EXECUTOR                 1020.0 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs) - Will be executed  [4]
# UVVM: ID_INSERTED_DELAY               1020.0 ns  AXILITE_VVC,1                  Running: insert_delay(AXILITE_VVC,1, 10000000 fs)  [4]
# UVVM: ID_CMD_EXECUTOR                 1030.0 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs) - Will be executed  [5]
# UVVM: ID_INSERTED_DELAY               1030.0 ns  AXILITE_VVC,1                  Running: insert_delay(AXILITE_VVC,1, 10000000 fs)  [5]
# UVVM: ID_CMD_EXECUTOR                 1040.0 ns  AXILITE_VVC,1                    insert_delay(AXILITE_VVC,1, 10000000 fs) - Will be executed  [6]
# UVVM: ID_INSERTED_DELAY               1040.0 ns  AXILITE_VVC,1                  Running: insert_delay(AXILITE_VVC,1, 10000000 fs)  [6]
# UVVM: ID_CMD_EXECUTOR                 1050.0 ns  AXILITE_VVC,1                    axilite_write(AXILITE_VVC,1, x"0000", x"ABCD") - Will be executed  [7]
# UVVM: ID_CMD_EXECUTOR_WAIT            1050.0 ns  AXILITE_VVC,1                    ..Executor: Waiting for command
# UVVM: ID_BFM                          1102.5 ns  AXILITE_VVC_B,1                write_response_channel_check()=> OK. 'Fourth inter-bfm delay axilite write'  [7]
# UVVM: ID_AWAIT_COMPLETION_END         1102.5 ns  TB seq.(uvvm)                    await_completion(AXILITE_VVC,1, 560 ns)=> AXILITE_VVC,1 finished.  [8]
# UVVM: ID_POS_ACK                      1102.5 ns  TB seq.                        check_value() => OK, for time 540000000 fs. 'Checking that inter-bfm delay was upheld'

As you can see the await_completion finishes at 1050 on NVC and 1102.5 on Modelsim, additionally the write_response_channel_check is run before on modelsim.

There are earlier test in the testcase that checks the passthrough of data, however I do see some warnings in modelsim, is it related to this?

# ** Warning: (vsim-8684) No drivers exist on inout port /test/i1_axilite_vvc/axilite_vvc_master_if.write_address_channel.awready, and its initial value is not used.
# Therefore, simulation behavior may occur that is not in compliance with
# the VHDL standard as the initial values come from the base signal /test/axilite_if_1.write_address_channel.awready.
# ** Warning: (vsim-8684) No drivers exist on inout port /test/i1_axilite_vvc/axilite_vvc_master_if.write_data_channel.wready, and its initial value is not used.
# Therefore, simulation behavior may occur that is not in compliance with
# the VHDL standard as the initial values come from the base signal /test/axilite_if_1.write_data_channel.wready.
# ** Warning: (vsim-8684) No drivers exist on inout port /test/i1_axilite_vvc/axilite_vvc_master_if.write_response_channel.bvalid, and its initial value is not used.
# Therefore, simulation behavior may occur that is not in compliance with
# the VHDL standard as the initial values come from the base signal /test/axilite_if_1.write_response_channel.bvalid.
# ** Warning: (vsim-8684) No drivers exist on inout port /test/i1_axilite_vvc/axilite_vvc_master_if.write_response_channel.bresp(1), and its initial value is not used.
# Therefore, simulation behavior may occur that is not in compliance with
# the VHDL standard as the initial values come from the base signal /test/axilite_if_1.write_response_channel.bresp(1).
# ** Warning: (vsim-8684) No drivers exist on inout port /test/i1_axilite_vvc/axilite_vvc_master_if.write_response_channel.bresp(0), and its initial value is not used.
# Therefore, simulation behavior may occur that is not in compliance with
# the VHDL standard as the initial values come from the base signal /test/axilite_if_1.write_response_channel.bresp(0).
# ** Warning: (vsim-8684) No drivers exist on inout port /test/i1_axilite_vvc/axilite_vvc_master_if.read_address_channel.arready, and its initial value is not used.
# Therefore, simulation behavior may occur that is not in compliance with
# the VHDL standard as the initial values come from the base signal /test/axilite_if_1.read_address_channel.arready.
# ** Warning: (vsim-8684) No drivers exist on inout port /test/i1_axilite_vvc/axilite_vvc_master_if.read_data_channel.rvalid, and its initial value is not used.
# Therefore, simulation behavior may occur that is not in compliance with
# the VHDL standard as the initial values come from the base signal /test/axilite_if_1.read_data_channel.rvalid.
# ** Warning: (vsim-8684) No drivers exist on inout port /test/i1_axilite_vvc/axilite_vvc_master_if.read_data_channel.rdata(31), and its initial value is not used.
# Therefore, simulation behavior may occur that is not in compliance with
# the VHDL standard as the initial values come from the base signal /test/axilite_if_1.read_data_channel.rdata(31).
---snip---
# ** Warning: (vsim-8684) No drivers exist on inout port /test/i1_axilite_vvc/axilite_vvc_master_if.read_data_channel.rresp(1), and its initial value is not used.
# Therefore, simulation behavior may occur that is not in compliance with
# the VHDL standard as the initial values come from the base signal /test/axilite_if_1.read_data_channel.rresp(1).
# ** Warning: (vsim-8684) No drivers exist on inout port /test/i1_axilite_vvc/axilite_vvc_master_if.read_data_channel.rresp(0), and its initial value is not used.
# Therefore, simulation behavior may occur that is not in compliance with
# the VHDL standard as the initial values come from the base signal /test/axilite_if_1.read_data_channel.rresp(0).
Blebowski commented 1 year ago

Hello @avelure , unrelated to this topic, I see that you are using NVC a lot and publishing a lot of bug reports. Could you try to test with the new code coverage implementation please ? It might reveal some bugs.

avelure commented 1 year ago

Hi, @Blebowski. It is on my agenda, I just haven't gotten around to it yet. I might have some work for you within a month or so :)

JimLewis commented 1 year ago

@avelure UVVM uses shared variables of an ordinary type for communication which was deprecated and removed from VHDL in the 2002 revision.

Using variables of this sort introduces to VHDL the same race conditions that exist in Verilog and the result is that two compliant simulators can produce different simulation results due to it. Especially if you are expecting something to happen at an exact clock cycle. Let me explain. During a given simulation cycle, perhaps due to clock rising, if both the process that sets a communication variable runs and the process that reads the communication variable runs, then whether the process that reads the variable sees what was set during that clock cycle or the next clock cycle will depend on which process runs first.

The LRM does not dictate the order in which simulators run a particular process and you will find that different simulators will indeed run the processes in different orders. It is even possible that due to optimization that a given simulator will run processes in different orders after recompiling a design.

Your warnings from ModelSim,

# ** Warning: (vsim-8684) No drivers exist on inout port /test/i1_axilite_vvc/axilite_vvc_master_if.write_address_channel.awready, and its initial value is not used.
# Therefore, simulation behavior may occur that is not in compliance with

are due to ModelSim doing port collapsing optimizations. What they are not clearly saying is that the result of this optimization modelsim may do something that is not in compliance with the standard. What it seams is happening in this sort of optimization is that the ports are removed from the design and the code is migrated up one level (sort of like unrolling a subprogram). As a result, the ports and any initializations (typically to Z) are gone. It should be noted that this sort of issue only potentially causes issues in simulators that do port collapsing optimizations (ie: modelsim). A long time ago, OSVVM interfaces initialized ports to all Z. I never saw an issue with it.

There are other ways to communicate with Verification Components that are language legal - such as what OSVVM does. See https://osvvm.org/archives/1668.

nickg commented 1 year ago

I looked at this a bit but I can't see anything obviously wrong. @avelure is there any way to spot the difference in behaviour in a waveform output? Does GHDL or another simulator give the same result as ModelSim?

nickg commented 1 year ago

Hello @avelure , unrelated to this topic, ...

@Blebowski BTW I just enabled GitHub Discussions for this project. That can be used in future for feedback, Q&A, etc.

Blebowski commented 1 year ago

Hi @nickg , thanks, I will use those for further questions.

nickg commented 1 year ago

@bpadalino tested with RiveraPRO and got the same result as Modelsim so there is probably a bug here somewhere.

bpadalino commented 1 year ago

Note that some of the transactions did happen in a different order.

Attaching all logs here for posterity.

modelsim.log nvc.log riviera.log

bpadalino commented 1 year ago

I figured out how to fix the simulation. By adding another wait for 0 ns here, the simulation completes just fine.

Unsure if this is a bug in nvc and the calculation of the delta cycles, or if it's a race condition that UVVM is not considering and they need to change to wait an extra delta cycle in some other places?

h/t to @JimLewis for suggesting adding an extra delta cycle.

avelure commented 1 year ago

Yes, I found the same earlier, there is a delta-cycle transition that can be filtered out by adding delta-cycle waits at various places, but I don't think that fixes the root cause. I think it might be due to handling of the protected variable queues, but I'm still investigating. queues_are_empty(VOID) returns true at one point where it shouldn't.

bpadalino commented 1 year ago

I think it might be due to handling of the protected variable queues, but I'm still investigating. queues_are_empty(VOID) returns true at one point where it shouldn't.

Just curious, what makes you say that it returns true when it shouldn't? Is it possible the explanation @JimLewis gave above about the ordering of processes?

Do you know if there is something we can instrument to see if nvc and modelsim are running the processes in different orders?

Just trying to understand the thought process and to verify that indeed the function should return true when it isn't.

JimLewis commented 1 year ago

@avelure This was a curious problem to look at. I added to my notebook that when setting and reading flags in a shared variable - whether it is a protected type or ordinary type - you can run into process order issues.

So you need to work though the details of when await_completion reads any activity indication and when axilite_write indicates it is doing activity.

nickg commented 1 year ago

It's definitely to do with the order the processes are run in. Here's a very simple diff you can apply to NVC which causes the processes to be run in the reverse order to normal:

diff --git a/src/thread.c b/src/thread.c
index 1ccf27e801a0..1428d1fcdc42 100644
--- a/src/thread.c
+++ b/src/thread.c
@@ -1020,7 +1020,7 @@ void workq_start(workq_t *wq)
             nparallel += wptr.count;
          }
          else {
-            for (int j = 0; j < wptr.count; j++)
+            for (int j = wptr.count - 1; j >= 0; j--)
                execute_task(&(eq->tasks[j]));
             nserial += wptr.count;
          }

If I apply that then the test has the same behaviour as Modelsim/RiveraPRO.

The LRM doesn't specify which order the processes are to be run in (they might even be run concurrently) so UVVM shouldn't be relying on that. We do seem to be running them in a different order to every other simulator though, but I think that's just an implementation detail.

bpadalino commented 1 year ago

I wonder if there is any value in being able to randomize this to help expose issues with verification frameworks? Maybe run forward, backward and random?

Anyway, I'm glad the little insight @JimLewis had was able to resolve where the bug resides.

nickg commented 1 year ago

I wonder if there is any value in being able to randomize this to help expose issues with verification frameworks? Maybe run forward, backward and random?

This is a good idea. I've added a --shuffle option to the -r command. With that the test case above can pass around half the time.

avelure commented 2 months ago

I did not find the root cause for this in UVVM, meanwhile there has been a new release of UVVM v2 (2024.09.19) where the affected code has been rewritten to avoid the issue in all VVCs.