Re: Exception in p4p

[Michael Davidsaver via Core-talk <core-talk at aps.anl.gov>]

> 2022-12-14T13:14:03.905922950 CRIT pvxs.tcp.io Server Error while processing cmd 0x0a: vector::_M_range_check

This is definitely a bug with PVXS.

The stack trace shows "libpvxs.so.1.1", can you confirm that
you are testing with the released PVXS 1.1.0?


> Does anybody have a clue or hint ?

The first thing to do is to enable full debug logging.

> export PVXS_LOG=*=DEBUG

https://mdavidsaver.github.io/pvxs/util.html#logging


Next...

Can you package this test into a form which I can run
against a soft motor IOC?  eg. where does AxisTestUtil
come from?


Can you collect a packet capture?

https://mdavidsaver.github.io/pvxs/details.html#packet-capture


On 12/14/22 04:33, Torsten Bögershausen via Core-talk wrote:
> Hej All,
>
> I am seeing some unexpected exceptions when running
> tests via pytest and p4p.
>
> After a lot of digging, the exception problem could be
> cooked down into 2 test cases,
> reading the .RBV and the .CNEN field of a motorRecord,
> before closing the connection:
>
> class Test(unittest.TestCase):
>      url_string = os.getenv("TESTEDMOTORAXIS")
>      print(f"url_string={url_string}")
>
>      axisTestUtil = AxisTestUtil(url_string, log_debug=True)
>      axisComm = axisTestUtil.getAxis()
>
>      # Read variables (floating point)
>      def test_TC_01101(self):
>          tc_no = "01101"
>          rbv = float(self.axisComm.getActPos(tc_no=tc_no))
>          print(
>              f"{datetime.datetime.now():%Y-%m-%d %H:%M:%S} {filnam}:{lineno()} {tc_no} rbv={rbv}"
>          )
>
>      # Read variables (boolean)
>      def test_TC_01102(self):
>          tc_no = "01102"
>          enabled = self.axisComm.getEnabledStatus(tc_no=tc_no)
>          print(
>              f"{datetime.datetime.now():%Y-%m-%d %H:%M:%S} {filnam}:{lineno()} {tc_no} enabled={enabled}"
>          )
>
>      def teardown_class(self):
>          tc_no = "011999"
>          print(
>              f"{datetime.datetime.now():%Y-%m-%d %H:%M:%S} {filnam}:{lineno()} {tc_no} teardown_class"
>          )
>          self.axisTestUtil.close()
>
>
> The somewhat shortened log seems to indicate that the exception happens
> before the shutdown.
> And the problem is the both under MacOs with python3.9 and
> Debian with python3.7
>
>
>
> platform linux -- Python 3.7.3, pytest-7.2.0, pluggy-1.0.0
> collecting ... url_string=pva://IOC:m1
> collected 2 items
>
> Does anybody have a clue or hint ?
> Thanks
> /Torsten
>
> 011_Basic_Communication.py 2022-12-14 13:14:03 ConnP4P get IOC:m1.RBV
> 2022-12-14 13:14:03 ConnP4P get IOC:m1.RBV ret=Wed Dec 14 13:10:50 2022 100.11 time=0.01
> 2022-12-14 13:14:03 011:39 01101 rbv=100.11
> .2022-12-14 13:14:03 ConnP4P get IOC:m1.CNEN
> 2022-12-14T13:14:03.905922950 CRIT pvxs.tcp.io Server Error while processing cmd 0x0a: vector::_M_range_check
> Dumping a stack trace of thread 'PVXCTCP':
> [    0x7f4fc8afeb6b]: ...python3.7/site-packages/p4p/../epicscorelibs/lib/libCom.so.7.0.7.99.0(epicsStackTrace+0x4b)
> [    0x7f4fc8deb4b5]: ...python3.7/site-packages/p4p/../pvxslibs/lib/libpvxs.so.1.1(_ZN4pvxs6detail11_log_printfEjPKcz+0xa5)
> [    0x7f4fc8dadcf6]: ...python3.7/site-packages/p4p/../pvxslibs/lib/libpvxs.so.1.1(_ZN4pvxs4impl8ConnBase7bevReadEv+0x696)
> [    0x7f4fc8dae031]: ...python3.7/site-packages/p4p/../pvxslibs/lib/libpvxs.so.1.1(_ZN4pvxs4impl8ConnBase8bevReadSEP11buffereventPv+0x21)
> [    0x7f4fc871e432]: ...python3.7/site-packages/p4p/../pvxslibs/lib/./libevent_core.so.2.2.0(bufferevent_run_deferred_callbacks_locked+0x82)
> [    0x7f4fc8717db6]: ...python3.7/site-packages/p4p/../pvxslibs/lib/./libevent_core.so.2.2.0(event_process_active_single_queue.isra.33+0x446)
> [    0x7f4fc871875f]: ...python3.7/site-packages/p4p/../pvxslibs/lib/./libevent_core.so.2.2.0(event_base_loop+0x49f)
> [    0x7f4fc8e21e00]: ...python3.7/site-packages/p4p/../pvxslibs/lib/libpvxs.so.1.1(_ZN4pvxs4impl6evbase3Pvt3runEv+0x160)
> [    0x7f4fc8b17f69]: ...python3.7/site-packages/p4p/../epicscorelibs/lib/libCom.so.7.0.7.99.0(epicsThreadCallEntryPoint+0x69)
> [    0x7f4fc8b038da]: ...python3.7/site-packages/p4p/../epicscorelibs/lib/libCom.so.7.0.7.99.0(start_routine+0xda)
> [    0x7f4fcb68bfa3]: /lib/x86_64-linux-gnu/libpthread.so.0(start_thread+0xf3)
> [    0x7f4fcb3d306f]: /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)
> 2022-12-14 13:14:04 ConnP4P get IOC:m1.CNEN ret=Enable time=1.01
> 2022-12-14 13:14:04 011:47 01102 enabled=True
> .2022-12-14 13:14:04 011:53 011999 teardown_class
> 2022-12-14 13:14:04 TestUtil close() begin
> 2022-12-14 13:14:04 TestUtil close() done