Avalon master gives pop from empty queue error in Modelsim

[mczerski]

vunit 4.4.0, modelsim intel starter edition 10.5b (shipped with quartus 18.1), ubuntu 18.04
I think that it is the same issue as in #692

minimal testbench to reproduce the error:
avalon_tb.vhd

library ieee;
use ieee.std_logic_1164.all;

library vunit_lib;
context vunit_lib.vunit_context;
context vunit_lib.vc_context;

entity avalon_tb is
    generic (runner_cfg : string);
end avalon_tb;

architecture testbench of avalon_tb is 

    -- Avalon-MM Slave --
    signal av_address : std_logic_vector(31 downto 0);
    signal av_write : std_logic := '0';
    signal av_writedata : std_logic_vector(31 downto 0) := (others=> '0');
    signal av_read : std_logic := '0';
    signal av_readdata : std_logic_vector(31 downto 0) := (others=> '0');
    signal av_byteenable : std_logic_vector(3 downto 0);
    signal av_burstcount : std_logic_vector(3 downto 0);

    constant avalon_bus : bus_master_t := new_bus(data_length => 32, address_length => av_address'length);

    signal clk : std_logic := '0';

    constant CLK_period : time := 20 ns;

begin
    avalon_master : entity vunit_lib.avalon_master
    generic map (
        bus_handle => avalon_bus,
        use_readdatavalid => false,
        fixed_read_latency => 0
    )
    port map (
      clk => clk,
      address => av_address,
      byteenable => av_byteenable,
      burstcount => av_burstcount,
      write => av_write,
      writedata => av_writedata,
      read => av_read,
      readdata => av_readdata,
      readdatavalid => '0',
      waitrequest => '0'
    );

    -- Clock process definitions
    CLK_process: process
    begin
        clk <= '0';
        wait for CLK_period/2;
        clk <= '1';
        wait for CLK_period/2;
    end process; 

    tests: process
    begin
        test_runner_setup(runner, runner_cfg);

        wait for CLK_period*2;

        check_bus(net, avalon_bus, 0, (0 to 31 => '0'));

        test_runner_cleanup(runner);
    end process;
end;

run.py

import os
from vunit import VUnit

# Create VUnit instance by parsing command line arguments
vu = VUnit.from_argv()

vu.add_verification_components()

# Create library 'lib'
lib = vu.add_library("lib")

# Add all files ending in .vhd in current working directory to library
lib.add_source_file("avalon_tb.vhd")

vu.main()

test log with error:

# Start time: 12:54:41 on Nov 20,2020
# ** Warning: Design size of 42663 statements exceeds ModelSim-Intel FPGA Starter Edition recommended capacity.
# Expect performance to be adversely affected.
# ** Warning: (vsim-3116) Problem reading symbols from linux-gate.so.1 : can not open ELF file.
# ** Error: Pop from empty queue
#    Time: 70 ns  Iteration: 1  Process: /avalon_tb/avalon_master/read_capture File: /usr/local/lib/python3.6/dist-packages/vunit/vhdl/data_types/src/queue_pkg-body.vhd
# Break in Subprogram unsafe_pop at /usr/local/lib/python3.6/dist-packages/vunit/vhdl/data_types/src/queue_pkg-body.vhd line 114
# Stopped at /usr/local/lib/python3.6/dist-packages/vunit/vhdl/data_types/src/queue_pkg-body.vhd line 114
# 
# Test Run Failed!
# 
# Stack trace result from 'tb' command
#  /usr/local/lib/python3.6/dist-packages/vunit/vhdl/data_types/src/queue_pkg-body.vhd 114 return [address 0xf6a68156] Subprogram unsafe_pop
# called from  /usr/local/lib/python3.6/dist-packages/vunit/vhdl/data_types/src/queue_pkg-body.vhd 131 return [address 0xf6a685c7] Subprogram pop_type
# called from  /usr/local/lib/python3.6/dist-packages/vunit/vhdl/data_types/src/queue_pkg-body.vhd 138 return [address 0xf6a67ba3] Subprogram check_type
# called from  /usr/local/lib/python3.6/dist-packages/vunit/vhdl/data_types/src/queue_pkg-body.vhd 207 return [address 0xf6a65880] Subprogram pop
# called from  /usr/local/lib/python3.6/dist-packages/vunit/vhdl/com/src/com_types.vhd 532 return [address 0xf6f1e91d] Subprogram pop
# called from  /usr/local/lib/python3.6/dist-packages/vunit/vhdl/verification_components/src/avalon_master.vhd 157 return [address 0xf6ffb3b5] Process read_capture
# 
# 
# Surrounding code from 'see' command
#   109 :   ) return character is
#   110 :     variable head : integer;
#   111 :     variable data : character;
#   112 :   begin
#   113 :     assert queue /= null_queue report "Pop from null queue";
# ->114 :     assert length(queue) > 0 report "Pop from empty queue";
#   115 :     head := get(queue.p_meta, head_idx);
#   116 :     data := get(queue.data, 1 + head);
#   117 :     set(queue.p_meta, head_idx, head + 1);
#   118 :     return data;
# 
fail (P=0 S=0 F=1 T=1) lib.avalon_tb.all (1.2 seconds)

==== Summary =============================
fail lib.avalon_tb.all (1.2 seconds)
==========================================
pass 0 of 1
fail 1 of 1
==========================================
Total time was 1.2 seconds
Elapsed time was 1.2 seconds
==========================================
Some failed!

applying this patch causes the test to pass:

--- /usr/local/lib/python3.6/dist-packages/vunit/vhdl/verification_components/src/avalon_master.vhd.orig	2020-11-20 13:01:00.450536863 +0100
+++ /usr/local/lib/python3.6/dist-packages/vunit/vhdl/verification_components/src/avalon_master.vhd	2020-11-20 13:01:09.614578240 +0100
@@ -78,9 +78,9 @@
           address <= pop_std_ulogic_vector(request_msg);
           byteenable(byteenable'range) <= (others => '1');
           read <= '1';
+          push(acknowledge_queue, request_msg);
           wait until rising_edge(clk) and waitrequest = '0';
           read <= '0';
-          push(acknowledge_queue, request_msg);
 
         elsif msg_type = bus_burst_read_msg then
           while rnd.Uniform(0.0, 1.0) > read_high_probability loop

[eine]

I think it might be fixed in #666. @mczerski, can you please try?

[mczerski]

@eine no, still the same error.

[slaweksiluk]

#666 is for avalon stream. I will take a look on this.

[slaweksiluk]

Indeed the same bug as in #692. Now fixed at 14f887a Thank you for the reproducer