ChannelFinder returns variable count of PVs when IOCs are connected/disconnected

[connorfi]

I am writing a utility that polls ChannelFinder for changes via the RESTful API. I am seeing that the total returned entries for a given query varies for a time after an IOC (with RecCaster) has connected or disconnected. I am running version ChannelFinder 4.7.1 w/ elasticsearch 8.7.1. Here is the output from my polling, latest to oldest responses.

Updated PV Lists - 03:16:33 PM SPVs: [1657], ConfigPVs: [593], CPVs: [398]
Updated PV Lists - 03:16:21 PM SPVs: [5], ConfigPVs: [39], CPVs: [0]
Updated PV Lists - 03:16:20 PM SPVs: [5], ConfigPVs: [53], CPVs: [0]
Updated PV Lists - 03:16:19 PM SPVs: [74], ConfigPVs: [97], CPVs: [2]
Updated PV Lists - 03:16:18 PM SPVs: [151], ConfigPVs: [121], CPVs: [20]
Updated PV Lists - 03:16:17 PM SPVs: [237], ConfigPVs: [147], CPVs: [42]
Updated PV Lists - 03:16:15 PM SPVs: [322], ConfigPVs: [174], CPVs: [65]
Updated PV Lists - 03:16:14 PM SPVs: [414], ConfigPVs: [202], CPVs: [86]
Updated PV Lists - 03:16:13 PM SPVs: [523], ConfigPVs: [235], CPVs: [114]
Updated PV Lists - 03:16:11 PM SPVs: [631], ConfigPVs: [269], CPVs: [139]
Updated PV Lists - 03:16:10 PM SPVs: [739], ConfigPVs: [301], CPVs: [164]
Updated PV Lists - 03:16:08 PM SPVs: [851], ConfigPVs: [337], CPVs: [194]
Updated PV Lists - 03:16:06 PM SPVs: [956], ConfigPVs: [369], CPVs: [221]
Updated PV Lists - 03:16:04 PM SPVs: [1081], ConfigPVs: [408], CPVs: [251]
Updated PV Lists - 03:16:02 PM SPVs: [1212], ConfigPVs: [449], CPVs: [283]
Updated PV Lists - 03:16:00 PM SPVs: [1351], ConfigPVs: [491], CPVs: [318]
Updated PV Lists - 03:15:58 PM SPVs: [1495], ConfigPVs: [535], CPVs: [353]
Updated PV Lists - 03:15:26 PM SPVs: [1657], ConfigPVs: [593], CPVs: [398]

I have about 2000 PVs in Channelfinder. The IOC that I am start/stopping hosts all of the PVs. I assume this "re-indexing" would occur anytime an IOC w/ RecCaster connected to CF is started or stopped. The re-indexing takes about 30 seconds to return to the original count.

Is this behavior known/expected? Is it resolved/improved in 4.7.2. Issue #96 seems to discuss some changes that might be related.

[jacomago]

Hi @connorfi

I recommend you use 4.7.2. We at ESS went from syncing all 1500 IOCs (around 2 million PVs I think) over several days to syncing in less than an hour.

[connorfi]

@jacomago thank you for responding. I have a few more questions to understand the syncing behavior.

1. Under what conditions/when does a sync occur?
2. What is the recommended behavior for processes that rely on ChannelFinder during a sync?
3. Is there a way to detect a sync in progress other than variable responses? For example a "Sync Status" field in GET http://localhost/ChannelFinder to indicate syncing progress/completion?

[jacomago]

1. This is actually controlled on the recceiver side:

• IOC goes up

• recsync module communicates with recceiver

• Note there is a configurable TIMEOUT field for this communication on the IOC

• recceiver tells Channelfinder via REST api data has changed

• ChannelFinder updates elastic with new info

• IOC goes down

• recceiver sees a timeout in communication with IOC

• recceiver tells Channelfinder via REST api data has changed

• ChannelFinder updates elastic with new info

ChannelFinder itself is quite "dumb" by design. It has no idea about what an IOC is, just a channel, property, and tag.

2. With the latest version, I can't expect you to see the middle of a sync. For a single IOC of < 10000 PVs it takes less than a second.

3. In some ways you can always assume ChannelFinder data is in flux? Unless you expect 100% uptime of every IOC and network card, etc.

[connorfi]

Thank you for the additional background.

The use case of a single IOC w/ ~2000 PVs is just for my dev environment. The application will have many more IOCs and PVs, so I would like to understand more about the concept of operations when an installation is waiting for CF to sync. Is it simply a known down-time for services/systems that rely on CF?

I guess the hang-up I have is that I didn't expect CF to tell me that it knows about fewer PVs than it did previously if the channels were not intentionally removed from the DB. In my mind, an IOC coming online/offline would be more of a "DB entry update" (of say the pvStatus property) rather than a delete/add operation. Can you provide some insight into why Channel Finder has this behavior in the first place?

[jacomago]

Like I said, if you update to the latest. The sync time is very quick.

In terms of design... Both recceiver and ChannelFinder were created a long time ago. I expect the original creators can't remember how it was designed!

"I didn't expect CF to tell me that it knows about fewer PVs than it did previously if the channels were not intentionally removed from the DB"

This shouldn't happen. Current behavior is no PVs are removed from channelfinder, only set as Inactive. As you described it's just an update to the property. (I'm 90% sure)

[connorfi]

I have finally updated to 4.7.2. I am seeing that the sync is faster. But polling ChannelFinder/resources/channels? every second I still see up to two changes over 3 seconds. This is with ~3500 PVs total. [NOTE: on a VM with more resources I was not able to detect the sync w/ a 1second poll interval]

The sync time is much more reasonable and for my application I think I can now wait for it to stabilize before determining that there is an actual change in the number of channels.

I still believe ChannelFinder/resources/channels? should not be changing when IOCs come on/offline. Can you run a test on your end to see if you observe this behavior? I think we may be in the 10% of your certainty.

[jacomago]

That sounds like it could be the recceiver or reccaster (IOC) side. It could actually be a misconfigured IOC. We have seen something similar before. You have to be careful with the TIMEOUT in the ioc. We have it set to 5 seconds. But otherwise which version of these are you using?

But I'm not quite sure what you mean by polling "ChannelFinder/resources/channels?" Do you mean "hostname/ChannelFinder/resources/channels/count"?

[connorfi]

Interesting. I didn't know about the URI "hostname/ChannelFinder/resources/channels/count".

I just ran a test where I started my IOC and refreshed a browser with path http://localhost:8081/ChannelFinder/resources/channels/count (I am on the same machine as Channel Finder and have it configured for port 8081 instead of 8080). In a terminal I started a camonitor on the reccaster PV State-Sts. Shortly after State-Sts changed to "Done" I saw the channel count go to zero for one refresh of the browser.

I am using the client demo IOC that comes with RecSync. demoMain.cpp is unmodified. Below is the setup in st.cmd, is reccastTimeout what you means as the TIMEOUT?.

## Register all support components
dbLoadDatabase("../../dbd/demo.dbd",0,0)
demo_registerRecordDeviceDriver(pdbbase)

var(reccastTimeout, 5.0)
var(reccastMaxHoldoff, 5.0)

epicsEnvSet("IOCNAME", "myioc")
epicsEnvSet("ENGINEER", "myself")
epicsEnvSet("LOCATION", "myplace")
epicsEnvSet("CONTACT", "mycontact")
epicsEnvSet("BUILDING", "mybuilding")
epicsEnvSet("SECTOR", "mysector")

addReccasterEnvVars("CONTACT", "SECTOR")
addReccasterEnvVars("BUILDING")

Yes, the full path I am polling in my application is: http://localhost:8081/ChannelFinder/resources/channels?. This returns a list of all channels and their properties. When I detect a change in the total # of PVs or a subset of the properties I re-count the PVs with specific tags. When I start/stop an IOC I see the # of PVs change.

I should also clarify that with 4.7.2, I am no longer so worried about this behavior since it recovers in a very short period. So, we can continue to investigate or we can note the behavior somehow and potentially close this issue. I will leave it up to your discretion.

[jacomago]

That sounds like the correct behavior. The pvStatus property changes whenever the ioc goes up and down. So number of PVs with particular properties/tags changes.

A couple of notes:

• If you are using grafana you can use the metrics endpoint to get a live graph of this information. That's in https://github.com/ChannelFinder/ChannelFinderService/releases/tag/ChannelFinder-4.7.3-alpha at least.

  Then the grafana endpoint is https://hostname/actuator/prometheus

• If you want to see the full api you can go to https://hostname/swagger-ui/index.html

[connorfi]

pvStatus is a field that I am intentionally ignoring because it does change on start/stop. The subset of fields I am looking at are: [iocid, recordType, pv_tag_1, pv_tag_2, pv_tag_3]

That link to swagger is extremely helpful! Might not hurt to note that on the readthedocs page or the readme. I am not sure how I would have known to check that uri (unless I am just naive to this as a common practice).

I will keep an eye out for the full 4.7.3 release.

Thank you for fielding all my inquiries and providing additional details. This has really helped me out.

[jacomago]

Ok. I think I understand now.

From my recollection, the way the receiver works is it updates all the channels it has and just updates everything if something changed. That's probably why you see this flicker down to 0 channels as it deleted the old first??? Perhaps, it's very obtuse code.

I'm already looking into something similar for another issue. So if I can fix that issue I might be able to fix this one as well. Where we should only be changing the properties that changed and not the whole channel.

[jacomago]

Hi can you test recciever 1.7? And see how it is.

[connorfi]

Thanks for letting me know about the new release. I am not sure when I will be able to upgrade and test, but it seems worthwhile given the improvements that have been made.