PVA Client fails to connect

[kasemir]

Might be related to #50.

Run this test database run softIocPVA:

record(calc, "ramp")
{
  field(SCAN, "1 second")
  field(INPA, "ramp")
  field(CALC, "A+1")
}

record(calc, "saw")
{
  field(SCAN, "1 second")
  field(INPA, "saw")
  field(CALC, "A<10 ? A+1 : 0")
}

record(calc, "rnd")
{
  field(SCAN, "1 second")
  field(CALC, "100*RNDM")
}

The following test code that tries to connect to all 3 PVs works OK with org.epics.pvaccess_5.1.1.jar and org.epics.pvdata_6.1.1.jar under Java 8:

Channel ramp created
Channel saw created
Channel rnd created
Channel ramp state: CONNECTED
Channel saw state: CONNECTED
Channel rnd state: CONNECTED
ramp = epics:nt/NTScalar:1.0     double value 76.0    alarm_t alarm...
saw = epics:nt/NTScalar:1.0     double value 10.0    alarm_t alarm...
rnd = epics:nt/NTScalar:1.0     double value 83.42870222018769    ...
...

But with epics-pvdata-6.1.3-SNAPSHOT.jar and epics-pvaccess-5.1.3-SNAPSHOT.jar under Java 9+ it only connects to one or two of the PVs:

Channel ramp created
Channel saw created
Channel rnd created
Channel rnd state: CONNECTED
rnd = epics:nt/NTScalar:1.0     double value 66.19668879224841    ...
rnd = epics:nt/NTScalar:1.0     double value 97.21675440604257    ...

Example code to follow...

[kasemir]

import java.util.concurrent.TimeUnit;
import org.epics.pvaccess.ClientFactory;
import org.epics.pvaccess.client.Channel;
import org.epics.pvaccess.client.Channel.ConnectionState;
import org.epics.pvaccess.client.ChannelProvider;
import org.epics.pvaccess.client.ChannelProviderRegistry;
import org.epics.pvaccess.client.ChannelProviderRegistryFactory;
import org.epics.pvaccess.client.ChannelRequester;
import org.epics.pvdata.copy.CreateRequest;
import org.epics.pvdata.monitor.Monitor;
import org.epics.pvdata.monitor.MonitorElement;
import org.epics.pvdata.monitor.MonitorRequester;
import org.epics.pvdata.pv.MessageType;
import org.epics.pvdata.pv.PVStructure;
import org.epics.pvdata.pv.Status;
import org.epics.pvdata.pv.Structure;

class Demo implements ChannelRequester, MonitorRequester
{
    final private static CreateRequest request_creater = CreateRequest.create();
    private static ChannelProvider provider;
    final private PVStructure read_request = request_creater.createRequest("field()");
    final private Channel channel;
    private Monitor value_monitor = null;

    Demo(final String name) throws Exception
    {
        channel = provider.createChannel(name, this, ChannelProvider.PRIORITY_DEFAULT);
    }

    // ChannelRequester
    @Override
    public String getRequesterName()
    {
        return getClass().getName();
    }

    // ChannelRequester
    @Override
    public void message(final String message, final MessageType type)
    {
        System.out.println("Message " + type + ": " + message);
    }

    // ChannelRequester
    @Override
    public void channelCreated(final Status status, final Channel channel)
    {
        if (status.isSuccess())
            System.out.println("Channel " + channel.getChannelName() + " created");
        else
            System.out.println("Channel " + channel.getChannelName() + " create problem: " + status.getMessage());
    }

    // ChannelRequester
    @Override
    public void channelStateChange(final Channel channel, final ConnectionState state)
    {
        System.out.println("Channel " + channel.getChannelName() + " state: " + state);
        switch (state)
        {
        case CONNECTED:
            subscribe();
            break;
        case DISCONNECTED:
        default:
            // Ignore
        }
    }

    private void subscribe()
    {
        synchronized (this)
        {   // Avoid double-subscription
            if (this.value_monitor != null)
                return;
            value_monitor = channel.createMonitor(this, read_request);
        }
    }

    // MonitorRequester
    @Override
    public void monitorConnect(final Status status, final Monitor monitor,
            final Structure structure)
    {
        if (status.isSuccess())
            monitor.start();
    }

    // MonitorRequester
    @Override
    public void monitorEvent(final Monitor monitor)
    {
        MonitorElement update;
        while ((update = monitor.poll()) != null)
        {
            try
            {
                String value = update.getPVStructure().toString().replace("\n", "");
                if (value.length() > 60)
                    value = value.substring(0, 60) + "...";
                System.out.println(channel.getChannelName() + " = " + value);
            }
            catch (Exception ex)
            {
                ex.printStackTrace();
            }
            monitor.release(update);
        }
    }

    // MonitorRequester
    @Override
    public void unlisten(final Monitor monitor)
    {
        // Ignore
    }

    public static void main(String[] args) throws Exception
    {
//        System.setProperty("EPICS_PVA_DEBUG", "3");
        ClientFactory.start();
        final ChannelProviderRegistry registry = ChannelProviderRegistryFactory.getChannelProviderRegistry();
        provider = registry.getProvider("pva");

        new Demo("ramp");
        new Demo("saw");
        new Demo("rnd");
        TimeUnit.SECONDS.sleep(30);
        System.exit(0);
    }
}

[shroffk]

Thanks @kasemir I was able to recreate the problem with your example above.
I am looking into it now

[kasemir]

Excellent. I tried to also test the old pva lib, the one that workd OK, with JDK 9/10/11, but the old pva depends on Corba classes which have been removed from JDK 9/10/11.

So can only test old lib with old JDK and new lib with new JDK.
Don't think that the JDK is the problem here.

[shroffk]

Ok, I think I have figured it out...the CID is reused before the server completed the channel creation.

started creating channel ramp
creating channel ramp with CID 0
successfully created Channel ramp
Channel ramp created
started creating channel saw
creating channel saw with CID 0
successfully created Channel saw
Channel saw created
started creating channel rnd
creating channel rnd with CID 0
successfully created Channel rnd
Channel rnd created
channel create succeeded on server for sid 0
channel create succeeded on server for sid 0 setting connection state to Connected
Channel rnd state: CONNECTED

Thus only the last channel created connects...if the server completed creating the connection fast then 2 of them might connect.

[shroffk]

The above commit fixes this issue. Would you be able to verify this.
I will merge and release the snapshots

[kasemir]

Your explanation and also the fix make sense.
There might be a way to avoid the sync sections by using ConcurrentHashMap operations and atomic counters, but more important is that it works at all.
Go ahead and merge, because that way it'll show up in the snapshot used to build phoebus, right?

[shroffk]

There might be a way to avoid the sync sections by using ConcurrentHashMap operations and atomic counters

+1

[shroffk]

The fix is not in the latest snapshot release

They snapshots release is currently done by me since I have not set up a deploy CI task with the appropriate authenctications needed to push to the sonatype repo. This can be a discussion item at the epics meeting.

[kasemir]

With the latest pva libs, the original Demo code as well as Phoebus work, thanks!