Profiling capabilities #15

chiggs · 2013-06-20T16:38:26Z

We want to know where all the time is going.

Initially, knowing how much time is spent in the simulator vs. how much time is spent in callback handlers would be a very useful indicator. This should be easy to do since all callbacks go through the same handler.

chiggs · 2014-03-18T09:34:19Z

Profiled the endian_swapper example from changeset 89d892c with RANDOM_SEED=1 and all calls to *.log.debug removed.

percall values removed for clarity since they are all 0.00

6795204 function calls (6783689 prills) in 4.490 seconds

Ordered by: cumulative time

          ncalls  tottime  cumtime filename:lineno(function)
   106975/100405    0.253    3.350 cocotb_profiling/cocotb/scheduler.py:270(schedule)
   106944/106627    0.138    2.113 cocotb_profiling/cocotb/decorators.py:105(send)
   106975/106658    0.038    1.932 {method 'send' of 'generator' objects}
          100858    0.235    0.980 cocotb_profiling/cocotb/log.py:77(__init__)
     27241/26967    0.031    0.871 cocotb_profiling/cocotb/scheduler.py:199(add)
           96967    0.248    0.809 cocotb_profiling/cocotb/scheduler.py:166(_add_trigger)
          101178    0.048    0.747 /usr/lib64/python2.7/logging/__init__.py:1539(getLogger)
          101178    0.166    0.699 /usr/lib64/python2.7/logging/__init__.py:998(getLogger)
           24334    0.045    0.570 cocotb_profiling/cocotb/monitors/avalon.py:90(_monitor_recv)
           46360    0.087    0.552 cocotb_profiling/cocotb/triggers.py:47(__init__)
           41482    0.027    0.525 cocotb_profiling/cocotb/triggers.py:90(__init__)
          267265    0.357    0.513 /usr/lib64/python2.7/threading.py:120(acquire)
          267265    0.325    0.413 /usr/lib64/python2.7/threading.py:140(release)
           27214    0.034    0.392 cocotb_profiling/cocotb/decorators.py:217(__call__)
           27103    0.034    0.365 cocotb_profiling/cocotb/decorators.py:226(__get__)
           16960    0.015    0.361 cocotb_profiling/cocotb/scheduler.py:406(enable_react_delay)
           27214    0.102    0.357 cocotb_profiling/cocotb/decorators.py:82(__init__)
           32537    0.024    0.340 cocotb_profiling/cocotb/scheduler.py:395(move_to_rw)
     26898/25897    0.013    0.336 cocotb_profiling/cocotb/decorators.py:68(__call__)
           27103    0.056    0.331 cocotb_profiling/cocotb/decorators.py:212(__init__)
     27122/26121    0.020    0.323 cocotb_profiling/cocotb/decorators.py:133(_finished_cb)
           12168    0.020    0.305 cocotb_profiling/examples/endian_swapper/tests/test_endian_swapper.py:107(clock_gen)
       4559/3558    0.003    0.304 cocotb_profiling/cocotb/triggers.py:447(_cb)
       4591/3558    0.020    0.301 cocotb_profiling/cocotb/scheduler.py:77(react)
           44960    0.065    0.264 cocotb_profiling/cocotb/handle.py:118(getvalue)
            7878    0.025    0.249 cocotb_profiling/cocotb/drivers/avalon.py:191(_send_string)
          101280    0.050    0.247 /usr/lib64/python2.7/logging/__init__.py:210(_acquireLock)
            1087    0.001    0.238 cocotb_profiling/cocotb/log.py:139(info)
            1087    0.003    0.237 cocotb_profiling/cocotb/log.py:86(_makeRecord)
           16268    0.012    0.207 cocotb_profiling/cocotb/triggers.py:166(__init__)
            3590    0.015    0.202 /usr/lib64/python2.7/inspect.py:987(getframeinfo)
          101280    0.043    0.202 /usr/lib64/python2.7/logging/__init__.py:219(_releaseLock)
           25481    0.019    0.201 cocotb_profiling/cocotb/handle.py:163(__le__)
          706523    0.189    0.189 {isinstance}
           25608    0.051    0.183 cocotb_profiling/cocotb/handle.py:92(__setattr__)
             447    0.000    0.182 /usr/lib64/python2.7/inspect.py:1052(stack)
             447    0.004    0.182 /usr/lib64/python2.7/inspect.py:1025(getouterframes)
           12206    0.012    0.180 cocotb_profiling/cocotb/triggers.py:115(__init__)
           12110    0.027    0.147 cocotb_profiling/cocotb/monitors/avalon.py:99(valid)
             534    0.002    0.132 cocotb_profiling/examples/endian_swapper/tests/test_endian_swapper.py:115(run_test)
            3590    0.017    0.121 /usr/lib64/python2.7/inspect.py:518(findsource)
            8544    0.012    0.114 cocotb_profiling/cocotb/drivers/avalon.py:178(_wait_ready)
          157849    0.113    0.113 {hasattr}
           16269    0.029    0.108 cocotb_profiling/cocotb/scheduler.py:156(playout_writes)
            7180    0.029    0.104 /usr/lib64/python2.7/inspect.py:440(getsourcefile)
           44960    0.090    0.099 cocotb_profiling/cocotb/binary.py:141(set_binstr)
           25832    0.021    0.096 cocotb_profiling/cocotb/handle.py:99(__hasattr__)
           12110    0.008    0.087 cocotb_profiling/cocotb/scheduler.py:410(react_delay)
          267163    0.086    0.086 {method 'acquire' of 'thread.lock' objects}
            6160    0.005    0.081 cocotb_profiling/cocotb/triggers.py:181(__init__)
           44961    0.020    0.080 cocotb_profiling/cocotb/handle.py:160(_get_value_str)
          534530    0.078    0.078 /usr/lib64/python2.7/threading.py:62(_note)
            6056    0.048    0.077 cocotb_profiling/cocotb/binary.py:106(get_buff)
           24897    0.033    0.076 cocotb_profiling/cocotb/handle.py:123(setimmediatevalue)
           25853    0.036    0.076 {simulator.get_handle_by_name}
           23542    0.035    0.070 cocotb_profiling/cocotb/triggers.py:201(prime)
            4626    0.004    0.062 cocotb_profiling/cocotb/triggers.py:150(__init__)
             352    0.001    0.061 cocotb_profiling/examples/endian_swapper/tests/test_endian_swapper.py:153(random_packet_sizes)
           44961    0.060    0.060 {simulator.get_signal_val}
            4622    0.004    0.060 cocotb_profiling/cocotb/decorators.py:143(join)
             320    0.008    0.059 cocotb_profiling/cocotb/generators/byte.py:38(get_bytes)
            4622    0.005    0.056 cocotb_profiling/cocotb/triggers.py:440(__init__)
           10770    0.018    0.053 /usr/lib64/python2.7/inspect.py:398(getfile)
          535424    0.051    0.051 {thread.get_ident}
           23374    0.013    0.051 cocotb_profiling/cocotb/generators/byte.py:46(random_data)
           75289    0.041    0.041 {simulator.create_callback}
           25736    0.014    0.040 cocotb_profiling/cocotb/log.py:101(_willLog)
           16268    0.015    0.040 cocotb_profiling/cocotb/triggers.py:169(prime)
           16960    0.016    0.040 cocotb_profiling/cocotb/triggers.py:153(prime)
            3028    0.020    0.038 cocotb_profiling/cocotb/binary.py:126(set_buff)
           23436    0.008    0.036 /usr/lib64/python2.7/random.py:237(randint)
           12206    0.012    0.031 cocotb_profiling/cocotb/triggers.py:119(prime)
            2222    0.002    0.031 cocotb_profiling/cocotb/triggers.py:132(__init__)
           84917    0.030    0.030 {method 'pop' of 'list' objects}
            2069    0.002    0.030 cocotb_profiling/cocotb/triggers.py:198(__init__)
           79975    0.026    0.030 cocotb_profiling/cocotb/scheduler.py:242(prune_routines)
          267163    0.029    0.029 {method 'release' of 'thread.lock' objects}
           23436    0.026    0.028 /usr/lib64/python2.7/random.py:173(randrange)
              64    0.000    0.026 cocotb_profiling/cocotb/scheduler.py:376(move_to_cleanup)
           26823    0.017    0.026 /usr/lib64/python2.7/logging/__init__.py:1332(isEnabledFor)
           25481    0.015    0.025 cocotb_profiling/cocotb/handle.py:149(setcachedvalue)
            7548    0.015    0.024 cocotb_profiling/cocotb/binary.py:31(resolve)
            7180    0.005    0.024 /usr/lib64/python2.7/genericpath.py:15(exists)
          110232    0.023    0.023 {method 'append' of 'list' objects}
              32    0.001    0.023 cocotb_profiling/examples/endian_swapper/tests/test_endian_swapper.py:66(__init__)
           26898    0.023    0.023 cocotb_profiling/cocotb/decorators.py:64(__init__)
           23695    0.023    0.023 {simulator.register_value_change_callback}
   182705/182704    0.022    0.022 {len}
            4622    0.005    0.022 cocotb_profiling/cocotb/scheduler.py:193(queue)
           45280    0.020    0.020 cocotb_profiling/cocotb/binary.py:62(__init__)
              31    0.000    0.020 cocotb_profiling/cocotb/decorators.py:178(send)
              16    0.000    0.020 cocotb_profiling/cocotb/scheduler.py:361(issue_result)
           41042    0.020    0.020 cocotb_profiling/cocotb/binary.py:170(__nonzero__)
              16    0.000    0.019 cocotb_profiling/cocotb/regression.py:144(handle_result)
            7182    0.019    0.019 {posix.stat}
             447    0.000    0.019 /usr/lib64/python2.7/logging/__init__.py:1260(handle)
           21869    0.018    0.018 {simulator.set_signal_val}
             447    0.001    0.018 /usr/lib64/python2.7/logging/__init__.py:1292(callHandlers)
             447    0.001    0.017 /usr/lib64/python2.7/logging/__init__.py:735(handle)
           16268    0.015    0.015 {simulator.register_rwsynch_callback}
           16960    0.015    0.015 {simulator.register_readonly_callback}
           79734    0.014    0.014 cocotb_profiling/cocotb/triggers.py:62(clearpeers)
            6160    0.006    0.014 cocotb_profiling/cocotb/triggers.py:184(prime)
           23054    0.014    0.014 {method 'format' of 'str' objects}
             447    0.001    0.013 /usr/lib64/python2.7/logging/__init__.py:834(emit)
            4875    0.003    0.012 cocotb_profiling/cocotb/drivers/__init__.py:62(_cr_twiddler)
           58719    0.012    0.012 {method 'items' of 'dict' objects}
           25610    0.012    0.012 {method 'startswith' of 'str' objects}
             640    0.002    0.012 cocotb_profiling/cocotb/drivers/avalon.py:303(_driver_send)
           12206    0.012    0.012 {simulator.register_timed_callback}
           79830    0.012    0.012 {method 'pop' of 'dict' objects}
           17950    0.005    0.011 /usr/lib64/python2.7/inspect.py:51(ismodule)
            3590    0.005    0.011 /usr/lib64/python2.7/inspect.py:472(getmodule)
           71502    0.011    0.011 {chr}
           47988    0.011    0.011 cocotb_profiling/cocotb/binary.py:150(_adjust)
             598    0.001    0.011 cocotb_profiling/cocotb/drivers/__init__.py:236(_wait_for_nsignal)
          100677    0.010    0.010 {id}
              16    0.000    0.010 cocotb_profiling/cocotb/regression.py:186(execute)
              64    0.000    0.010 cocotb_profiling/cocotb/monitors/avalon.py:80(__init__)
           28720    0.007    0.010 /usr/lib64/python2.7/string.py:220(lower)
              64    0.000    0.010 cocotb_profiling/cocotb/monitors/__init__.py:152(__init__)
             640    0.001    0.010 cocotb_profiling/cocotb/drivers/__init__.py:154(_send)
           14360    0.005    0.010 /usr/lib64/python2.7/inspect.py:59(isclass)
             640    0.001    0.009 cocotb_profiling/cocotb/drivers/__init__.py:129(send)
           26823    0.009    0.009 /usr/lib64/python2.7/logging/__init__.py:1318(getEffectiveLevel)
           17950    0.005    0.009 /usr/lib64/python2.7/inspect.py:181(istraceback)
           25481    0.009    0.009 cocotb_profiling/cocotb/scheduler.py:163(save_write)
           45288    0.009    0.009 {method 'replace' of 'str' objects}
              64    0.000    0.008 cocotb_profiling/cocotb/drivers/__init__.py:200(__init__)
             447    0.000    0.008 /usr/lib64/python2.7/logging/__init__.py:712(format)
             447    0.001    0.008 cocotb_profiling/cocotb/log.py:198(format)
             447    0.001    0.008 /usr/lib64/python2.7/logging/__init__.py:1226(makeRecord)
             242    0.000    0.008 cocotb_profiling/cocotb/drivers/avalon.py:120(write)
            3028    0.008    0.008 {simulator.set_signal_val_str}
             640    0.002    0.008 cocotb_profiling/cocotb/monitors/__init__.py:123(_recv)
             447    0.004    0.007 /usr/lib64/python2.7/logging/__init__.py:242(__init__)
           14360    0.004    0.007 /usr/lib64/python2.7/inspect.py:67(ismethod)
           14360    0.004    0.007 /usr/lib64/python2.7/inspect.py:142(isfunction)
           17950    0.005    0.006 /usr/lib64/python2.7/inspect.py:191(isframe)
             447    0.003    0.006 cocotb_profiling/cocotb/log.py:162(_format)
             224    0.000    0.006 cocotb_profiling/cocotb/drivers/avalon.py:88(read)
              64    0.000    0.006 cocotb_profiling/cocotb/monitors/__init__.py:58(__init__)
            3590    0.002    0.006 /usr/lib64/python2.7/re.py:188(compile)
            3590    0.006    0.006 {method 'match' of '_sre.SRE_Pattern' objects}
            7180    0.006    0.006 {imp.get_suffixes}
           75216    0.006    0.006 {method 'disable' of '_lsprof.Profiler' objects}
             128    0.001    0.005 cocotb_profiling/cocotb/bus.py:52(__init__)
            1492    0.001    0.005 cocotb_profiling/cocotb/binary.py:95(get_value)
            1474    0.002    0.005 cocotb_profiling/cocotb/triggers.py:101(__del__)
              32    0.000    0.005 cocotb_profiling/cocotb/drivers/avalon.py:168(__init__)
              32    0.000    0.005 cocotb_profiling/cocotb/drivers/__init__.py:261(__init__)
             320    0.002    0.005 cocotb_profiling/cocotb/scoreboard.py:106(check_received_transaction)
              64    0.000    0.005 cocotb_profiling/cocotb/drivers/__init__.py:89(__init__)
           14360    0.004    0.005 /usr/lib64/python2.7/inspect.py:209(iscode)
            6160    0.005    0.005 {simulator.register_nextstep_callback}
              32    0.000    0.005 cocotb_profiling/cocotb/drivers/avalon.py:71(__init__)
            4622    0.004    0.004 cocotb_profiling/cocotb/triggers.py:445(prime)
             697    0.001    0.004 cocotb_profiling/examples/endian_swapper/tests/test_endian_swapper.py:47(stream_out_config_setter)
            3590    0.003    0.004 /usr/lib64/python2.7/re.py:226(_compile)
              32    0.000    0.004 cocotb_profiling/cocotb/drivers/avalon.py:53(__init__)
           24801    0.004    0.004 {method 'popitem' of 'dict' objects}
              32    0.000    0.004 cocotb_profiling/cocotb/scheduler.py:345(finish_test)
             500    0.001    0.003 cocotb_profiling/cocotb/generators/bit.py:43(bit_toggler)
             713    0.001    0.003 cocotb_profiling/cocotb/triggers.py:322(set)
            3590    0.002    0.003 <string>:8(__new__)
           17168    0.003    0.003 {method 'remove' of 'list' objects}
           28720    0.003    0.003 {method 'lower' of 'str' objects}
              73    0.000    0.003 cocotb_profiling/cocotb/drivers/avalon.py:84(_release_lock)
             447    0.000    0.003 /usr/lib64/python2.7/logging/__init__.py:827(flush)
              32    0.000    0.003 cocotb_profiling/cocotb/triggers.py:303(__call__)
            1531    0.001    0.003 cocotb_profiling/cocotb/triggers.py:66(__del__)
            1920    0.001    0.003 {getattr}
             306    0.001    0.003 cocotb_profiling/cocotb/drivers/__init__.py:277(_next_valids)
            1593    0.002    0.002 cocotb_profiling/cocotb/triggers.py:94(unprime)
              24    0.000    0.002 cocotb_profiling/cocotb/drivers/__init__.py:56(start)
             447    0.002    0.002 {method 'flush' of 'file' objects}
            1708    0.001    0.002 cocotb_profiling/cocotb/handle.py:70(__getattr__)
            8074    0.002    0.002 {method 'get' of 'dict' objects}
             160    0.000    0.002 cocotb_profiling/cocotb/triggers.py:312(__init__)
              73    0.000    0.002 cocotb_profiling/examples/endian_swapper/tests/test_endian_swapper.py:158(randomly_switch_config)
            6618    0.002    0.002 {min}
              96    0.000    0.002 cocotb_profiling/examples/endian_swapper/tests/test_endian_swapper.py:96(reset)
           23828    0.002    0.002 {method 'random' of '_random.Random' objects}
            7180    0.002    0.002 {max}
             407    0.000    0.002 cocotb_profiling/cocotb/generators/__init__.py:65(gaussian)
            3590    0.002    0.002 {built-in method __new__ of type object at 0x3bd318a0a0}
           23054    0.002    0.002 {ord}
              32    0.000    0.002 cocotb_profiling/cocotb/scheduler.py:352(cleanup)
            3590    0.001    0.001 /usr/lib64/python2.7/linecache.py:33(getlines)
             447    0.000    0.001 /usr/lib64/python2.7/logging/__init__.py:699(release)
             447    0.000    0.001 /usr/lib64/python2.7/logging/__init__.py:692(acquire)
             280    0.000    0.001 cocotb_profiling/cocotb/decorators.py:128(kill)
              21    0.000    0.001 cocotb_profiling/cocotb/handle.py:53(__init__)
             392    0.001    0.001 /usr/lib64/python2.7/random.py:558(gauss)
            1341    0.001    0.001 cocotb_profiling/cocotb/log.py:152(ljust)
              51    0.000    0.001 cocotb_profiling/cocotb/log.py:53(__init__)
              96    0.000    0.001 cocotb_profiling/cocotb/triggers.py:334(wait)
             578    0.001    0.001 cocotb_profiling/cocotb/generators/__init__.py:79(sine_wave)
            4591    0.001    0.001 {method 'enable' of '_lsprof.Profiler' objects}
             196    0.000    0.001 cocotb_profiling/cocotb/generators/bit.py:69(random_50_percent)
             280    0.000    0.001 cocotb_profiling/cocotb/scheduler.py:234(schedule_remove)
              96    0.000    0.001 cocotb_profiling/cocotb/triggers.py:295(__init__)
             447    0.000    0.001 /usr/lib64/python2.7/posixpath.py:95(splitext)
             115    0.000    0.001 cocotb_profiling/cocotb/drivers/__init__.py:170(_send_thread)
            1339    0.001    0.001 {range}
             447    0.001    0.001 /usr/lib64/python2.7/genericpath.py:85(_splitext)
             208    0.000    0.001 cocotb_profiling/cocotb/decorators.py:125(close)
              58    0.000    0.001 cocotb_profiling/cocotb/regression.py:227(_my_test)
            1909    0.001    0.001 {method 'rfind' of 'str' objects}
             208    0.000    0.001 {method 'close' of 'generator' objects}
             447    0.001    0.001 /usr/lib64/python2.7/logging/__init__.py:153(getLevelName)
              51    0.000    0.001 /usr/lib64/python2.7/logging/__init__.py:816(__init__)
             447    0.000    0.001 /usr/lib64/python2.7/posixpath.py:110(basename)
            3028    0.001    0.001 cocotb_profiling/cocotb/binary.py:137(get_binstr)
            1788    0.001    0.001 {method 'ljust' of 'str' objects}
             121    0.000    0.001 cocotb_profiling/cocotb/drivers/avalon.py:77(_acquire_lock)
              51    0.000    0.001 /usr/lib64/python2.7/logging/__init__.py:654(__init__)
             447    0.000    0.001 /usr/lib64/python2.7/posixpath.py:80(split)
            1474    0.000    0.000 {simulator.remove_callback}
             447    0.000    0.000 cocotb_profiling/cocotb/log.py:157(rjust)
             578    0.000    0.000 cocotb_profiling/cocotb/generators/__init__.py:94(<genexpr>)
             894    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:598(filter)
              56    0.000    0.000 cocotb_profiling/cocotb/drivers/__init__.py:302(set_valid_generator)
            1593    0.000    0.000 {simulator.deregister_callback}
            1739    0.000    0.000 cocotb_profiling/cocotb/triggers.py:52(unprime)
              32    0.000    0.000 cocotb_profiling/cocotb/scoreboard.py:61(result)
             153    0.000    0.000 cocotb_profiling/cocotb/triggers.py:136(prime)
              32    0.000    0.000 cocotb_profiling/cocotb/scoreboard.py:54(__init__)
             447    0.000    0.000 {simulator.get_sim_time}
             320    0.000    0.000 cocotb_profiling/examples/endian_swapper/tests/test_endian_swapper.py:91(model)
               1    0.000    0.000 /usr/lib64/python2.7/pstats.py:1(<module>)
             447    0.000    0.000 {method 'write' of 'file' objects}
             447    0.000    0.000 /usr/lib64/python2.7/threading.py:825(currentThread)
             384    0.000    0.000 cocotb_profiling/cocotb/log.py:142(__getattr__)
             447    0.000    0.000 {method 'split' of 'str' objects}
              32    0.000    0.000 cocotb_profiling/cocotb/result.py:56(__init__)
              51    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:1044(_fixupParents)
             750    0.000    0.000 {math.sin}
              51    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:635(_addHandlerRef)
              51    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:1270(addHandler)
             640    0.000    0.000 cocotb_profiling/cocotb/handle.py:171(__len__)
             196    0.000    0.000 {math.log}
             793    0.000    0.000 cocotb_profiling/cocotb/triggers.py:338(clear)
            1338    0.000    0.000 {abs}
              51    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:683(createLock)
              16    0.000    0.000 cocotb_profiling/cocotb/xunit_reporter.py:72(add_testcase)
             768    0.000    0.000 {setattr}
             415    0.000    0.000 {method 'rjust' of 'str' objects}
             447    0.000    0.000 /usr/lib64/python2.7/threading.py:681(name)
              64    0.000    0.000 /usr/lib64/python2.7/StringIO.py:54(__init__)
              51    0.000    0.000 /usr/lib64/python2.7/threading.py:100(RLock)
             447    0.000    0.000 {sys._getframe}
              16    0.000    0.000 /usr/lib64/python2.7/xml/etree/ElementTree.py:527(SubElement)
              51    0.000    0.000 /usr/lib64/python2.7/os.py:510(getenv)
             115    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:1112(setLevel)
             447    0.000    0.000 {method 'join' of 'str' objects}
             494    0.000    0.000 {time.time}
              96    0.000    0.000 cocotb_profiling/cocotb/triggers.py:299(prime)
               2    0.000    0.000 /usr/lib64/python2.7/linecache.py:68(updatecache)
               1    0.000    0.000 /usr/lib64/python2.7/functools.py:2(<module>)
              51    0.000    0.000 /usr/lib64/python2.7/threading.py:105(__init__)
             166    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:182(_checkLevel)
              51    0.000    0.000 /usr/lib64/python2.7/UserDict.py:58(get)
              32    0.000    0.000 cocotb_profiling/cocotb/scoreboard.py:84(add_interface)
              16    0.000    0.000 {repr}
               2    0.000    0.000 {method 'readlines' of 'file' objects}
             196    0.000    0.000 {math.cos}
             447    0.000    0.000 {posix.getpid}
              16    0.000    0.000 /usr/lib64/python2.7/xml/etree/ElementTree.py:224(makeelement)
              96    0.000    0.000 cocotb_profiling/cocotb/triggers.py:319(prime)
             128    0.000    0.000 {method 'copy' of 'dict' objects}
             211    0.000    0.000 cocotb_profiling/cocotb/generators/__init__.py:35(repeat)
              64    0.000    0.000 cocotb_profiling/cocotb/monitors/__init__.py:95(add_callback)
             352    0.000    0.000 {callable}
             128    0.000    0.000 {method 'iteritems' of 'dict' objects}
              51    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:578(__init__)
              21    0.000    0.000 {simulator.get_name_string}
             196    0.000    0.000 {math.sqrt}
              16    0.000    0.000 /usr/lib64/python2.7/xml/etree/ElementTree.py:207(__init__)
              32    0.000    0.000 cocotb_profiling/cocotb/drivers/__init__.py:51(__init__)
              16    0.000    0.000 cocotb_profiling/cocotb/regression.py:138(next_test)
              16    0.000    0.000 cocotb_profiling/cocotb/generators/bit.py:54(intermittent_single_cycles)
              16    0.000    0.000 cocotb_profiling/cocotb/generators/bit.py:82(wave)
              64    0.000    0.000 cocotb_profiling/cocotb/monitors/__init__.py:51(__init__)
              44    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:949(append)
              51    0.000    0.000 /usr/lib64/python2.7/threading.py:57(__init__)
              21    0.000    0.000 {simulator.get_type_string}
              32    0.000    0.000 {method 'update' of 'dict' objects}
              51    0.000    0.000 /usr/lib64/python2.7/UserDict.py:18(__getitem__)
              51    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:390(__init__)
              16    0.000    0.000 /usr/lib64/python2.7/xml/etree/ElementTree.py:300(append)
              51    0.000    0.000 /usr/lib64/python2.7/UserDict.py:70(__contains__)
              51    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:753(setFormatter)
               2    0.000    0.000 {open}
              51    0.000    0.000 {thread.allocate_lock}
              16    0.000    0.000 cocotb_profiling/cocotb/result.py:49(__init__)
              16    0.000    0.000 cocotb_profiling/cocotb/decorators.py:147(__nonzero__)
              16    0.000    0.000 cocotb_profiling/cocotb/scheduler.py:224(new_test)
               1    0.000    0.000 /usr/lib64/python2.7/pstats.py:32(Stats)
               2    0.000    0.000 {method 'endswith' of 'str' objects}
               1    0.000    0.000 /usr/lib64/python2.7/logging/__init__.py:942(__init__)
               1    0.000    0.000 /usr/lib64/python2.7/pstats.py:447(TupleComp)

chiggs · 2014-04-06T08:45:10Z

Endian swapper example makefile now has a "profile" target that will generate an SVG callgraph.

cmarqu · 2019-10-14T20:01:07Z

Related: https://github.com/andresdemski/cocotb-performance

cocotb crashes when running the mixed language example with Riviera-PRO, using a Verilog toplevel and the pre-built binary wheels (manylinux2014, built on CentOS7). Valgrind reports ``` COUT: ==6174== Invalid free() / delete / delete[] / realloc() COUT: ==6174== at 0xC78271B: operator delete(void*) (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so) COUT: ==6174== by 0x1CE1AC80: std::string::assign(std::string const&) (in /home/philipp/src/cocotb-riviera-debug-3078-binary/.direnv/python-3.10.7/lib/python3.10/site-packages/cocotb/libs/libgpilog.so) COUT: ==6174== by 0x1CDE56C6: GpiObjHdl::initialise(std::string const&, std::string const&) (GpiCbHdl.cpp:74) COUT: ==6174== by 0x1CE3D587: VhpiObjHdl::initialise(std::string const&, std::string const&) (VhpiCbHdl.cpp:258) COUT: ==6174== by 0x1CE46932: VhpiImpl::create_gpi_obj_from_handle(unsigned int*, std::string&, std::string&) (VhpiImpl.cpp:462) COUT: ==6174== by 0x1CE470E5: VhpiImpl::native_check_create(std::string&, GpiObjHdl*) (VhpiImpl.cpp:575) COUT: ==6174== by 0x1CDE6E1E: gpi_get_handle_by_name_(GpiObjHdl*, std::string, GpiImplInterface*) (GpiCommon.cpp:297) COUT: ==6174== by 0x1CDE711C: gpi_get_handle_by_name (GpiCommon.cpp:339) COUT: ==6174== by 0x14BF9595: get_handle_by_name((anonymous namespace)::gpi_hdl_Object<GpiObjHdl*>*, _object*) (simulatormodule.cpp:681) COUT: ==6174== by 0x1CF7351A: ??? (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== by 0x1CF77976: _PyEval_EvalFrameDefault (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== by 0x1CF76492: ??? (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== Address 0xed71320 is 0 bytes inside data symbol "_ZNSs4_Rep20_S_empty_rep_storageE" COUT: ==6174== ``` A GDB backtrace looks identical, with slightly more symbol information: ``` #0 __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44 #1 0x00007fe519095893 in __pthread_kill_internal (signo=6, threadid=<optimized out>) at pthread_kill.c:78 cocotb#2 0x00007fe519042846 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26 cocotb#3 0x00007fe51902b81c in __GI_abort () at abort.c:79 cocotb#4 0x00007fe5190889ae in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7fe5191b144f "%s\n") at ../sysdeps/posix/libc_fatal.c:155 cocotb#5 0x00007fe5190a014c in malloc_printerr (str=str@entry=0x7fe5191af0a9 "free(): invalid pointer") at malloc.c:5660 cocotb#6 0x00007fe5190a211c in _int_free (av=<optimized out>, p=<optimized out>, have_lock=have_lock@entry=0) at malloc.c:4435 cocotb#7 0x00007fe5190a4b13 in __GI___libc_free (mem=<optimized out>) at malloc.c:3385 cocotb#8 0x00007fe514f9ea91 in std::string::assign(std::string const&) () from /home/philipp/src/cocotb-riviera-debug-3078-binary/.direnv/python-3.10.7/lib64/python3.10/site-packages/cocotb/libs/libgpilog.so cocotb#9 0x00007fe514fbe875 in std::string::operator= (__str=..., this=0x7fe50e0d2d58) at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/basic_string.h:3726 cocotb#10 GpiObjHdl::initialise (this=0x7fe50e0d2d30, name=..., fq_name=...) at cocotb/share/lib/gpi/GpiCbHdl.cpp:74 cocotb#11 0x00007fe514f761b3 in VhpiImpl::create_gpi_obj_from_handle (this=0x7fe50c17df00, new_hdl=<optimized out>, name=..., fq_name=...) at cocotb/share/lib/vhpi/VhpiImpl.cpp:462 cocotb#12 0x00007fe514f796cb in VhpiImpl::native_check_create (this=0x7fe50c17df00, name=..., parent=<optimized out>) at cocotb/share/lib/vhpi/VhpiImpl.cpp:575 cocotb#13 0x00007fe514fc1955 in gpi_get_handle_by_name_ (skip_impl=0x0, name=..., parent=0x7fe50c0b9ea0) at cocotb/share/lib/gpi/GpiCommon.cpp:297 cocotb#14 gpi_get_handle_by_name_ (parent=0x7fe50c0b9ea0, name=..., skip_impl=0x0) at cocotb/share/lib/gpi/GpiCommon.cpp:260 cocotb#15 0x00007fe514fc1b01 in gpi_get_handle_by_name (base=0x7fe50c0b9ea0, name=0x7fe5001192a0 "i_swapper_vhdl") at cocotb/share/lib/gpi/GpiCommon.cpp:339 cocotb#16 0x00007fe5141136c6 in get_handle_by_name (self=0x7fe5000c07f0, args=<optimized out>) at cocotb/share/lib/simulator/simulatormodule.cpp:681 cocotb#17 0x00007fe51471d51b in method_vectorcall_VARARGS (func=<method_descriptor at remote 0x7fe514193970>, args=0x7fe5000f4ee8, nargsf=<optimized out>, kwnames=0x0) at Objects/descrobject.c:311 ``` This Valgrind report indicates that `free()` is called on an object which isn't intended ot be freed, and that's `std::basic_string<char, std::char_traits<char>, std::allocator<char>>::_Rep::_S_empty_rep_storage` in this case. This symbol within libstdc++ is documented as (https://github.com/gcc-mirror/gcc/blob/releases/gcc-10/libstdc++-v3/include/bits/basic_string.h#L3230): ``` // The following storage is init'd to 0 by the linker, resulting // (carefully) in an empty string with one reference. static size_type _S_empty_rep_storage[]; ``` What seems to happen is that when we call ``` int GpiObjHdl::initialise(const std::string &name, const std::string &fq_name) { m_name = name; ... } ``` `m_name` gets free()'d after it got the new `name` assigned. Since `m_name` was empty/unset before, free() tries to access `_S_empty_rep_storage`. Assigning an explicit default value to `m_name` works around the problem nicely. That being said, it's unclear why free() is getting invoked on that symbol at all. It's also unclear why the same code only causes issues for a single mixed signal testcase. Finding out is unlikely to be trivial: cocotb wheels link (parts of) a static libstdc++ from RHEL7, while Riviera-PRO comes with its own dynamically-linked libstdc++. It's my hope that the workaround in this commit serves us long enough before it becomes a problem in itself. Fixes cocotb#3078

cocotb crashes when running the mixed language example with Riviera-PRO, using a Verilog toplevel and the pre-built binary wheels (manylinux2014, built on CentOS7). Valgrind reports ``` COUT: ==6174== Invalid free() / delete / delete[] / realloc() COUT: ==6174== at 0xC78271B: operator delete(void*) (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so) COUT: ==6174== by 0x1CE1AC80: std::string::assign(std::string const&) (in /home/philipp/src/cocotb-riviera-debug-3078-binary/.direnv/python-3.10.7/lib/python3.10/site-packages/cocotb/libs/libgpilog.so) COUT: ==6174== by 0x1CDE56C6: GpiObjHdl::initialise(std::string const&, std::string const&) (GpiCbHdl.cpp:74) COUT: ==6174== by 0x1CE3D587: VhpiObjHdl::initialise(std::string const&, std::string const&) (VhpiCbHdl.cpp:258) COUT: ==6174== by 0x1CE46932: VhpiImpl::create_gpi_obj_from_handle(unsigned int*, std::string&, std::string&) (VhpiImpl.cpp:462) COUT: ==6174== by 0x1CE470E5: VhpiImpl::native_check_create(std::string&, GpiObjHdl*) (VhpiImpl.cpp:575) COUT: ==6174== by 0x1CDE6E1E: gpi_get_handle_by_name_(GpiObjHdl*, std::string, GpiImplInterface*) (GpiCommon.cpp:297) COUT: ==6174== by 0x1CDE711C: gpi_get_handle_by_name (GpiCommon.cpp:339) COUT: ==6174== by 0x14BF9595: get_handle_by_name((anonymous namespace)::gpi_hdl_Object<GpiObjHdl*>*, _object*) (simulatormodule.cpp:681) COUT: ==6174== by 0x1CF7351A: ??? (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== by 0x1CF77976: _PyEval_EvalFrameDefault (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== by 0x1CF76492: ??? (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== Address 0xed71320 is 0 bytes inside data symbol "_ZNSs4_Rep20_S_empty_rep_storageE" COUT: ==6174== ``` A GDB backtrace looks identical, with slightly more symbol information: ``` #0 __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44 #1 0x00007fe519095893 in __pthread_kill_internal (signo=6, threadid=<optimized out>) at pthread_kill.c:78 #2 0x00007fe519042846 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26 #3 0x00007fe51902b81c in __GI_abort () at abort.c:79 #4 0x00007fe5190889ae in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7fe5191b144f "%s\n") at ../sysdeps/posix/libc_fatal.c:155 #5 0x00007fe5190a014c in malloc_printerr (str=str@entry=0x7fe5191af0a9 "free(): invalid pointer") at malloc.c:5660 #6 0x00007fe5190a211c in _int_free (av=<optimized out>, p=<optimized out>, have_lock=have_lock@entry=0) at malloc.c:4435 #7 0x00007fe5190a4b13 in __GI___libc_free (mem=<optimized out>) at malloc.c:3385 #8 0x00007fe514f9ea91 in std::string::assign(std::string const&) () from /home/philipp/src/cocotb-riviera-debug-3078-binary/.direnv/python-3.10.7/lib64/python3.10/site-packages/cocotb/libs/libgpilog.so #9 0x00007fe514fbe875 in std::string::operator= (__str=..., this=0x7fe50e0d2d58) at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/basic_string.h:3726 #10 GpiObjHdl::initialise (this=0x7fe50e0d2d30, name=..., fq_name=...) at cocotb/share/lib/gpi/GpiCbHdl.cpp:74 #11 0x00007fe514f761b3 in VhpiImpl::create_gpi_obj_from_handle (this=0x7fe50c17df00, new_hdl=<optimized out>, name=..., fq_name=...) at cocotb/share/lib/vhpi/VhpiImpl.cpp:462 #12 0x00007fe514f796cb in VhpiImpl::native_check_create (this=0x7fe50c17df00, name=..., parent=<optimized out>) at cocotb/share/lib/vhpi/VhpiImpl.cpp:575 #13 0x00007fe514fc1955 in gpi_get_handle_by_name_ (skip_impl=0x0, name=..., parent=0x7fe50c0b9ea0) at cocotb/share/lib/gpi/GpiCommon.cpp:297 #14 gpi_get_handle_by_name_ (parent=0x7fe50c0b9ea0, name=..., skip_impl=0x0) at cocotb/share/lib/gpi/GpiCommon.cpp:260 #15 0x00007fe514fc1b01 in gpi_get_handle_by_name (base=0x7fe50c0b9ea0, name=0x7fe5001192a0 "i_swapper_vhdl") at cocotb/share/lib/gpi/GpiCommon.cpp:339 #16 0x00007fe5141136c6 in get_handle_by_name (self=0x7fe5000c07f0, args=<optimized out>) at cocotb/share/lib/simulator/simulatormodule.cpp:681 #17 0x00007fe51471d51b in method_vectorcall_VARARGS (func=<method_descriptor at remote 0x7fe514193970>, args=0x7fe5000f4ee8, nargsf=<optimized out>, kwnames=0x0) at Objects/descrobject.c:311 ``` This Valgrind report indicates that `free()` is called on an object which isn't intended ot be freed, and that's `std::basic_string<char, std::char_traits<char>, std::allocator<char>>::_Rep::_S_empty_rep_storage` in this case. This symbol within libstdc++ is documented as (https://github.com/gcc-mirror/gcc/blob/releases/gcc-10/libstdc++-v3/include/bits/basic_string.h#L3230): ``` // The following storage is init'd to 0 by the linker, resulting // (carefully) in an empty string with one reference. static size_type _S_empty_rep_storage[]; ``` What seems to happen is that when we call ``` int GpiObjHdl::initialise(const std::string &name, const std::string &fq_name) { m_name = name; ... } ``` `m_name` gets free()'d after it got the new `name` assigned. Since `m_name` was empty/unset before, free() tries to access `_S_empty_rep_storage`. Assigning an explicit default value to `m_name` works around the problem nicely. That being said, it's unclear why free() is getting invoked on that symbol at all. It's also unclear why the same code only causes issues for a single mixed signal testcase. Finding out is unlikely to be trivial: cocotb wheels link (parts of) a static libstdc++ from RHEL7, while Riviera-PRO comes with its own dynamically-linked libstdc++. It's my hope that the workaround in this commit serves us long enough before it becomes a problem in itself. Fixes #3078

cocotb crashes when running the mixed language example with Riviera-PRO, using a Verilog toplevel and the pre-built binary wheels (manylinux2014, built on CentOS7). Valgrind reports ``` COUT: ==6174== Invalid free() / delete / delete[] / realloc() COUT: ==6174== at 0xC78271B: operator delete(void*) (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so) COUT: ==6174== by 0x1CE1AC80: std::string::assign(std::string const&) (in /home/philipp/src/cocotb-riviera-debug-3078-binary/.direnv/python-3.10.7/lib/python3.10/site-packages/cocotb/libs/libgpilog.so) COUT: ==6174== by 0x1CDE56C6: GpiObjHdl::initialise(std::string const&, std::string const&) (GpiCbHdl.cpp:74) COUT: ==6174== by 0x1CE3D587: VhpiObjHdl::initialise(std::string const&, std::string const&) (VhpiCbHdl.cpp:258) COUT: ==6174== by 0x1CE46932: VhpiImpl::create_gpi_obj_from_handle(unsigned int*, std::string&, std::string&) (VhpiImpl.cpp:462) COUT: ==6174== by 0x1CE470E5: VhpiImpl::native_check_create(std::string&, GpiObjHdl*) (VhpiImpl.cpp:575) COUT: ==6174== by 0x1CDE6E1E: gpi_get_handle_by_name_(GpiObjHdl*, std::string, GpiImplInterface*) (GpiCommon.cpp:297) COUT: ==6174== by 0x1CDE711C: gpi_get_handle_by_name (GpiCommon.cpp:339) COUT: ==6174== by 0x14BF9595: get_handle_by_name((anonymous namespace)::gpi_hdl_Object<GpiObjHdl*>*, _object*) (simulatormodule.cpp:681) COUT: ==6174== by 0x1CF7351A: ??? (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== by 0x1CF77976: _PyEval_EvalFrameDefault (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== by 0x1CF76492: ??? (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== Address 0xed71320 is 0 bytes inside data symbol "_ZNSs4_Rep20_S_empty_rep_storageE" COUT: ==6174== ``` A GDB backtrace looks identical, with slightly more symbol information: ``` #0 __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44 #1 0x00007fe519095893 in __pthread_kill_internal (signo=6, threadid=<optimized out>) at pthread_kill.c:78 cocotb#2 0x00007fe519042846 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26 cocotb#3 0x00007fe51902b81c in __GI_abort () at abort.c:79 cocotb#4 0x00007fe5190889ae in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7fe5191b144f "%s\n") at ../sysdeps/posix/libc_fatal.c:155 cocotb#5 0x00007fe5190a014c in malloc_printerr (str=str@entry=0x7fe5191af0a9 "free(): invalid pointer") at malloc.c:5660 cocotb#6 0x00007fe5190a211c in _int_free (av=<optimized out>, p=<optimized out>, have_lock=have_lock@entry=0) at malloc.c:4435 cocotb#7 0x00007fe5190a4b13 in __GI___libc_free (mem=<optimized out>) at malloc.c:3385 cocotb#8 0x00007fe514f9ea91 in std::string::assign(std::string const&) () from /home/philipp/src/cocotb-riviera-debug-3078-binary/.direnv/python-3.10.7/lib64/python3.10/site-packages/cocotb/libs/libgpilog.so cocotb#9 0x00007fe514fbe875 in std::string::operator= (__str=..., this=0x7fe50e0d2d58) at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/basic_string.h:3726 cocotb#10 GpiObjHdl::initialise (this=0x7fe50e0d2d30, name=..., fq_name=...) at cocotb/share/lib/gpi/GpiCbHdl.cpp:74 cocotb#11 0x00007fe514f761b3 in VhpiImpl::create_gpi_obj_from_handle (this=0x7fe50c17df00, new_hdl=<optimized out>, name=..., fq_name=...) at cocotb/share/lib/vhpi/VhpiImpl.cpp:462 cocotb#12 0x00007fe514f796cb in VhpiImpl::native_check_create (this=0x7fe50c17df00, name=..., parent=<optimized out>) at cocotb/share/lib/vhpi/VhpiImpl.cpp:575 cocotb#13 0x00007fe514fc1955 in gpi_get_handle_by_name_ (skip_impl=0x0, name=..., parent=0x7fe50c0b9ea0) at cocotb/share/lib/gpi/GpiCommon.cpp:297 cocotb#14 gpi_get_handle_by_name_ (parent=0x7fe50c0b9ea0, name=..., skip_impl=0x0) at cocotb/share/lib/gpi/GpiCommon.cpp:260 cocotb#15 0x00007fe514fc1b01 in gpi_get_handle_by_name (base=0x7fe50c0b9ea0, name=0x7fe5001192a0 "i_swapper_vhdl") at cocotb/share/lib/gpi/GpiCommon.cpp:339 cocotb#16 0x00007fe5141136c6 in get_handle_by_name (self=0x7fe5000c07f0, args=<optimized out>) at cocotb/share/lib/simulator/simulatormodule.cpp:681 cocotb#17 0x00007fe51471d51b in method_vectorcall_VARARGS (func=<method_descriptor at remote 0x7fe514193970>, args=0x7fe5000f4ee8, nargsf=<optimized out>, kwnames=0x0) at Objects/descrobject.c:311 ``` This Valgrind report indicates that `free()` is called on an object which isn't intended ot be freed, and that's `std::basic_string<char, std::char_traits<char>, std::allocator<char>>::_Rep::_S_empty_rep_storage` in this case. This symbol within libstdc++ is documented as (https://github.com/gcc-mirror/gcc/blob/releases/gcc-10/libstdc++-v3/include/bits/basic_string.h#L3230): ``` // The following storage is init'd to 0 by the linker, resulting // (carefully) in an empty string with one reference. static size_type _S_empty_rep_storage[]; ``` What seems to happen is that when we call ``` int GpiObjHdl::initialise(const std::string &name, const std::string &fq_name) { m_name = name; ... } ``` `m_name` gets free()'d after it got the new `name` assigned. Since `m_name` was empty/unset before, free() tries to access `_S_empty_rep_storage`. Assigning an explicit default value to `m_name` works around the problem nicely. That being said, it's unclear why free() is getting invoked on that symbol at all. It's also unclear why the same code only causes issues for a single mixed signal testcase. Finding out is unlikely to be trivial: cocotb wheels link (parts of) a static libstdc++ from RHEL7, while Riviera-PRO comes with its own dynamically-linked libstdc++. It's my hope that the workaround in this commit serves us long enough before it becomes a problem in itself. Fixes cocotb#3078

cocotb crashes when running the mixed language example with Riviera-PRO, using a Verilog toplevel and the pre-built binary wheels (manylinux2014, built on CentOS7). Valgrind reports ``` COUT: ==6174== Invalid free() / delete / delete[] / realloc() COUT: ==6174== at 0xC78271B: operator delete(void*) (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so) COUT: ==6174== by 0x1CE1AC80: std::string::assign(std::string const&) (in /home/philipp/src/cocotb-riviera-debug-3078-binary/.direnv/python-3.10.7/lib/python3.10/site-packages/cocotb/libs/libgpilog.so) COUT: ==6174== by 0x1CDE56C6: GpiObjHdl::initialise(std::string const&, std::string const&) (GpiCbHdl.cpp:74) COUT: ==6174== by 0x1CE3D587: VhpiObjHdl::initialise(std::string const&, std::string const&) (VhpiCbHdl.cpp:258) COUT: ==6174== by 0x1CE46932: VhpiImpl::create_gpi_obj_from_handle(unsigned int*, std::string&, std::string&) (VhpiImpl.cpp:462) COUT: ==6174== by 0x1CE470E5: VhpiImpl::native_check_create(std::string&, GpiObjHdl*) (VhpiImpl.cpp:575) COUT: ==6174== by 0x1CDE6E1E: gpi_get_handle_by_name_(GpiObjHdl*, std::string, GpiImplInterface*) (GpiCommon.cpp:297) COUT: ==6174== by 0x1CDE711C: gpi_get_handle_by_name (GpiCommon.cpp:339) COUT: ==6174== by 0x14BF9595: get_handle_by_name((anonymous namespace)::gpi_hdl_Object<GpiObjHdl*>*, _object*) (simulatormodule.cpp:681) COUT: ==6174== by 0x1CF7351A: ??? (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== by 0x1CF77976: _PyEval_EvalFrameDefault (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== by 0x1CF76492: ??? (in /usr/lib64/libpython3.10.so.1.0) COUT: ==6174== Address 0xed71320 is 0 bytes inside data symbol "_ZNSs4_Rep20_S_empty_rep_storageE" COUT: ==6174== ``` A GDB backtrace looks identical, with slightly more symbol information: ``` #0 __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44 #1 0x00007fe519095893 in __pthread_kill_internal (signo=6, threadid=<optimized out>) at pthread_kill.c:78 #2 0x00007fe519042846 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26 #3 0x00007fe51902b81c in __GI_abort () at abort.c:79 #4 0x00007fe5190889ae in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7fe5191b144f "%s\n") at ../sysdeps/posix/libc_fatal.c:155 #5 0x00007fe5190a014c in malloc_printerr (str=str@entry=0x7fe5191af0a9 "free(): invalid pointer") at malloc.c:5660 #6 0x00007fe5190a211c in _int_free (av=<optimized out>, p=<optimized out>, have_lock=have_lock@entry=0) at malloc.c:4435 #7 0x00007fe5190a4b13 in __GI___libc_free (mem=<optimized out>) at malloc.c:3385 #8 0x00007fe514f9ea91 in std::string::assign(std::string const&) () from /home/philipp/src/cocotb-riviera-debug-3078-binary/.direnv/python-3.10.7/lib64/python3.10/site-packages/cocotb/libs/libgpilog.so #9 0x00007fe514fbe875 in std::string::operator= (__str=..., this=0x7fe50e0d2d58) at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/basic_string.h:3726 #10 GpiObjHdl::initialise (this=0x7fe50e0d2d30, name=..., fq_name=...) at cocotb/share/lib/gpi/GpiCbHdl.cpp:74 #11 0x00007fe514f761b3 in VhpiImpl::create_gpi_obj_from_handle (this=0x7fe50c17df00, new_hdl=<optimized out>, name=..., fq_name=...) at cocotb/share/lib/vhpi/VhpiImpl.cpp:462 #12 0x00007fe514f796cb in VhpiImpl::native_check_create (this=0x7fe50c17df00, name=..., parent=<optimized out>) at cocotb/share/lib/vhpi/VhpiImpl.cpp:575 #13 0x00007fe514fc1955 in gpi_get_handle_by_name_ (skip_impl=0x0, name=..., parent=0x7fe50c0b9ea0) at cocotb/share/lib/gpi/GpiCommon.cpp:297 #14 gpi_get_handle_by_name_ (parent=0x7fe50c0b9ea0, name=..., skip_impl=0x0) at cocotb/share/lib/gpi/GpiCommon.cpp:260 #15 0x00007fe514fc1b01 in gpi_get_handle_by_name (base=0x7fe50c0b9ea0, name=0x7fe5001192a0 "i_swapper_vhdl") at cocotb/share/lib/gpi/GpiCommon.cpp:339 #16 0x00007fe5141136c6 in get_handle_by_name (self=0x7fe5000c07f0, args=<optimized out>) at cocotb/share/lib/simulator/simulatormodule.cpp:681 #17 0x00007fe51471d51b in method_vectorcall_VARARGS (func=<method_descriptor at remote 0x7fe514193970>, args=0x7fe5000f4ee8, nargsf=<optimized out>, kwnames=0x0) at Objects/descrobject.c:311 ``` This Valgrind report indicates that `free()` is called on an object which isn't intended ot be freed, and that's `std::basic_string<char, std::char_traits<char>, std::allocator<char>>::_Rep::_S_empty_rep_storage` in this case. This symbol within libstdc++ is documented as (https://github.com/gcc-mirror/gcc/blob/releases/gcc-10/libstdc++-v3/include/bits/basic_string.h#L3230): ``` // The following storage is init'd to 0 by the linker, resulting // (carefully) in an empty string with one reference. static size_type _S_empty_rep_storage[]; ``` What seems to happen is that when we call ``` int GpiObjHdl::initialise(const std::string &name, const std::string &fq_name) { m_name = name; ... } ``` `m_name` gets free()'d after it got the new `name` assigned. Since `m_name` was empty/unset before, free() tries to access `_S_empty_rep_storage`. Assigning an explicit default value to `m_name` works around the problem nicely. That being said, it's unclear why free() is getting invoked on that symbol at all. It's also unclear why the same code only causes issues for a single mixed signal testcase. Finding out is unlikely to be trivial: cocotb wheels link (parts of) a static libstdc++ from RHEL7, while Riviera-PRO comes with its own dynamically-linked libstdc++. It's my hope that the workaround in this commit serves us long enough before it becomes a problem in itself. Fixes #3078

GordonMcGregor mentioned this issue Jul 9, 2013

VCS core dump #51

Closed

stuarthodgson mentioned this issue Jul 10, 2013

Python threading exception #53

Closed

chiggs added this to the 0.5 milestone Mar 20, 2014

chiggs mentioned this issue Mar 23, 2014

Scheduler needs an overhaul #121

Closed

stuarthodgson removed this from the 1.0 milestone Jul 20, 2015

chevillotn mentioned this issue Jan 7, 2016

Questasim stuck in endless loop when more python code is added #376

Open

kleon1024 mentioned this issue Apr 2, 2019

Co-simulation encounters No context available error #891

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Profiling capabilities #15

Profiling capabilities #15

chiggs commented Jun 20, 2013

chiggs commented Mar 18, 2014

chiggs commented Apr 6, 2014

cmarqu commented Oct 14, 2019

Profiling capabilities #15

Profiling capabilities #15

Comments

chiggs commented Jun 20, 2013

chiggs commented Mar 18, 2014

chiggs commented Apr 6, 2014

cmarqu commented Oct 14, 2019