Java Agent is not sending data with the same value

A_Macierzynski · ‎Jan 31, 2019

Hello!

Scope:

I have few different type of properties defined in Java Agent through the methods. Some of the should be send ALWAYS, some only on VALUE change.

Problem:

Even if I will set up everything to ALWAYS, properties with the same val are not pushed to the ThingWorx.

Code details:

1. I am setting properties very very often. It can be every second or even faster. There can be more than 50 properties bound to RemoteThing.

2. I am using this snippet to setup remote property definition on Virtal Thing implementation:

PropertyDefinition property = new PropertyDefinition(propertyName, "", ThingworxDataUtils.parseType(propertyType));
AspectCollection aspectCollection = new AspectCollection();
aspectCollection.put(Aspects.ASPECT_CACHETIME, new StringPrimitive("0"));
aspectCollection.put(Aspects.ASPECT_ISFOLDED, new BooleanPrimitive(false));
aspectCollection.put("pushType", new StringPrimitive(pushType));
property.setAspects(aspectCollection);
this.defineProperty(property);

PushType is set to "ALWAYS". Property is defined on ThingWorx to have Push Type = ALWAYS as well.

Now I have a logs like that in my Agent:

Line 1190: [DEBUG] 22/Jan/2019 13:12:59,965 [pool-9-thread-8] - S7Controller:234 S7-1200 Frequency TAG: param_power1ontime Value :42
Line 1191: [DEBUG] 22/Jan/2019 13:12:59,965 [pool-9-thread-8] - PLCVirtualThing:72 [AVAILABLE] Set Property Thing: RT_RTTFT_STE98-800_00919 Property: param_power1ontime Value: 57 Type: DWORD
Line 1204: [TRACE] 22/Jan/2019 13:12:59,968 [pool-9-thread-8] - VirtualThing:1164 PUSHING PROPERTIES = {"values":{"rows":[{"name":"param_utilization","time":1548159179965,"value":{"value":58,"baseType":"LONG"},"quality":"GOOD"},{"name":"param_power1ontime","time":1548159179966,"value":{"value":57,"baseType":"LONG"},"quality":"GOOD"},{"name":"param_power2ontime","time":1548159179966,"value":{"value":58,"baseType":"LONG"},"quality":"GOOD"}],"dataShape":{"fieldDefinitions":{"name":{"name":"name","aspects":{},"description":"name","baseType":"STRING","ordinal":0},"time":{"name":"time","aspects":{},"description":"time","baseType":"DATETIME","ordinal":0},"value":{"name":"value","aspects":{},"description":"value","baseType":"VARIANT","ordinal":0},"quality":{"name":"quality","aspects":{},"description":"quality","baseType":"STRING","ordinal":0}}}}}
Line 2601: [DEBUG] 22/Jan/2019 13:13:49,972 [pool-9-thread-3] - S7Controller:234 S7-1200 Frequency TAG: param_power1ontime Value :57
Line 2602: [DEBUG] 22/Jan/2019 13:13:49,972 [pool-9-thread-3] - PLCVirtualThing:72 [AVAILABLE] Set Property Thing: RT_RTTFT_STE98-800_00919 Property: param_power1ontime Value: 57 Type: DWORD
HERE PUSHIN PROPERTIES LOG IS NOT APPEARING, WHEN THE VALUE IS THE SAME (57). IT IS OOTB LOG FROM THINGWORX JAVA SDK
Line 932: [DEBUG] 22/Jan/2019 13:14:39,974 [pool-9-thread-6] - S7Controller:234 S7-1200 Frequency TAG: param_power1ontime Value :57
Line 933: [DEBUG] 22/Jan/2019 13:14:39,975 [pool-9-thread-6] - PLCVirtualThing:72 [AVAILABLE] Set Property Thing: RT_RTTFT_STE98-800_00919 Property: param_power1ontime Value: 58 Type: DWORD
Line 942: [TRACE] 22/Jan/2019 13:14:39,978 [pool-9-thread-6] - VirtualThing:1164 PUSHING PROPERTIES = {"values":{"rows":[{"name":"param_utilization","time":1548159279974,"value":{"value":30,"baseType":"LONG"},"quality":"GOOD"},{"name":"param_watercontrolontime","time":1548159279978,"value":{"value":23,"baseType":"LONG"},"quality":"GOOD"},{"name":"param_power1ontime","time":1548159279975,"value":{"value":58,"baseType":"LONG"},"quality":"GOOD"}],"dataShape":{"fieldDefinitions":{"name":{"name":"name","aspects":{},"description":"name","baseType":"STRING","ordinal":0},"time":{"name":"time","aspects":{},"description":"time","baseType":"DATETIME","ordinal":0},"value":{"name":"value","aspects":{},"description":"value","baseType":"VARIANT","ordinal":0},"quality":{"name":"quality","aspects":{},"description":"quality","baseType":"STRING","ordinal":0}}}}}
Line 2132: [DEBUG] 22/Jan/2019 13:15:29,978 [pool-9-thread-7] - S7Controller:234 S7-1200 Frequency TAG: param_power1ontime Value :58
Line 2133: [DEBUG] 22/Jan/2019 13:15:29,979 [pool-9-thread-7] - PLCVirtualThing:72 [AVAILABLE] Set Property Thing: RT_RTTFT_STE98-800_00919 Property: param_power1ontime Value: 23 Type: DWORD
Line 2142: [TRACE] 22/Jan/2019 13:15:29,982 [pool-9-thread-7] - VirtualThing:1164 PUSHING PROPERTIES = {"values":{"rows":[{"name":"param_utilization","time":1548159329978,"value":{"value":13,"baseType":"LONG"},"quality":"GOOD"},{"name":"param_power1ontime","time":1548159329979,"value":{"value":23,"baseType":"LONG"},"quality":"GOOD"},{"name":"param_power2ontime","time":1548159329980,"value":{"value":23,"baseType":"LONG"},"quality":"GOOD"}],"dataShape":{"fieldDefinitions":{"name":{"name":"name","aspects":{},"description":"name","baseType":"STRING","ordinal":0},"time":{"name":"time","aspects":{},"description":"time","baseType":"DATETIME","ordinal":0},"value":{"name":"value","aspects":{},"description":"value","baseType":"VARIANT","ordinal":0},"quality":{"name":"quality","aspects":{},"description":"quality","baseType":"STRING","ordinal":0}}}}}
Line 2790: [DEBUG] 22/Jan/2019 13:16:19,980 [pool-9-thread-2] - S7Controller:234 S7-1200 Frequency TAG: param_power1ontime Value :23
Line 2791: [DEBUG] 22/Jan/2019 13:16:19,980 [pool-9-thread-2] - PLCVirtualThing:72 [AVAILABLE] Set Property Thing: RT_RTTFT_STE98-800_00919 Property: param_power1ontime Value: 40 Type: DWORD
Line 2801: [TRACE] 22/Jan/2019 13:16:19,983 [pool-9-thread-2] - VirtualThing:1164 PUSHING PROPERTIES = {"values":{"rows":[{"name":"param_utilization","time":1548159379980,"value":{"value":32,"baseType":"LONG"},"quality":"GOOD"},{"name":"param_watercontrolontime","time":1548159379983,"value":{"value":13,"baseType":"LONG"},"quality":"GOOD"},{"name":"param_power1ontime","time":1548159379981,"value":{"value":40,"baseType":"LONG"},"quality":"GOOD"},{"name":"param_power2ontime","time":1548159379981,"value":{"value":42,"baseType":"LONG"},"quality":"GOOD"}],"dataShape":{"fieldDefinitions":{"name":{"name":"name","aspects":{},"description":"name","baseType":"STRING","ordinal":0},"time":{"name":"time","aspects":{},"description":"time","baseType":"DATETIME","ordinal":0},"value":{"name":"value","aspects":{},"description":"value","baseType":"VARIANT","ordinal":0},"quality":{"name":"quality","aspects":{},"description":"quality","baseType":"STRING","ordinal":0}}}}}

Any ideas what I should check?

Adam

PaiChung · ‎Jan 31, 2019

Can you try using a datachange subscription to verify that indeed always is not working properly?

not sure if you've already done so or not.

tkawasaki · ‎Jan 31, 2019

Hello,

Your property definition looks alright, both isFolded:FALSE and pushType:ALWAYS are set properly.

The log output "PUSHING PROPERTIES = {" is logged within updateSubscribedProperties() so it might be helpful to review your logic about in which conditions updateSubscribedProperties() is called.

Also, you can add below code before updateSubscribedProperties() to check which values are actually in the queue. If the value doesn't exist in the queue, something is wrong with setProperty() or property definition.

        int propCount = super.getPendingPropertyUpdates().get("Pressure").getPropertyValueCount();
        System.out.println("PropertyCount:"+propCount);
        for(int i =0; i < propCount; i++){
            System.out.println("Queued:"+super.getPendingPropertyUpdates().get("param_power1ontime").get(i).getVTQ());
        }

A_Macierzynski · ‎Feb 06, 2019

@tkawasaki @PaiChung

Thank you for your answers!

Unfortunatelly I could not reproduce error on my instance.

The only thing which I changed is this method:

@Override
    public void processScanRequest() {
        try {
            super.processScanRequest();
            if(!super.getPendingPropertyUpdates().isEmpty())
                logger.debug("[PUSHING] Properties: " + super.getPendingPropertyUpdates().toInfoTable().toJSON().toString());
            super.updateSubscribedProperties(AppConstants.THINGWORX_PROPERTY_WRITE_TIMEOUT);
        } catch (Exception e) {
            logger.error("Exception occurred while updating properties. ", e);
        }
    }

So as @tkawasaki suggusted lowered the logging from Trace to Debug and added my own log te see what kind of data I am trying to push and now suddenly it is working...

I have no idea what happened. I will investigate it more and will let you know if I will found anything!

Regards,

Adam