Re: IOC segfaults with epicsMutexLock (pmutexNode=0x0)

[Blaz Kranjc <blaz.kranjc@cosylab.com>]

Hi Mark,

we are using base version 3.14.12.3 (this line numbers seems to be the same as in 3.14.12.5).

The casStatsFetch is called in ai_init.

We will revert this IOC to the old module version for now.

Cheers,
Blaz

----- Original Message -----
From: "Mark Rivers" <rivers@cars.uchicago.edu>
To: "blaz kranjc" <blaz.kranjc@cosylab.com>, "tech-talk" <tech-talk@aps.anl.gov>
Sent: Monday, December 5, 2016 4:36:46 PM
Subject: RE: IOC segfaults with epicsMutexLock (pmutexNode=0x0)

Hi Blaz,

You did not say what version of EPICS base you are running.  If I look ca caservertask.c in 3.14.12.5 at line 955 it is the following:
	LOCK_CLIENTQ;

This macro is defined as:

#define LOCK_CLIENTQ    epicsMutexMustLock (clientQlock);

So for some reason clientQlock is 0.  This is not a mutex in devIocStats, it is a mutex in caservertask.c. / server.h.

A couple of reasons this could happen:

1) Something is overwriting memory and setting clientQlock to 0.
2) casStatsFetch is being called before it is OK to do so, and the clientQlock mutex has not yet been created.

Since you say it only happens if there are 4000 autosave PVs then my first suspicion would be a race condition pointing to #2 above.  But that is just a guess.

Mark


-----Original Message-----
From: tech-talk-bounces@aps.anl.gov [mailto:tech-talk-bounces@aps.anl.gov] On Behalf Of Blaz Kranjc
Sent: Monday, December 05, 2016 10:16 AM
To: tech-talk@aps.anl.gov
Subject: IOC segfaults with epicsMutexLock (pmutexNode=0x0)

Hi everybody,

after an update of the devIocStats module one of our IOC segfaults during the IOC startup. The IOC is providing an interface to some cameras with ADCore (version 2.4, cameras were replaced by a ADExample simDetector instance).
Latest tested version of devIocStats that worked is 3.1.5, the updated version is 3.1.15.

The segfault only occurs if a lot of PVs (~4000 PVs) is restored from saverestore at initHookState 7, otherwise the IOC starts without a problem. Output of the startup script is appended to this email.

Trace from the core dump:
#0  epicsMutexLock (pmutexNode=0x0) at ../../../src/libCom/osi/epicsMutex.cpp:143
#1  0x00007f002da7b328 in casStatsFetch (pChanCount=0x7eff911d5c28, pCircuitCount=0x7eff911d5c2c)
    at ../caservertask.c:955
#2  0x00007f002f552035 in scan_time (type=3) at ../devIocStatsAnalog.c:355
#3  0x00007f002cb8154e in epicsTimerForC::expire (this=<value optimized out>)
    at ../../../src/libCom/timer/epicsTimer.cpp:65
#4  0x00007f002cb82933 in timerQueue::process (this=0x4cdfc50, currentTime=...)
    at ../../../src/libCom/timer/timerQueue.cpp:140
#5  0x00007f002cb8302b in timerQueueActive::run (this=0x4cdfc20)
    at ../../../src/libCom/timer/timerQueueActive.cpp:91
#6  0x00007f002cb76691 in epicsThreadCallEntryPoint (pPvt=0x4cdfcf0)
    at ../../../src/libCom/osi/epicsThread.cpp:85
#7  0x00007f002cb7c29d in start_routine (arg=0x4ce0140) at ../../../src/libCom/osi/os/posix/osdThread.c:397
#8  0x000000381c807aa1 in start_thread () from /lib64/libpthread.so.0
#9  0x000000381c0e8aad in clone () from /lib64/libc.so.6

The IOC is running approximately 350 threads when this error occurs which makes browsing through the traces of other threads pretty hard.

The trace is not referencing the devIocStats directly. I'm suspecting the module because this happens when only devIocStats is swapped. The old working version of devIocStats was not using any locking and in the new version epicsMutex.h is used. The mutexes used in the devIocStats are created with epicsMutexMustCreate() [1].

It seems that the mutex is nulled between the locks. I would really appreciate any help with fixing this.

[1] https://github.com/epics-modules/iocStats/blob/0a192b0e5ab8d86bb9b6d5222e33074143ebe89e/devIocStats/devIocStatsAnalog.c