Strange PVManager error

[berryma4]

I keep getting this error from a BOY screen that uses this pv in a text input
I'm not sure why only this pv.

2017-01-19 10:34:48 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_BTS19:RFC_D0983:ON_RSTS_RF' was closed.

If I remove the text input, there is no error.
If I paste the text input with this pv into a new BOY screen, there is no error.
If I paste the text input back with this pv, there is the same error again.

[shroffk]

Do you see this error with vtype.pv?

[berryma4]

No, the error comes from pvmanager.

[kasemir]

The exception is caught by BOYPVFactory#exceptionHandler:

    private final static ExceptionHandler exceptionHandler = new ExceptionHandler() {
        @Override
        public void handleException(Exception ex) {
            ErrorHandlerUtil.handleError("Error from pv connection layer: ", ex);
        }
    };

That ErrorHandlerUtil then passes it on to a dialog etc., but also includes a plain java.util.logging log(WARNING, message, exception), so the console output should show the complete stack trace.

You already tested that the text input itself, used in another display, doesn't cause the problem.

Vague guess: Does the affected display use that same PV for 'write' actions?
Usually, the BOY code connects to all PVs when a display is opened, and closes all when the display is closed. But for write actions, I remember some odd code that would create the PV when first touched. Maybe there's a life-cycle problem with such PVs.

[berryma4]

Sorry I meant "java.lang.IllegalStateException: ConnectionCollector" comes from pvmanager.

[berryma4]

What's strange is the point I can remove the text input, then there is no error. Then, if I add it back, there is an error. If I make a new screen with the text input, no error. This might sound like your "write" issue because it's a text input. I will use a ro widget and see if the same behavior.

[kasemir]

Right, the exception originates in the pvmanager.
It's unclear if this is an internal error in the pvmanager, or if the BOY lifecycle of creating and closing the PVManager.reader/writer causes the error.
For the vtype.pv implementation, I noticed that BOY doesn't always close those PVs that were created on the fly for write actions. Maybe now we have a case of closing them too early or too often.

[berryma4]

Yes, it still happens with a "text update".

[berryma4]

I'm not sure why only this PV as opposed to all the others on the page. It seem to really dislike this particular PV name.

[kasemir]

What's the full exception?
Is that PV used in any other way in the same display? Grep for the PV name in the *.opi file.

[shroffk]

What kind of pv is this, what is the return/write type expected

[berryma4]

I removed all instances of it, except the text update.
Previously, it was used in a script too.
So, no error without text update, error when pasted back.
It's a VEnum.

CA Channel name = REA_BTS19:RFC_D0983:ON_RSTS_RF
CA Channel type = DBR_ENUM
CA Connection state = CONNECTED
CA Element count = 1
CA Hostname = xxx.xxx.xxx.xxx
CA Read access = true
CA Write access = true
Connected = true
Connection payload = JCAConnection [connected: true writeConnected: true channel: CAJChannel = { name = REA_BTS19:RFC_D0983:ON_RSTS_RF, connectionState = CONNECTED }]
Last message payload = Metadata gov.aps.jca.dbr.DBR_LABELS_Enum@6565f3 value gov.aps.jca.dbr.DBR_TIME_Enum@891f18f
Write Connected = true
isLongString = false
isPutCallback = false

[berryma4]

Okay someone else has the same error. A lot of these are Enums, but not all.

2017-01-12 18:39:01 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0006:V_CSET' was closed.
2017-01-12 18:39:01 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0001:V_CSET' was closed.
2017-01-12 18:39:01 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEO_N0000:V_CSET' was closed.
2017-01-12 18:39:01 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEC_N0002:V_CSET' was closed.
2017-01-12 18:39:01 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:PSELI_D0858:V_CSET' was closed.
2017-01-13 18:10:08 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:PSOL_D0831:I_CSET' was closed.
2017-01-16 19:22:11 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:PSOL_D0832:I_CSET' was closed.
2017-01-16 19:22:11 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:PSOL_D0833:I_CSET' was closed.
2017-01-16 19:22:27 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TECE_N0011:V_CSET' was closed.
2017-01-16 19:22:27 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEC_N0010:V_CSET' was closed.
2017-01-17 13:07:15 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:BEAM:PER_CO.PROC' was closed.
2017-01-17 13:07:48 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:BEAM:PER_CO.PROC' was closed.
2017-01-17 13:12:22 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:BEAM:PER_CO.PROC' was closed.
2017-01-17 13:12:55 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:BEAM:PER_CO.PROC' was closed.
2017-01-17 14:58:25 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:BEAM:PER_CO.PROC' was closed.
2017-01-17 14:58:41 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:BEAM:PER_CO.PROC' was closed.
2017-01-17 19:13:17 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:HVP_N0001:V_CSET' was closed.
2017-01-17 19:13:17 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:PSOL_D0831:I_CSET' was closed.
2017-01-17 19:13:17 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:PSOL_D0832:I_CSET' was closed.
2017-01-18 18:50:34 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:PSOL_D0831:I_CSET' was closed.
2017-01-19 10:39:29 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0004:V_CSET' was closed.
2017-01-19 10:39:29 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0001:V_CSET' was closed.
2017-01-19 10:40:38 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0006:ON_CMD' was closed.
2017-01-19 10:40:38 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0004:ON_CMD' was closed.
2017-01-19 10:40:38 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0005:ON_CMD' was closed.
2017-01-19 10:42:40 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TECB_N0011:ON_CMD' was closed.
2017-01-19 10:42:40 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TECE_N0011:ON_CMD' was closed.
2017-01-19 10:42:40 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEC_N0010:ON_CMD' was closed.
2017-01-19 10:42:40 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEC_N0012:ON_CMD' was closed.
2017-01-19 10:42:40 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:DCHE_D0855:ON_CMD' was closed.
2017-01-19 10:43:20 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0004:ON_CMD' was closed.
2017-01-19 10:43:20 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0006:ON_CMD' was closed.
2017-01-19 10:43:20 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0001:ON_CMD' was closed.
2017-01-19 10:43:20 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEO_N0000:ON_CMD' was closed.
2017-01-19 11:21:41 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:HVP_N0001:V_CSET' was closed.
2017-01-19 11:21:41 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:PSCA_D0834:V_CSET' was closed.
2017-01-19 11:53:18 ERROR: The file  does not exist.
2017-01-19 11:57:10 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0006:ON_CMD' was closed.
2017-01-19 11:57:10 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:TEE_N0005:ON_CMD' was closed.
2017-01-19 12:24:53 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:PSEL2_D0853:V_CSET' was closed.
2017-01-19 12:24:53 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:PSOL_D0854:I_CSET' was closed.
2017-01-19 12:24:53 ERROR: Error from pv connection layer: 
java.lang.IllegalStateException: ConnectionCollector for 'REA_EBIT1:PSEL_D0854:V_CSET' was closed.

[kasemir]

If you get the error with a *.opi that has just that one text input, does the CSS instance still have something else open for that PV, so the PVManager has multiple uses for that data sources?

Maybe the complete stack trace helps. BOYPVFactory.exceptionHandler() calls ErrorHandlerUtil.handleError():

    public static void handleError(final String message,
            final Throwable exception, final boolean writeToConsole, final boolean popErrorDialog){
        OPIBuilderPlugin.getLogger().log(Level.WARNING,
            message, exception); //$NON-NLS-1$
        if(writeToConsole)
            ConsoleService.getInstance().writeError(message + "\n" + exception);

Looks like you copied the console, where we just see "ERROR: .." and the exception message.
In the java util log you see a WARNING and then the full stack trace. Run CSS with -consoleLog to see that full log.

[berryma4]

I can get the error in the debugger. This is what throws the exception:
org.diirt.datasource.DataSource.java ln 182:

@Override
            public void run() {
                for (Map.Entry<ChannelHandler, Collection<ChannelReadRecipe>> entry : handlersWithSubscriptions.entrySet()) {
                    ChannelHandler channelHandler = entry.getKey();
                    Collection<ChannelReadRecipe> channelRecipes = entry.getValue();
                    for (ChannelReadRecipe channelRecipe : channelRecipes) {
                        try {
                            channelHandler.addReader(channelRecipe.getReadSubscription());
                        } catch(Exception ex) {
                            // If an error happens while adding the read subscription,
                            // notify the appropriate handler
                            channelRecipe.getReadSubscription().getExceptionWriteFunction().writeValue(ex);
                        }
                    }
                }
            }