pvxs icon indicating copy to clipboard operation
pvxs copied to clipboard

pvxs for RTEMS6?

Open hjunkes opened this issue 4 months ago • 24 comments

Can I build pvxs for RTEMS? I'm missing libevent2 there.

hjunkes avatar Sep 17 '25 14:09 hjunkes

Yes. RTEMS 5 is supported. There is a GHA job:

https://github.com/epics-base/pvxs/blob/021bcb4a06224ed8c0e8184b3a89c015830e2e3b/.github/workflows/ci-scripts-build.yml#L83-L88

I think a recipe to have rtems-source-builder build libevent would be a useful addition. Until then, you can build the bundled libevent as described in my documentation.

git clone --recursive https://github.com/epics-base/pvxs.git
...
make -C pvxs/bundle libevent.RTEMS-<yourbsp>

mdavidsaver avatar Sep 17 '25 15:09 mdavidsaver

Thanks for the quick reply. It's probably because I have no experience with cmake. I need to do a little more 'research' here.

rtems@rtems-dev:~/MVME2500_6/EPICS/epics-support$ make -C pvxs/bundle libevent.RTEMS-qoriq_e500
make: Entering directory '/home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle'
mkdir -p /home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/O.RTEMS-qoriq_e500
make -C /home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/O.RTEMS-qoriq_e500 -f /home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/Makefile TOP=../.. T_A=RTEMS-qoriq_e500 libevent.RTEMS-qoriq_e500
make[1]: Entering directory '/home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/O.RTEMS-qoriq_e500'
cmake  -DCMAKE_POLICY_VERSION_MINIMUM=3.10 -DCMAKE_INSTALL_PREFIX:PATH="/home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/usr/RTEMS-qoriq_e500" -DEVENT__DISABLE_OPENSSL=ON -DEVENT__DISABLE_MBEDTLS=ON -DEVENT__DISABLE_REGRESS=ON -DEVENT__DISABLE_SAMPLES=ON -DEVENT__DISABLE_TESTS=ON -DEVENT__DISABLE_BENCHMARK=ON -DCMAKE_MACOSX_RPATH=ON -DCMAKE_SKIP_INSTALL_RPATH=OFF -DCMAKE_MODULE_PATH:DIR="/home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/cmake" -DCMAKE_MAKE_PROGRAM="make" -DCMAKE_BUILD_TYPE=RELEASE -DEVENT__LIBRARY_TYPE=STATIC -DCMAKE_TOOLCHAIN_FILE="RTEMS-qoriq_e500.cmake" ../libevent
-- The C compiler identification is GNU 13.3.0
-- Detecting C compiler ABI info
-- Detecting C compiler ABI info - failed
-- Check for working C compiler: /home/rtems/MVME2500_6/rtems/6/bin/powerpc-rtems6-gcc
-- Check for working C compiler: /home/rtems/MVME2500_6/rtems/6/bin/powerpc-rtems6-gcc - broken
CMake Error at /usr/share/cmake-3.18/Modules/CMakeTestCCompiler.cmake:66 (message):
  The C compiler

    "/home/rtems/MVME2500_6/rtems/6/bin/powerpc-rtems6-gcc"

  is not able to compile a simple test program.

  It fails with the following output:

    Change Dir: /home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/O.RTEMS-qoriq_e500/CMakeFiles/CMakeTmp

    Run Build Command(s):make cmTC_6e0a4/fast && make[2]: Entering directory '/home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/O.RTEMS-qoriq_e500/CMakeFiles/CMakeTmp'
    make  -f CMakeFiles/cmTC_6e0a4.dir/build.make CMakeFiles/cmTC_6e0a4.dir/build
    make[3]: Entering directory '/home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/O.RTEMS-qoriq_e500/CMakeFiles/CMakeTmp'
    Building C object CMakeFiles/cmTC_6e0a4.dir/testCCompiler.c.obj
    /home/rtems/MVME2500_6/rtems/6/bin/powerpc-rtems6-gcc   -B/home/rtems/MVME2500_6/rtems/6/powerpc-rtems6/qoriq_e500/lib/ -specs bsp_specs -qrtems -mcpu=8540 -msoft-float -meabi -msdata=sysv -mstrict-align  -o CMakeFiles/cmTC_6e0a4.dir/testCCompiler.c.obj -c /home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/O.RTEMS-qoriq_e500/CMakeFiles/CMakeTmp/testCCompiler.c
    powerpc-rtems6-gcc: fatal error: cannot read spec file 'bsp_specs': No such file or directory
    compilation terminated.
    make[3]: *** [CMakeFiles/cmTC_6e0a4.dir/build.make:85: CMakeFiles/cmTC_6e0a4.dir/testCCompiler.c.obj] Error 1
    make[3]: Leaving directory '/home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/O.RTEMS-qoriq_e500/CMakeFiles/CMakeTmp'
    make[2]: *** [Makefile:140: cmTC_6e0a4/fast] Error 2
    make[2]: Leaving directory '/home/rtems/MVME2500_6/EPICS/epics-support/pvxs/bundle/O.RTEMS-qoriq_e500/CMakeFiles/CMakeTmp'

hjunkes avatar Sep 18 '25 08:09 hjunkes

According to https://docs.rtems.org/docs/main/user/migration/v5-to-v6.html I deleted '-spec bsp_specs' out of bundle/cmake/Platform/RTEMS.cmake

run

make -C pvxs/bundle libevent
make -C pvxs/bundle libevent.RTEMS-qoriq_e500
make -C pvxs

without problems:

rtems@rtems-dev:~/MVME2500_6/EPICS/epics-support$ ls -l pvxs/lib/RTEMS-qoriq_e500/
total 32088
-rw-r--r-- 1 rtems rtems 24404116 Sep 18 12:12 libpvxs.a
-rw-r--r-- 1 rtems rtems  8449574 Sep 18 12:14 libpvxsIoc.a

hjunkes avatar Sep 18 '25 10:09 hjunkes

Hallo Michael, I am now trying to get the whole thing running with RTEMS6 / libbsd on an MVME2500. Unfortunately, the whole thing hangs in the call UDPManager::instance at pvxs/src/server.cpp

Server::Pvt::Pvt(const Config &conf)
  384     :effective(conf)
  385     ,beaconMsg(128)
  386     ,acceptor_loop("PVXTCP", epicsThreadPriorityCAServerLow-2)
  387     ,beaconSender4(AF_INET, SOCK_DGRAM, 0)
  388     ,beaconSender6(AF_INET6, SOCK_DGRAM, 0)
  389     ,beaconTimer(__FILE__, __LINE__,
  390                  event_new(acceptor_loop.base, -1, EV_TIMEOUT, doBeaconsS, this))
  391     ,searchReply(0x10000)
  392     ,builtinsrc(StaticSource::build())
  393     ,state(Stopped)
  394 {
  395     effective.expand();
  396     beaconSender4.set_broadcast(true);
  397
  398     auto manager = UDPManager::instance(effective.shareUDP());

I have to continue tomorrow because I have to leave now. Perhaps you have another good idea on how best to debug the problem. Danke Heinz

hjunkes avatar Sep 18 '25 14:09 hjunkes

@hjunkes Having a stack trace would be helpful. Also, I assume you are testing 1.4.0? Could you also test PVXS 1.3.3? I suspect a regression due to a change in 1.4.0 related to when/how the OS network configuration is inspected (a464e9a6eb366c62423a28bc7fbfa98f6b0d21e5).

mdavidsaver avatar Sep 18 '25 17:09 mdavidsaver

Same behaviour with 1.3.3

commit 5f993bafb38eb0a5c645039822a118ba9e06c455 (HEAD, tag: 1.3.3)
Author: Michael Davidsaver <[email protected]>
Date:   Thu Apr 3 14:06:04 2025 +0100

    1.3.3

okay, I'll look into it...

hjunkes avatar Sep 19 '25 08:09 hjunkes

Hallo Michael, Unfortunately, I'm still a little clumsy when it comes to using the software.

Since I can't use a debugger with the ppc target, I'm trying to use printf statements...

   53 Server::Server(const Config& conf)
   54 {
   55     /* Here be dragons.
   56      *
   57      * We keep two different ref. counters.
   58      * - "external" counter which keeps a server running.
   59      * - "internal" which only keeps server storage from being destroyed.
   60      *
   61      * External refs are held as Server::pvt.  Internal refs are
   62      * held by various in-progress operations (OpBase sub-classes)
   63      * Which need to safely access server storage, but should not
   64      * prevent a server from stopping.
   65      */
W  66 printf("create shared conf (size: %d), Pvt size : %d .....\n", sizeof(conf), sizeof(Pvt));
   67     auto internal(std::make_shared<Pvt>(conf));
+  68 printf(" internal state : %d \n", internal->state);
   69     internal->internal_self = internal;
~  70 printf(" Server .....\n");
   71     // external
   72     pvt.reset(internal.get(), [internal](Pvt*) mutable {
   73         auto trash(std::move(internal));
   74         trash->stop();
   75     });
+  76 printf(" Server schluss .....\n");
   77     // we don't keep a weak_ptr to the external reference.
   78     // Caller is entirely responsible for keeping this server running
   79 }

on unix it runs as expected:

## Register all support components
dbLoadDatabase("dbd/mvme2500IOC.dbd")
mvme2500IOC_registerRecordDeviceDriver(pdbbase)
INFO: PVXS QSRV2 is loaded, permitted, and ENABLED.
create shared conf (size: 104), Pvt size : 560 .....
 internal state : 0
 Server .....
 Server schluss .....
 nach initialise PvxsServer
 nach HookRegister
## Load record instances
#dbLoadTemplate("db/user.substitutions")
dbLoadRecords("db/mvme2500IOCVersion.db", "user=rtems")
...

RTEMS ppc gets stuck here?

 auto internal(std::make_shared<Pvt>(conf));
chdir("/Volumes/Epics/MVME2500/mvme2500IOC/iocBoot/iocmvme2500IOC/")
***** Starting EPICS application *****
#< envPaths
epicsEnvSet("IOC","mvme2500IOC")
epicsEnvSet("PVXS_QSRV_ENABLE","NO")
cd "/Volumes/Epics/MVME2500/mvme2500IOC"
## Register all support components
dbLoadDatabase("dbd/mvme2500IOC.dbd")
mvme2500IOC_re nach threadonce ServerInit ...
 nach Guard ...
 call Server ...
gisterRecordDeviceDriver(pdbbase)
create shared conf (size: 72), Pvt size : 336 .....

hjunkes avatar Sep 19 '25 13:09 hjunkes

I'm trying to use printf statements...

Also turn on all of the PVXS logging.

epicsEnvSet("PVXS_LOG", "*=DEBUG")

mdavidsaver avatar Sep 19 '25 13:09 mdavidsaver

ok, see output on linux, but nothing on RTEMS

rtems@rtems-dev:~/MVME2500_6/EPICS/FHI/mvme2500IOC/iocBoot/iocmvme2500IOC$ ../../bin/linux-x86_64/mvme2500IOC st_linux.cmd
< envPaths
epicsEnvSet("IOC","iocmvme2500IOC")
epicsEnvSet("TOP","/home/rtems/MVME2500_6/EPICS/FHI/mvme2500IOC")
epicsEnvSet("EPICS_BASE","/home/rtems/MVME2500_6/EPICS/epics-base")
epicsEnvSet("SUPPORT","/home/rtems/MVME2500_6/EPICS/epics-support")
epicsEnvSet("SNCSEQ","/home/rtems/MVME2500_6/EPICS/epics-support/sequencer")
epicsEnvSet("SSCAN","/home/rtems/MVME2500_6/EPICS/epics-support/sscan")
epicsEnvSet("CALC","/home/rtems/MVME2500_6/EPICS/epics-support/calc")
epicsEnvSet("ASYN","/home/rtems/MVME2500_6/EPICS/epics-support/asyn")
epicsEnvSet("AUTOSAVE","/home/rtems/MVME2500_6/EPICS/epics-support/autosave")
epicsEnvSet("RECCASTER","/home/rtems/MVME2500_6/EPICS/epics-support/recsync/client")
epicsEnvSet("PVXS","/home/rtems/MVME2500_6/EPICS/epics-support/pvxs")
epicsEnvSet("IOC","linuxIOC")
#epicsEnvSet("PVXS_QSRV_ENABLE","NO")
epicsEnvSet("PVXS_LOG", "*=DEBUG")
cd "/home/rtems/MVME2500_6/EPICS/FHI/mvme2500IOC"
## Register all support components
dbLoadDatabase("dbd/mvme2500IOC.dbd")
mvme2500IOC_registerRecordDeviceDriver(pdbbase)
INFO: PVXS QSRV2 is loaded, permitted, and ENABLED.
create shared conf (size: 104), Pvt size : 560 .....
2025-09-19T15:42:16.937370773 INFO pvxs.loop Enter loop worker for 0x7f8c90000bf0 using epoll
2025-09-19T15:42:16.937468603 DEBUG pvxs.iface refresh after 705430.1 sec
2025-09-19T15:42:16.937738099 DEBUG pvxs.iface Ignoring interface 'lo' address family=17
2025-09-19T15:42:16.937798041 DEBUG pvxs.iface Ignoring interface 'ens192' address family=17
2025-09-19T15:42:16.937854799 DEBUG pvxs.iface Ignoring interface 'ens224' address family=17
2025-09-19T15:42:16.937909709 DEBUG pvxs.iface Ignoring interface 'tap0' address family=17
2025-09-19T15:42:16.938015550 DEBUG pvxs.iface Found interface 1 "lo" w/ 2 127.0.0.1
2025-09-19T15:42:16.938186816 DEBUG pvxs.iface Found interface 3 "ens224" w/ 2 141.14.128.65
2025-09-19T15:42:16.938258343 DEBUG pvxs.iface Found interface 4 "tap0" w/ 2 10.1.2.3
2025-09-19T15:42:16.938326822 DEBUG pvxs.iface Found interface 1 "lo" w/ 10 [::1]
2025-09-19T15:42:16.938396493 DEBUG pvxs.iface Found interface 3 "ens224" w/ 10 [fe80::250:56ff:fe83:8307]%3
2025-09-19T15:42:16.938789262 INFO pvxs.loop Enter loop worker for 0x7f8c94000ba0 using epoll
2025-09-19T15:42:16.938905509 INFO pvxs.udp.setup Bound to UDP 0.0.0.0:5076 as lo
2025-09-19T15:42:16.938943213 DEBUG pvxs.udp.setup Listening for SEARCH on 0.0.0.0:5076
2025-09-19T15:42:16.939078474 DEBUG pvxs.server.setup Will send beacons to 141.14.143.255:5076
2025-09-19T15:42:16.939093144 DEBUG pvxs.server.setup Will send beacons to 10.255.255.255:5076
2025-09-19T15:42:16.939270786 DEBUG pvxs.udp.io UDP 0x7f8c94001a60 event 2
0000 : CA028003 00000038 00000015 00000000
0010 : 00000000 00000000 0000FFFF 00000000
0020 : 9A570103 74637000 01000000 02124648
0030 : 493A4D50 3A494D4F 423A6D79 54656D70
2025-09-19T15:42:16.939353746 DEBUG pvxs.udp.io UDP Rx 64, 141.14.135.182:39511 -> 141.14.143.255:5076 @3 (0.0.0.0:5076)
 internal state : 0
 Server .....
 Server schluss .....
 nach initialise PvxsServer
 nach HookRegister
## Load record instances
#dbLoadTemplate("db/user.substitutions")
dbLoadRecords("db/mvme2500IOCVersion.db", "user=rtems")
***** Preparing EPICS application *****
chdir("/Volumes/Epics/MVME2500/mvme2500IOC/iocBoot/iocmvme2500IOC/")
***** Starting EPICS application *****
#< envPaths
epicsEnvSet("IOC","mvme2500IOC")
epicsEnvSet("PVXS_LOG", "*=DEBUG")
cd "/Volumes/Epics/MVME2500/mvme2500IOC"
## Register all support components
dbLoadDatabase("dbd/mvme2500IOC.dbd")
mvme2500IOC_registerRecordDeviceDriver(pdbbase)
INFO nach threadonce ServerInit ...
 nach Guard ...
 call Server ...
: PVXS QSRV2 is loaded, permitted, and ENABLED.
create shared conf (size: 72), Pvt size : 336 .....

hjunkes avatar Sep 19 '25 13:09 hjunkes

Sorry, I was already further along yesterday evening. The method I wanted to check was: Server::Pvt::Pvt(const Config &conf)

hjunkes avatar Sep 19 '25 14:09 hjunkes

Hurra, it works ..

in /pvxs/src/evhelper.cpp

 #ifdef __rtems__
   178             /* with libbsd circa RTEMS 5.1
   179              * TCP peer close/reset notifications appear to be lost.
   180              * Maybe due to absence of NOTE_EOF?
   181              * poll() seems to work though.
   182              */
   183             event_config_avoid_method(conf.get(), "kqueue");
   184 #endif

I deleted it ;-)

fs: mount: (0) Success
 check for time registered , C++ initialization ...
 Will try to start telnetd with prio 0 ...
 telnetd initialized with result 0
***** Preparing EPICS application *****
chdir("/Volumes/Epics/MVME2500/mvme2500IOC/iocBoot/iocmvme2500IOC/")
***** Starting EPICS application *****
#< envPaths
epicsEnvSet("IOC","mvme2500IOC")
epicsEnvSet("PVXS_LOG", "*=DEBUG")
cd "/Volumes/Epics/MVME2500/mvme2500IOC"
## Register all support components
dbLoadDatabase("dbd/mvme2500IOC.dbd")
mvme2500IOC_registerRecordDeviceDriver(pdbbase)
INFO nach threadonce ServerInit ...
 nach Guard ...
 call Server ...
: PVXS QSRV2 is loaded, permitted, and ENABLED.
create shared conf (size: 72), Pvt size : 336 .....
 houps ...
Warning: failed to fetch monotonic time 0 -1
2024-04-14T07:30:53.979678239 INFO pvxs.loop Enter loop worker for 0x2326b48 using kqueue
2024-04-14T07:30:53.989689599 DEBUG pvxs.iface refresh after 0.0 sec
2024-04-14T07:30:54.000845499 DEBUG pvxs.iface Ignoring interface 'tsec0' address family=18
2024-04-14T07:30:54.006373019 DEBUG pvxs.iface Found interface 1 "tsec0" w/ 28 [fe80::ee9e:cdff:fe0f:1b77]%1
2024-04-14T07:30:54.017470079 DEBUG pvxs.iface Found interface 1 "tsec0" w/ 2 141.14.128.89
2024-04-14T07:30:54.023006639 DEBUG pvxs.iface Ignoring interface 'tsec1' address family=18
2024-04-14T07:30:54.034135719 DEBUG pvxs.iface Found interface 2 "tsec1" w/ 28 [fe80::ee9e:cdff:fe0f:1b78]%2
2024-04-14T07:30:54.039678079 DEBUG pvxs.iface Ignoring interface 'tsec2' address family=18
2024-04-14T07:30:54.050800159 DEBUG pvxs.iface Found interface 3 "tsec2" w/ 28 [fe80::ee9e:cdff:fe0f:1b79]%3
2024-04-14T07:30:54.056505939 DEBUG pvxs.iface Ignoring interface 'lo0' address family=18
2024-04-14T07:30:54.067470619 DEBUG pvxs.iface Found interface 4 "lo0" w/ 2 127.0.0.1
2024-04-14T07:30:54.073024679 DEBUG pvxs.iface Found interface 4 "lo0" w/ 28 [::1]
2024-04-14T07:30:54.084343879 DEBUG pvxs.iface Found interface 4 "lo0" w/ 28 [fe80::1]%4
 houps ...
2024-04-14T07:30:54.090006659 INFO pvxs.loop Enter loop worker for 0x2629060 using kqueue
Warning: failed to fetch monotonic time 0 -1
Warning: failed to fetch monotonic time 0 -1
Warning: failed to fetch monotonic time 0 -1
Warning: failed to fetch monotonic time 0 -1
2024-04-14T07:30:54.090224979 INFO pvxs.udp.setup Bound to UDP 0.0.0.0:5076 as lo
2024-04-14T07:30:54.090269879 DEBUG pvxs.udp.setup Listening for SEARCH on 0.0.0.0:5076
 internal state : 0
2024-04-14T07:30:54.128732219 DEBUG pvxs. Server .....
server .setup Will send beacons to 141.14.143.255:5076
Server schluss  und raus aus der initialisierung ...
.....
 nach initialise PvxsServer
 nach HookRegister
## Load record instances
#dbLoadTemplate("db/user.substitutions")
dbLoadRecords("db/mvme2500IOCVersion.db", "user=rtems")
#dbLoadRecords("db/dbSubExample.db", "user=rtems")
#dbLoadRecords("db/table.db", "N=TST:,LBL1=Label A,LBL2=Label B,PO1=0,PO2=1")
traceIocInit
iocInit will be traced
iocInit
iocInit: Reached initHookAtIocBuild
Starting iocInit
ntpd: RTEMS service init
iocInit: Reached initHookAtBeginning
############################################################################
## EPICS R7.0.9.1-DEV
## Rev. 1b701cfa2dd5c15e4b89-dirty
## Rev. Date Git: 2025-08-15 15:18:31 +1000
############################################################################
iocInit: Reached initHookAfterCallbackInit
 houps ...
2024-04-14T07:30:54.226424019 DEBUG pvxs.client.setup Using UDP Rx port 22570
2024-04-14T07:30:54.226478419 INFO pvxs.loop Enter loop worker for 0x2e4c4c8 using kqueue
2024-04-14T07:30:54.241675179 INFO pvxs.client.io Searching to 141.14.143.255:5076
2024-04-14T07:30:54.247266339 INFO pvxs.client.io Listening for beacons on 0.0.0.0:5076
iocInit: Reached initHookAfterCaLinkInit
2024-04-14T07:30:54.2iocInit: Re5ached initHookAfterInitDrvSup
2808799 DEBUG pvxs.iface refresihocInit: Reached initHookAfterInitRecSup
 after 1713079854.3 seic
ocInit: Reached initHookAfterInitDevSup
iocInit: Reached in2itHookAfterInitDatabase
024-04-14T07:30:54.252916799 DEBUG pvixocInit: Reached initHookAfterFinishDevSup
s.iface Ignoring interface 'tsec0' address family=18
2024-04-14T07:30:54.252965599 DEBUG pvxs.iface Found interface 1 "tsec0" w/ 28 [fe80::ee9e:cdff:fe0f:1b77]%1
2024-04-14T07:30:54.253022879 DEBUG pvxs.iface Found interface 1 "tsec0" w/ 2 141.14.128.89
2024-04-14T07:30:54.253060619 DEBUG pvxs.iface Ignoring interface 'tsec1' address family=18
2024-04-14T07:30:54.253097879 DEBUG pvxs.iface Found interface 2 "tsec1" w/ 28 [fe80::ee9e:cdff:fe0f:1b78]%2
2024-04-14T07:30:54.253133099 DEBUG pvxs.iface Ignoring interface 'tsec2' address family=18
2024-04-14T07:30:54.253179479 DEBUG pvxs.iface Found interface 3 "tsec2" w/ 28 [fe80::ee9e:cdff:fe0f:1b79]%3
2024-04-14T07:30:54.253215899 DEBUG pvxs.iface Ignoring interface 'lo0' address family=18
2024-04-14T07:30:54.253260779 DEBUG pvxs.iface Found interface 4 "lo0" w/ 2 127.0.0.1
2024-04-14T07:30:54.253307079 DEBUG pvxs.iface Found interface 4 "lo0" w/ 28 [::1]
errlog: lost 4 messages
2024-04-14T07:30:54.471018479 DEBUG pvxs.udp.io UDP 0x262bb30 event 2
0000 : CA028003 0000004F 00000013 00000000
0010 : 00000000 00000000 0000FFFF 00000000
0020 : 9A570103 74637000 02000000 02124648
0030 : 493A4D50 3A494D4F 423A6D79 54656D70
...
2024-04-14T07:30:54.471144379 DEBUG pvxs.udp.io UDP Rx 87, 141.14.135.182:39511 -> 141.14.143.255:5076 @1 (0.0.0.0:5076)
iocInit: Reached initHookAfterScanInit
iocInit: Reached initHookAfterInitialProcess
iocInit: Reached initHookAfterCaServerInit
iocInit: Reached initHookAfterIocBuilt
iocInit: Reached initHookAtIocRun
iocInit: Reached initHookAfterDatabaseRunning
iocInit: Reached initHookAfterInterruptAccept
iocInit: Reached initHookAfterCaServerRunning
iocInit: Reached initHookAtEnd
iocRun: All initialization complete
2024-04-14T07:30:54.825472859 DEBUG pvxs.server.setup Server Starting
2024-04-14T07:30:54.831047379 DEBUG pvxs.server.setup Server starting

hjunkes avatar Sep 19 '25 14:09 hjunkes

I'm reopening because there is still work to be done.

Hurra, it works ..

So it is an issue with initializing libevent with RTEMS6+bsdlib. I will see about adding some debug logs for this.

 #ifdef __rtems__
   178             /* with libbsd circa RTEMS 5.1
   179              * TCP peer close/reset notifications appear to be lost.
   180              * Maybe due to absence of NOTE_EOF?
   181              * poll() seems to work though.
   182              */
   183             event_config_avoid_method(conf.get(), "kqueue");
   184 #endif

hmm. Any idea if this issue was addressed in libbsd at some point? Otherwise you may be open to "leaking" TCP connections and FD exhaustion. I hope that the timeout would still trigger, but I don't know the kqueue mechanism well enough to be sure.

@kiwichris fyi.

mdavidsaver avatar Sep 19 '25 14:09 mdavidsaver

@hjunkes Could you attach a log of a successful run of make -C pvxs/bundle libevent.RTEMS-qoriq_e500? This should show which features were detected with libbsd.

mdavidsaver avatar Sep 19 '25 14:09 mdavidsaver

MD: replace inline with attachment

libevent.txt

hjunkes avatar Sep 19 '25 14:09 hjunkes

There is another problem here? Could this be related to the fact that NTP is not yet synchronized when the IOC starts up?

dbLoadDatabase("dbd/mvme2500IOC.dbd")
mvme2500IOC_registerRecordDeviceDriver(pdbbase)
INFO: PVXS QSRV2 is loaded, permitted, and ENABLED.
Warning: failed to fetch monotonic time 0 -1
## Load record instances
Warning: failed to fetch monotonic time 0 -1
#dbLoadTemplate("db/uoser.substitutions")
dbLoadRecords("db/mvme2500IOCVersion.db", "user=rtems")
Warning: failed to fetch monotonic time 0 -1
#dbLoadRecords("db/dbSubExample.db", "user=rtems")
Warning: failed to fetch monotonic time 0 -1
Warning: failed to fetch monotonic time 0 -1
dbLoadRecords("db/table.db", "N=TST:,LBL1=Label A,LBL2=Label B,PO1=0,PO2=1")
traceIocInit
iocInit will be traced
iocInit
iocInit: Reached initHookAtIocBuild
Starting iocInit
ntpd: RTEMS service init
iocInit: Reached initHookAtBeginning

hjunkes avatar Sep 19 '25 14:09 hjunkes

Could this be related to the fact that NTP is not yet synchronized when the IOC starts up?

A monotonic time source is specifically not supposed to be effected by NTP.

Warning: failed to fetch monotonic time 0 -1

Do you know where this message is printed from? I can't find it.

mdavidsaver avatar Sep 19 '25 16:09 mdavidsaver

is from epics-base/modules/libcom/src/osi/os/posix/osdMonotonic.c

epicsUInt64 epicsMonotonicGet(void)
{
    struct timespec ts;
    int ret = clock_gettime(osdMonotonicID, &ts);
    if(ret) {
        errlogPrintf("Warning: failed to fetch monotonic time %d %d\n",
                     (int)osdMonotonicID, ret);
        return 0;
    } else {
        epicsUInt64 ret = ts.tv_sec;
        ret *= 1000000000;
        ret += ts.tv_nsec;
        return ret;
    }
}

hint for myself (RTEMS-Doku Glossar):

: The CLOCK_MONOTONIC is a clock provided by RTEMS which measures the time
since an unspecified starting point. In contrast to [CLOCK_REALTIME], this clock cannot be set. 
It may be affected by incremental adjustments for example carried out by the [NTP] or the use of a [PPS]

in src/evhelper.cpp

   696 #if EPICS_VERSION_INT<VERSION_INT(7,0,3,1)
   697 #  define getMonotonic getCurrent
   698 #endif

(We are running ## EPICS R7.0.9.1-DEV)

  726 void IfaceMap::refresh(bool force)
   727 {
   728     auto now(epicsTime::getMonotonic());
   729     auto age = now-updated;

epicsTime.h

     * Returns an epicsTime containing the current monotonic time, an
     * OS clock which never going backwards or jumping forwards.
     * This time is has an undefined epoch, and is only useful for
     * measuring time differences.
     */
    static epicsTime getMonotonic () {
        epicsTime ret;
        epicsTimeGetMonotonic(&ret.ts); // can't fail
        return  ret;
    }

in modules/libcom/src/osi/epicsGeneralTime.c

  218 int epicsTimeGetMonotonic ( epicsTimeStamp * pDest )
  219 {
 220     epicsUInt64 now = epicsMonotonicGet();
  221     pDest->nsec = now%1000000000ul;
  222     pDest->secPastEpoch = now/1000000000ul;
  223     return 0;
  224 }

hjunkes avatar Sep 22 '25 09:09 hjunkes

with

commit 021bcb4a06224ed8c0e8184b3a89c015830e2e3b (HEAD -> master, origin/master, origin/HEAD)
Author: Michael Davidsaver <[email protected]>
Date:   Sun Jul 13 20:29:43 2025 -0700

    server: fix Dead op cleanup

I do not see anymore these messages ...

However, I am still a little confused. 'osdMonotonicID' used has the value '1', but according to the documentation, it should be '4', right?

powerpc-rtems6/include/time.h:#define CLOCK_MONOTONIC		((clockid_t) 4)
powerpc-rtems6/include/time.h:#define CLOCK_MONOTONIC_RAW	((clockid_t) 5)
powerpc-rtems6/include/time.h:#define CLOCK_MONOTONIC_COARSE	((clockid_t) 6)

hjunkes avatar Sep 22 '25 11:09 hjunkes

I'm reopening because there is still work to be done.

Hurra, it works ..

So it is an issue with initializing libevent with RTEMS6+bsdlib. I will see about adding some debug logs for this.

 #ifdef __rtems__
   178             /* with libbsd circa RTEMS 5.1
   179              * TCP peer close/reset notifications appear to be lost.
   180              * Maybe due to absence of NOTE_EOF?
   181              * poll() seems to work though.
   182              */
   183             event_config_avoid_method(conf.get(), "kqueue");
   184 #endif

hmm. Any idea if this issue was addressed in libbsd at some point? Otherwise you may be open to "leaking" TCP connections and FD exhaustion. I hope that the timeout would still trigger, but I don't know the kqueue mechanism well enough to be sure.

@kiwichris fyi.

I think kqueue is the mechanism supported in rtems-libbsd: rtems-libbsd/freebsd/sys/kern/kern_event.c:

    86 #ifdef __rtems__
    87 /* Maintain a global kqueue list on RTEMS */
    88 static struct kqlist fd_kqlist;
    89 #endif /* __rtems__ */

hjunkes avatar Sep 22 '25 15:09 hjunkes

Hurra, it works ..

in /pvxs/src/evhelper.cpp

 #ifdef __rtems__
   178             /* with libbsd circa RTEMS 5.1
   179              * TCP peer close/reset notifications appear to be lost.
   180              * Maybe due to absence of NOTE_EOF?
   181              * poll() seems to work though.
   182              */
   183             event_config_avoid_method(conf.get(), "kqueue");
   184 #endif

I deleted it ;-)

Based on your latest tech-talk mail (archive link not available), there is an issue with RTEMS/libbsd and the kqueue mechanism. The result is that when the first TCP connection is closed, UDP reception stops.

https://gitlab.rtems.org/rtems/rtos/rtems/-/issues/5201#note_124749

My recommendation in the near term is to switch to the "poll" mechanism.

libevent allows the equivalent of the event_config_avoid_method() call at runtime by setting environment variables like $EVENT_NO<METHOD>. Set before registerRecordDeviceDriver() is called.

epicsEnvSet("PVXS_LOG", "pvxs.loop=INFO")
epicsEnvSet("EVENT_NOKQUEUE", "1")

dbdLoadRecord("dbd/someioc.dbd")
...

The effect can be seen in this pvxs.loop log message. eg. "... using kqueue".

2024-04-14T07:30:53.979678239 INFO pvxs.loop Enter loop worker for 0x2326b48 using kqueue

mdavidsaver avatar Nov 20 '25 01:11 mdavidsaver

First sorry, I have not tracked this issue. I am looking and catching up now.

Hurra, it works .. in /pvxs/src/evhelper.cpp

 #ifdef __rtems__
   178             /* with libbsd circa RTEMS 5.1
   179              * TCP peer close/reset notifications appear to be lost.
   180              * Maybe due to absence of NOTE_EOF?
   181              * poll() seems to work though.
   182              */
   183             event_config_avoid_method(conf.get(), "kqueue");
   184 #endif

I deleted it ;-)

Based on your latest tech-talk mail (archive link not available), there is an issue with RTEMS/libbsd and the kqueue mechanism. The result is that when the first TCP connection is closed, UDP reception stops.

OK

https://gitlab.rtems.org/rtems/rtos/rtems/-/issues/5201#note_124749

We have this fixed on RTEMS 7 and that issue is for 7.1. If @hjunkes can make a new issue we can assign to the 6 branch I can get it looked at.

My recommendation in the near term is to switch to the "poll" mechanism.

Makes sense.

kiwichris avatar Nov 20 '25 01:11 kiwichris

https://gitlab.rtems.org/rtems/rtos/rtems/-/issues/5201#note_124749

We have this fixed on RTEMS 7 and that issue is for 7.1. If @hjunkes can make a new issue we can assign to the 6 branch I can get it looked at.

There is an issue already ... https://gitlab.rtems.org/rtems/rtos/rtems/-/issues/5311

We can use that to deal with this issue.

kiwichris avatar Nov 20 '25 01:11 kiwichris

@kiwichris Is there some visible symptom of these issues? eg. Am I missing an error returned by a close()?

mdavidsaver avatar Nov 20 '25 01:11 mdavidsaver

@kiwichris Is there some visible symptom of these issues? eg. Am I missing an error returned by a close()?

The previous code, ie 6.1 and earlier, will return EBADF if the fd is in a call or blocked. I don't think you are missing anything but I am not sure.

Note;

  1. The fix discussed in the RTEMS issues is on the 6 branch. I am looking into this now to be sure. It will be in 6.2 when I release that.
  2. The close when busy functionality is only enabled for libbsd file descriptors. The previous behavior is still present for other types of descriptors, ie files etc.

Previously if you call close on a socket fd while you have threads blocked in a kqueue call the close failed with an error and the descriptor stayed open, ie you could leak them. An event that wakes a thread in a kqueue call of that fd is none the wiser a close was made and failed and will happily make the kqueue call again and block. On FreeBSD (where libbsd) comes from the close call will close the socket and complete without error. Any held resources related to the fd are held until all references are gone. A thread blocked in kqueue wakes then fails when it attempts the call again as the fd is closed.

kiwichris avatar Nov 20 '25 02:11 kiwichris