From 3decfc998ce7d51be5428e1d871ed54827f5bddc Mon Sep 17 00:00:00 2001 From: Trevor Date: Fri, 8 Dec 2023 05:41:54 -0500 Subject: [PATCH] Add extra checks to make state last_update checks more stable (#784) --- docs/specs/sequences/generated.md | 5 + .../system_last_update/config_system.attr | 9 - .../system_last_update/config_system.json | 12 - .../system_last_update/config_update.attr | 9 +- .../system_last_update/config_update.json | 16 +- .../system_last_update/event_pointset.attr | 9 +- .../system_last_update/event_pointset.json | 8 +- .../system_last_update/event_system.attr | 9 +- .../system_last_update/event_system.json | 42 +- .../system_last_update/local_localnet.json | 10 + .../system_last_update/local_pointset.json | 16 + .../system_last_update/local_system.json | 4 +- .../system_last_update/local_update.json | 8 +- .../sequences/system_last_update/sequence.md | 5 + .../system_last_update/sequencer.log | 2509 ++++++++++++----- .../system_last_update/state_localnet.attr | 9 +- .../system_last_update/state_localnet.json | 8 +- .../system_last_update/state_pointset.attr | 9 +- .../system_last_update/state_pointset.json | 4 +- .../system_last_update/state_system.attr | 9 +- .../system_last_update/state_system.json | 20 +- .../system_last_update/state_update.attr | 9 +- .../system_last_update/state_update.json | 20 +- .../system_last_update/state_validation.attr | 9 - .../system_last_update/state_validation.json | 147 - .../sequences/system_last_update/system.log | 56 +- .../daq/mqtt/sequencer/SequenceBase.java | 4 + .../sequencer/sequences/ConfigSequences.java | 5 + 28 files changed, 1926 insertions(+), 1054 deletions(-) delete mode 100644 validator/sequences/system_last_update/config_system.attr delete mode 100644 validator/sequences/system_last_update/config_system.json create mode 100644 validator/sequences/system_last_update/local_localnet.json create mode 100644 validator/sequences/system_last_update/local_pointset.json delete mode 100644 validator/sequences/system_last_update/state_validation.attr delete mode 100644 validator/sequences/system_last_update/state_validation.json diff --git a/docs/specs/sequences/generated.md b/docs/specs/sequences/generated.md index 24e1f39137..c67dffcc05 100644 --- a/docs/specs/sequences/generated.md +++ b/docs/specs/sequences/generated.md @@ -197,5 +197,10 @@ Check that a device publishes correct software information in state messages Check that last_update state is correctly set in response to a config update. 1. Wait for state last_config matches first config timestamp +1. Wait for state update complete 1. Force config update to trigger another config update 1. Wait for state last_config matches new config timestamp +1. Wait for state update complete +1. Force config update to trigger another config update +1. Wait for state last_config matches last config timestamp +1. Wait for state update complete diff --git a/validator/sequences/system_last_update/config_system.attr b/validator/sequences/system_last_update/config_system.attr deleted file mode 100644 index 4e2032ed73..0000000000 --- a/validator/sequences/system_last_update/config_system.attr +++ /dev/null @@ -1,9 +0,0 @@ -{ - "deviceId" : "AHU-1", - "deviceNumId" : "123456789101112", - "deviceRegistryId" : "ZZ-TRI-FECTA", - "projectId" : "bos-peringknife-dev", - "subFolder" : "system", - "subType" : "config", - "transactionId" : "1678207122021" -} \ No newline at end of file diff --git a/validator/sequences/system_last_update/config_system.json b/validator/sequences/system_last_update/config_system.json deleted file mode 100644 index bc4a075eeb..0000000000 --- a/validator/sequences/system_last_update/config_system.json +++ /dev/null @@ -1,12 +0,0 @@ -{ - "metrics_rate_sec" : 600, - "min_loglevel" : 200, - "operation" : { - "last_start" : "2023-03-07T16:38:08Z" - }, - "testing" : { - "sequence_name" : "system_last_update" - }, - "timestamp" : "2023-03-07T16:38:43.216Z", - "version" : "1.4.0-221-g632b879b" -} \ No newline at end of file diff --git a/validator/sequences/system_last_update/config_update.attr b/validator/sequences/system_last_update/config_update.attr index 1b785b677f..82379aeb2b 100644 --- a/validator/sequences/system_last_update/config_update.attr +++ b/validator/sequences/system_last_update/config_update.attr @@ -1,9 +1,10 @@ { "deviceId" : "AHU-1", "deviceNumId" : "123456789101112", - "deviceRegistryId" : "ZZ-TRI-FECTA", - "projectId" : "bos-peringknife-dev", + "deviceRegistryId" : "peringknife~ZZ-TRI-FECTA", + "projectId" : "bos-platform-dev", + "transactionId" : "RC:1702014606556", + "publishTime" : "2023-12-08T05:50:06Z", "subFolder" : "update", - "subType" : "config", - "transactionId" : "RC:1690575920093" + "subType" : "config" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/config_update.json b/validator/sequences/system_last_update/config_update.json index fc9fd86386..77b2b0e697 100644 --- a/validator/sequences/system_last_update/config_update.json +++ b/validator/sequences/system_last_update/config_update.json @@ -15,26 +15,26 @@ "ref" : "BV11.present_value", "units" : "No-units" }, - "filter_differential_pressure_setpoint" : { - "units" : "Bars", - "set_value" : 98 - }, "filter_differential_pressure_sensor" : { "ref" : "AV12.present_value", "units" : "Degrees-Celsius" + }, + "filter_differential_pressure_setpoint" : { + "set_value" : 98, + "units" : "Bars" } } }, "system" : { - "metrics_rate_sec" : 600, + "metrics_rate_sec" : 10, "min_loglevel" : 200, "operation" : { - "last_start" : "2023-07-28T20:23:12Z" + "last_start" : "2023-12-08T05:49:34Z" }, "testing" : { "sequence_name" : "system_last_update" } }, - "timestamp" : "2023-07-28T20:25:20Z", - "version" : "1.4.1" + "timestamp" : "2023-12-08T05:50:06Z", + "version" : "1.4.2-66-gd207962a3" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/event_pointset.attr b/validator/sequences/system_last_update/event_pointset.attr index 8b3b57306a..59950c8f8e 100644 --- a/validator/sequences/system_last_update/event_pointset.attr +++ b/validator/sequences/system_last_update/event_pointset.attr @@ -1,9 +1,10 @@ { "deviceId" : "AHU-1", "deviceNumId" : "123456789101112", - "deviceRegistryId" : "ZZ-TRI-FECTA", - "projectId" : "bos-peringknife-dev", + "deviceRegistryId" : "peringknife~ZZ-TRI-FECTA", + "projectId" : "bos-platform-dev", + "transactionId" : "PS:9106514635980066", + "publishTime" : "2023-12-08T05:50:14Z", "subFolder" : "pointset", - "subType" : "event", - "transactionId" : "PS:8732122066911886" + "subType" : "event" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/event_pointset.json b/validator/sequences/system_last_update/event_pointset.json index c370c89d3c..1fa0839014 100644 --- a/validator/sequences/system_last_update/event_pointset.json +++ b/validator/sequences/system_last_update/event_pointset.json @@ -1,15 +1,15 @@ { "points" : { "filter_alarm_pressure_status" : { - "present_value" : true + "present_value" : false }, "filter_differential_pressure_setpoint" : { "present_value" : 98 }, "filter_differential_pressure_sensor" : { - "present_value" : 11 + "present_value" : 10 } }, - "timestamp" : "2023-07-28T20:25:14Z", - "version" : "1.4.1" + "timestamp" : "2023-12-08T05:50:04Z", + "version" : "1.4.2" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/event_system.attr b/validator/sequences/system_last_update/event_system.attr index b5cdd84207..6594b30d99 100644 --- a/validator/sequences/system_last_update/event_system.attr +++ b/validator/sequences/system_last_update/event_system.attr @@ -1,9 +1,10 @@ { "deviceId" : "AHU-1", "deviceNumId" : "123456789101112", - "deviceRegistryId" : "ZZ-TRI-FECTA", - "projectId" : "bos-peringknife-dev", + "deviceRegistryId" : "peringknife~ZZ-TRI-FECTA", + "projectId" : "bos-platform-dev", + "transactionId" : "PS:9793162560796901", + "publishTime" : "2023-12-08T05:50:06Z", "subFolder" : "system", - "subType" : "event", - "transactionId" : "PS:8733108896924291" + "subType" : "event" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/event_system.json b/validator/sequences/system_last_update/event_system.json index 585f49e3a9..b46f0551b1 100644 --- a/validator/sequences/system_last_update/event_system.json +++ b/validator/sequences/system_last_update/event_system.json @@ -1,11 +1,41 @@ { - "event_count" : 11, - "last_config" : "2023-07-28T20:24:59Z", - "logentries" : [ ], + "event_count" : 3, + "last_config" : "2023-12-08T05:50:02Z", + "logentries" : [ { + "message" : "Update state 2023-12-08T05:49:56Z last_config 2023-12-08T05:49:54Z", + "category" : "device.log", + "timestamp" : "2023-12-08T05:49:56Z", + "level" : 200 + }, { + "message" : "Device AHU-1 config handler", + "category" : "device.log", + "timestamp" : "2023-12-08T05:50:02Z", + "level" : 200 + }, { + "message" : "Update state 2023-12-08T05:50:02Z last_config 2023-12-08T05:49:54Z", + "category" : "device.log", + "timestamp" : "2023-12-08T05:50:02Z", + "level" : 200 + }, { + "message" : "2023-12-08T05:50:02Z received config 2023-12-08T05:50:02Z", + "category" : "device.log", + "timestamp" : "2023-12-08T05:50:02Z", + "level" : 200 + }, { + "message" : "success", + "category" : "system.config.apply", + "timestamp" : "2023-12-08T05:50:02Z", + "level" : 300 + }, { + "message" : "Update state 2023-12-08T05:50:04Z last_config 2023-12-08T05:50:02Z", + "category" : "device.log", + "timestamp" : "2023-12-08T05:50:04Z", + "level" : 200 + } ], "metrics" : { "mem_total_mb" : 250.0, - "mem_free_mb" : 215.45263671875 + "mem_free_mb" : 219.94786071777344 }, - "timestamp" : "2023-07-28T20:25:14Z", - "version" : "1.4.1" + "timestamp" : "2023-12-08T05:50:05Z", + "version" : "1.4.2" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/local_localnet.json b/validator/sequences/system_last_update/local_localnet.json new file mode 100644 index 0000000000..2b858c197f --- /dev/null +++ b/validator/sequences/system_last_update/local_localnet.json @@ -0,0 +1,10 @@ +{ + "families" : { + "ether" : { + "addr" : "00:50:b6:ed:5f:77" + }, + "ipv4" : { + "addr" : "192.168.2.1" + } + } +} \ No newline at end of file diff --git a/validator/sequences/system_last_update/local_pointset.json b/validator/sequences/system_last_update/local_pointset.json new file mode 100644 index 0000000000..9d9265ba98 --- /dev/null +++ b/validator/sequences/system_last_update/local_pointset.json @@ -0,0 +1,16 @@ +{ + "points" : { + "filter_alarm_pressure_status" : { + "ref" : "BV11.present_value", + "units" : "No-units" + }, + "filter_differential_pressure_setpoint" : { + "units" : "Bars", + "set_value" : 98 + }, + "filter_differential_pressure_sensor" : { + "ref" : "AV12.present_value", + "units" : "Degrees-Celsius" + } + } +} \ No newline at end of file diff --git a/validator/sequences/system_last_update/local_system.json b/validator/sequences/system_last_update/local_system.json index bde16f93c7..d569265088 100644 --- a/validator/sequences/system_last_update/local_system.json +++ b/validator/sequences/system_last_update/local_system.json @@ -1,8 +1,8 @@ { "min_loglevel" : 200, - "metrics_rate_sec" : 600, + "metrics_rate_sec" : 10, "operation" : { - "last_start" : "2023-07-28T20:23:12Z" + "last_start" : "2023-12-08T05:49:34Z" }, "testing" : { "sequence_name" : "system_last_update" diff --git a/validator/sequences/system_last_update/local_update.json b/validator/sequences/system_last_update/local_update.json index 3e55d2c8d0..c237dd6123 100644 --- a/validator/sequences/system_last_update/local_update.json +++ b/validator/sequences/system_last_update/local_update.json @@ -1,11 +1,11 @@ { - "timestamp" : "2023-07-28T20:25:20Z", - "version" : "@@@cloud udmi version###1.4.1", + "timestamp" : "2023-12-08T05:50:06Z", + "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", "system" : { "min_loglevel" : 200, - "metrics_rate_sec" : 600, + "metrics_rate_sec" : 10, "operation" : { - "last_start" : "2023-07-28T20:23:12Z" + "last_start" : "2023-12-08T05:49:34Z" }, "testing" : { "sequence_name" : "system_last_update" diff --git a/validator/sequences/system_last_update/sequence.md b/validator/sequences/system_last_update/sequence.md index 528500e8f5..27835695cc 100644 --- a/validator/sequences/system_last_update/sequence.md +++ b/validator/sequences/system_last_update/sequence.md @@ -4,5 +4,10 @@ Check that last_update state is correctly set in response to a config update. 1. Wait for state last_config matches first config timestamp +1. Wait for state update complete 1. Force config update to trigger another config update 1. Wait for state last_config matches new config timestamp +1. Wait for state update complete +1. Force config update to trigger another config update +1. Wait for state last_config matches last config timestamp +1. Wait for state update complete diff --git a/validator/sequences/system_last_update/sequencer.log b/validator/sequences/system_last_update/sequencer.log index d2b8cdeec8..e768670c19 100644 --- a/validator/sequences/system_last_update/sequencer.log +++ b/validator/sequences/system_last_update/sequencer.log @@ -1,781 +1,1728 @@ -2023-07-28T20:25:08Z NOTICE starting test system_last_update ################################ -2023-07-28T20:25:08Z INFO stage start waiting for starting test wrapper at 0s -2023-07-28T20:25:16Z DEBUG Sending device state query -2023-07-28T20:25:16Z DEBUG Starting reset_config full reset false -2023-07-28T20:25:16Z DEBUG Reading generated config file /home/peringknife/udmi/sites/udmi_site_model/devices/AHU-1/out/generated_config.json -2023-07-28T20:25:16Z DEBUG Suppressing exception: java.lang.NullPointerException: Cannot read field "system" because "this.deviceState" is null -2023-07-28T20:25:16Z DEBUG Configuring device last_start to be 1970-01-01T00:01:13Z -2023-07-28T20:25:16Z DEBUG last_start changed true, last_start 1970-01-01T00:01:13Z -2023-07-28T20:25:16Z DEBUG extraFieldChanged false because extra_field null -2023-07-28T20:25:17Z DEBUG system config extra field null -2023-07-28T20:25:17Z TRACE updated check config_system true: { -2023-07-28T20:25:17Z TRACE updated check config_system true: "min_loglevel" : 100, -2023-07-28T20:25:17Z TRACE updated check config_system true: "metrics_rate_sec" : 600, -2023-07-28T20:25:17Z TRACE updated check config_system true: "operation" : { -2023-07-28T20:25:17Z TRACE updated check config_system true: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:17Z TRACE updated check config_system true: }, -2023-07-28T20:25:17Z TRACE updated check config_system true: "testing" : { -2023-07-28T20:25:17Z TRACE updated check config_system true: "sequence_name" : "extra_config" -2023-07-28T20:25:17Z TRACE updated check config_system true: } -2023-07-28T20:25:17Z TRACE updated check config_system true: } -2023-07-28T20:25:17Z DEBUG update config_system, configTransaction RC:1690575917501 -2023-07-28T20:25:17Z TRACE local local_system: { -2023-07-28T20:25:17Z TRACE local local_system: "min_loglevel" : 200, -2023-07-28T20:25:17Z TRACE local local_system: "metrics_rate_sec" : 600, -2023-07-28T20:25:17Z TRACE local local_system: "operation" : { -2023-07-28T20:25:17Z TRACE local local_system: "last_start" : "1970-01-01T00:01:13Z" -2023-07-28T20:25:17Z TRACE local local_system: }, -2023-07-28T20:25:17Z TRACE local local_system: "testing" : { -2023-07-28T20:25:17Z TRACE local local_system: "sequence_name" : "system_last_update" -2023-07-28T20:25:17Z TRACE local local_system: } -2023-07-28T20:25:17Z TRACE local local_system: } -2023-07-28T20:25:17Z TRACE updated check config_pointset false: { -2023-07-28T20:25:17Z TRACE updated check config_pointset false: "points" : { -2023-07-28T20:25:17Z TRACE updated check config_pointset false: "filter_alarm_pressure_status" : { -2023-07-28T20:25:17Z TRACE updated check config_pointset false: "ref" : "BV11.present_value", -2023-07-28T20:25:17Z TRACE updated check config_pointset false: "units" : "No-units" -2023-07-28T20:25:17Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:17Z TRACE updated check config_pointset false: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:17Z TRACE updated check config_pointset false: "units" : "Bars", -2023-07-28T20:25:17Z TRACE updated check config_pointset false: "set_value" : 98 -2023-07-28T20:25:17Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:17Z TRACE updated check config_pointset false: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:17Z TRACE updated check config_pointset false: "ref" : "AV12.present_value", -2023-07-28T20:25:17Z TRACE updated check config_pointset false: "units" : "Degrees-Celsius" -2023-07-28T20:25:17Z TRACE updated check config_pointset false: } -2023-07-28T20:25:17Z TRACE updated check config_pointset false: } -2023-07-28T20:25:17Z TRACE updated check config_pointset false: } -2023-07-28T20:25:17Z TRACE updated check config_gateway false: null -2023-07-28T20:25:17Z TRACE updated check config_localnet false: { -2023-07-28T20:25:17Z TRACE updated check config_localnet false: "families" : { -2023-07-28T20:25:17Z TRACE updated check config_localnet false: "ether" : { -2023-07-28T20:25:17Z TRACE updated check config_localnet false: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:17Z TRACE updated check config_localnet false: }, -2023-07-28T20:25:17Z TRACE updated check config_localnet false: "ipv4" : { -2023-07-28T20:25:17Z TRACE updated check config_localnet false: "addr" : "192.168.2.1" -2023-07-28T20:25:17Z TRACE updated check config_localnet false: } -2023-07-28T20:25:17Z TRACE updated check config_localnet false: } -2023-07-28T20:25:17Z TRACE updated check config_localnet false: } -2023-07-28T20:25:17Z TRACE updated check config_blobset false: null -2023-07-28T20:25:17Z TRACE updated check config_discovery false: null -2023-07-28T20:25:17Z DEBUG Suppressing exception: java.lang.NullPointerException: Cannot read field "system" because "this.deviceState" is null -2023-07-28T20:25:17Z DEBUG Suppressing exception: java.lang.NullPointerException: Cannot read field "system" because "this.deviceState" is null -2023-07-28T20:25:17Z DEBUG Update lastConfigUpdate 2023-07-28T20:25:17Z, because soft reset -2023-07-28T20:25:17Z TRACE stage suspend waiting for starting test wrapper at 9s -2023-07-28T20:25:17Z INFO stage start waiting for config sync at 9s -2023-07-28T20:25:17Z DEBUG Suppressing exception: java.lang.NullPointerException: Cannot read field "system" because "this.deviceState" is null -2023-07-28T20:25:17Z TRACE received command AHU-1/event/pointset -2023-07-28T20:25:17Z TRACE received event_pointset: { -2023-07-28T20:25:17Z TRACE received event_pointset: "points" : { -2023-07-28T20:25:17Z TRACE received event_pointset: "filter_alarm_pressure_status" : { -2023-07-28T20:25:17Z TRACE received event_pointset: "present_value" : true -2023-07-28T20:25:17Z TRACE received event_pointset: }, -2023-07-28T20:25:17Z TRACE received event_pointset: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:17Z TRACE received event_pointset: "present_value" : 98 -2023-07-28T20:25:17Z TRACE received event_pointset: }, -2023-07-28T20:25:17Z TRACE received event_pointset: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:17Z TRACE received event_pointset: "present_value" : 11 -2023-07-28T20:25:17Z TRACE received event_pointset: } -2023-07-28T20:25:17Z TRACE received event_pointset: }, -2023-07-28T20:25:17Z TRACE received event_pointset: "timestamp" : "2023-07-28T20:25:14Z", -2023-07-28T20:25:17Z TRACE received event_pointset: "version" : "1.4.1" -2023-07-28T20:25:17Z TRACE received event_pointset: } -2023-07-28T20:25:17Z DEBUG Handling device message event/pointset PS:8733061839528052 -2023-07-28T20:25:17Z DEBUG Suppressing exception: java.lang.NullPointerException: Cannot read field "system" because "this.deviceState" is null -2023-07-28T20:25:17Z TRACE received command AHU-1/event/system -2023-07-28T20:25:17Z DEBUG received event_system (no logs) -2023-07-28T20:25:17Z DEBUG Handling device message event/system PS:8732122066857171 -2023-07-28T20:25:17Z DEBUG Suppressing exception: java.lang.NullPointerException: Cannot read field "system" because "this.deviceState" is null -2023-07-28T20:25:17Z TRACE received command AHU-1/state/update -2023-07-28T20:25:17Z DEBUG received state_update -2023-07-28T20:25:17Z DEBUG Updated state after 16s 2023-07-28T20:25:01Z RC:1690575916497 -2023-07-28T20:25:17Z INFO Updated state #105: Changed 0 fields. -2023-07-28T20:25:17Z NOTICE Received serial number sequencer-13214 -2023-07-28T20:25:17Z DEBUG Updated state has last_config 2023-07-28T20:24:59Z (expecting null) -2023-07-28T20:25:17Z TRACE received command AHU-1/reply/update -2023-07-28T20:25:17Z TRACE received command AHU-1/config/update -2023-07-28T20:25:17Z DEBUG received config_update -2023-07-28T20:25:17Z DEBUG Removing configTransaction RC:1690575917501 -2023-07-28T20:25:17Z DEBUG last_start changed false, last_start 1970-01-01T00:01:13Z -2023-07-28T20:25:17Z DEBUG Updated config 2023-07-28T20:25:17Z RC:1690575917501 -2023-07-28T20:25:17Z INFO Updated config #072: Changed 2 fields: -2023-07-28T20:25:17Z INFO Updated config #072: Set `system.min_loglevel` = `200` -2023-07-28T20:25:17Z INFO Updated config #072: Set `system.testing.sequence_name` = `system_last_update` -2023-07-28T20:25:17Z TRACE received command AHU-1/state/update -2023-07-28T20:25:17Z DEBUG received state_update -2023-07-28T20:25:17Z DEBUG Updated state after 0s 2023-07-28T20:25:17Z PS:8733068905752338 -2023-07-28T20:25:17Z INFO Updated state #106: Changed 1 fields: -2023-07-28T20:25:17Z INFO Updated state #106: Set `timestamp` = `2023-07-28T20:25:17Z` -2023-07-28T20:25:17Z DEBUG Updated state has last_config 2023-07-28T20:24:59Z (expecting 2023-07-28T20:25:17Z) -2023-07-28T20:25:17Z TRACE received command AHU-1/state/system -2023-07-28T20:25:17Z TRACE received state_system: { -2023-07-28T20:25:17Z TRACE received state_system: "hardware" : { -2023-07-28T20:25:17Z TRACE received state_system: "make" : "BOS", -2023-07-28T20:25:17Z TRACE received state_system: "model" : "pubber" -2023-07-28T20:25:17Z TRACE received state_system: }, -2023-07-28T20:25:17Z TRACE received state_system: "last_config" : "2023-07-28T20:24:59Z", -2023-07-28T20:25:17Z TRACE received state_system: "operation" : { -2023-07-28T20:25:17Z TRACE received state_system: "operational" : true, -2023-07-28T20:25:17Z TRACE received state_system: "last_start" : "2023-07-28T20:23:12Z", -2023-07-28T20:25:17Z TRACE received state_system: "restart_count" : 3, -2023-07-28T20:25:17Z TRACE received state_system: "mode" : "active" -2023-07-28T20:25:17Z TRACE received state_system: }, -2023-07-28T20:25:17Z TRACE received state_system: "serial_no" : "sequencer-13214", -2023-07-28T20:25:17Z TRACE received state_system: "software" : { -2023-07-28T20:25:17Z TRACE received state_system: "firmware" : "v1" -2023-07-28T20:25:17Z TRACE received state_system: }, -2023-07-28T20:25:17Z TRACE received state_system: "status" : { -2023-07-28T20:25:17Z TRACE received state_system: "message" : "success", -2023-07-28T20:25:17Z TRACE received state_system: "category" : "system.config.apply", -2023-07-28T20:25:17Z TRACE received state_system: "timestamp" : "2023-07-28T20:24:59Z", -2023-07-28T20:25:17Z TRACE received state_system: "level" : 300 -2023-07-28T20:25:17Z TRACE received state_system: }, -2023-07-28T20:25:17Z TRACE received state_system: "timestamp" : "2023-07-28T20:25:17Z", -2023-07-28T20:25:17Z TRACE received state_system: "version" : "1.4.1" -2023-07-28T20:25:17Z TRACE received state_system: } -2023-07-28T20:25:17Z DEBUG Handling device message state/system PS:8733068905752338-0 -2023-07-28T20:25:17Z TRACE Ignoring partial state update -2023-07-28T20:25:17Z TRACE received command AHU-1/state/localnet -2023-07-28T20:25:17Z TRACE received state_localnet: { -2023-07-28T20:25:17Z TRACE received state_localnet: "families" : { -2023-07-28T20:25:17Z TRACE received state_localnet: "ether" : { -2023-07-28T20:25:17Z TRACE received state_localnet: "addr" : "40:1c:83:ca:77:54" -2023-07-28T20:25:17Z TRACE received state_localnet: }, -2023-07-28T20:25:17Z TRACE received state_localnet: "ipv4" : { -2023-07-28T20:25:17Z TRACE received state_localnet: "addr" : "10.0.0.142" -2023-07-28T20:25:17Z TRACE received state_localnet: }, -2023-07-28T20:25:17Z TRACE received state_localnet: "ipv6" : { -2023-07-28T20:25:17Z TRACE received state_localnet: "addr" : "fe80::134f:c1f5:f225:a441" -2023-07-28T20:25:17Z TRACE received state_localnet: } -2023-07-28T20:25:17Z TRACE received state_localnet: }, -2023-07-28T20:25:17Z TRACE received state_localnet: "timestamp" : "2023-07-28T20:25:17Z", -2023-07-28T20:25:17Z TRACE received state_localnet: "version" : "1.4.1" -2023-07-28T20:25:17Z TRACE received state_localnet: } -2023-07-28T20:25:17Z DEBUG Handling device message state/localnet PS:8733068905752338-1 -2023-07-28T20:25:17Z TRACE Ignoring partial state update -2023-07-28T20:25:17Z TRACE received command AHU-1/state/pointset -2023-07-28T20:25:17Z TRACE received state_pointset: { -2023-07-28T20:25:17Z TRACE received state_pointset: "points" : { -2023-07-28T20:25:17Z TRACE received state_pointset: "filter_alarm_pressure_status" : { }, -2023-07-28T20:25:17Z TRACE received state_pointset: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:17Z TRACE received state_pointset: "units" : "Bars", -2023-07-28T20:25:17Z TRACE received state_pointset: "value_state" : "applied" -2023-07-28T20:25:17Z TRACE received state_pointset: }, -2023-07-28T20:25:17Z TRACE received state_pointset: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:17Z TRACE received state_pointset: "units" : "Degrees-Celsius" -2023-07-28T20:25:17Z TRACE received state_pointset: } -2023-07-28T20:25:17Z TRACE received state_pointset: }, -2023-07-28T20:25:17Z TRACE received state_pointset: "timestamp" : "2023-07-28T20:25:17Z", -2023-07-28T20:25:17Z TRACE received state_pointset: "version" : "1.4.1" -2023-07-28T20:25:17Z TRACE received state_pointset: } -2023-07-28T20:25:17Z DEBUG Handling device message state/pointset PS:8733068905752338-2 -2023-07-28T20:25:17Z TRACE Ignoring partial state update -2023-07-28T20:25:19Z TRACE received command AHU-1/config/update -2023-07-28T20:25:19Z DEBUG received config_update -2023-07-28T20:25:19Z DEBUG Removing configTransaction PS:8733068905752338 -2023-07-28T20:25:19Z DEBUG last_start changed true, last_start 2023-07-28T20:23:12Z -2023-07-28T20:25:19Z DEBUG Updated config 2023-07-28T20:25:17Z PS:8733068905752338 -2023-07-28T20:25:19Z INFO Updated config #073: Changed 0 fields. -2023-07-28T20:25:19Z DEBUG stage finished waiting for config sync at 10s after 1s -2023-07-28T20:25:19Z TRACE stage resume waiting for starting test wrapper at 10s -2023-07-28T20:25:19Z DEBUG Configuration sync took 2s -2023-07-28T20:25:19Z DEBUG wait for config sync pending false -2023-07-28T20:25:19Z DEBUG Update config soft reset: 2023-07-28T20:25:17Z -2023-07-28T20:25:19Z TRACE local local_update: { -2023-07-28T20:25:19Z TRACE local local_update: "timestamp" : "2023-07-28T20:25:17Z", -2023-07-28T20:25:19Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.1", -2023-07-28T20:25:19Z TRACE local local_update: "system" : { -2023-07-28T20:25:19Z TRACE local local_update: "min_loglevel" : 200, -2023-07-28T20:25:19Z TRACE local local_update: "metrics_rate_sec" : 600, -2023-07-28T20:25:19Z TRACE local local_update: "operation" : { -2023-07-28T20:25:19Z TRACE local local_update: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:19Z TRACE local local_update: }, -2023-07-28T20:25:19Z TRACE local local_update: "testing" : { -2023-07-28T20:25:19Z TRACE local local_update: "sequence_name" : "system_last_update" -2023-07-28T20:25:19Z TRACE local local_update: } -2023-07-28T20:25:19Z TRACE local local_update: }, -2023-07-28T20:25:19Z TRACE local local_update: "localnet" : { -2023-07-28T20:25:19Z TRACE local local_update: "families" : { -2023-07-28T20:25:19Z TRACE local local_update: "ether" : { -2023-07-28T20:25:19Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:19Z TRACE local local_update: }, -2023-07-28T20:25:19Z TRACE local local_update: "ipv4" : { -2023-07-28T20:25:19Z TRACE local local_update: "addr" : "192.168.2.1" -2023-07-28T20:25:19Z TRACE local local_update: } -2023-07-28T20:25:19Z TRACE local local_update: } -2023-07-28T20:25:19Z TRACE local local_update: }, -2023-07-28T20:25:19Z TRACE local local_update: "pointset" : { -2023-07-28T20:25:19Z TRACE local local_update: "points" : { -2023-07-28T20:25:19Z TRACE local local_update: "filter_alarm_pressure_status" : { -2023-07-28T20:25:19Z TRACE local local_update: "ref" : "BV11.present_value", -2023-07-28T20:25:19Z TRACE local local_update: "units" : "No-units" -2023-07-28T20:25:19Z TRACE local local_update: }, -2023-07-28T20:25:19Z TRACE local local_update: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:19Z TRACE local local_update: "units" : "Bars", -2023-07-28T20:25:19Z TRACE local local_update: "set_value" : 98 -2023-07-28T20:25:19Z TRACE local local_update: }, -2023-07-28T20:25:19Z TRACE local local_update: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:19Z TRACE local local_update: "ref" : "AV12.present_value", -2023-07-28T20:25:19Z TRACE local local_update: "units" : "Degrees-Celsius" -2023-07-28T20:25:19Z TRACE local local_update: } -2023-07-28T20:25:19Z TRACE local local_update: } -2023-07-28T20:25:19Z TRACE local local_update: } -2023-07-28T20:25:19Z TRACE local local_update: } -2023-07-28T20:25:19Z TRACE Update config soft reset: Set `system.min_loglevel` = `200` -2023-07-28T20:25:19Z DEBUG Done with reset_config -2023-07-28T20:25:20Z DEBUG system config extra field null -2023-07-28T20:25:20Z TRACE updated check config_system true: { -2023-07-28T20:25:20Z TRACE updated check config_system true: "min_loglevel" : 200, -2023-07-28T20:25:20Z TRACE updated check config_system true: "metrics_rate_sec" : 600, -2023-07-28T20:25:20Z TRACE updated check config_system true: "operation" : { -2023-07-28T20:25:20Z TRACE updated check config_system true: "last_start" : "1970-01-01T00:01:13Z" -2023-07-28T20:25:20Z TRACE updated check config_system true: }, -2023-07-28T20:25:20Z TRACE updated check config_system true: "testing" : { -2023-07-28T20:25:20Z TRACE updated check config_system true: "sequence_name" : "system_last_update" -2023-07-28T20:25:20Z TRACE updated check config_system true: } -2023-07-28T20:25:20Z TRACE updated check config_system true: } -2023-07-28T20:25:20Z DEBUG update config_system, configTransaction RC:1690575920093 -2023-07-28T20:25:20Z TRACE local local_system: { -2023-07-28T20:25:20Z TRACE local local_system: "min_loglevel" : 200, -2023-07-28T20:25:20Z TRACE local local_system: "metrics_rate_sec" : 600, -2023-07-28T20:25:20Z TRACE local local_system: "operation" : { -2023-07-28T20:25:20Z TRACE local local_system: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:20Z TRACE local local_system: }, -2023-07-28T20:25:20Z TRACE local local_system: "testing" : { -2023-07-28T20:25:20Z TRACE local local_system: "sequence_name" : "system_last_update" -2023-07-28T20:25:20Z TRACE local local_system: } -2023-07-28T20:25:20Z TRACE local local_system: } -2023-07-28T20:25:20Z TRACE updated check config_pointset false: { -2023-07-28T20:25:20Z TRACE updated check config_pointset false: "points" : { -2023-07-28T20:25:20Z TRACE updated check config_pointset false: "filter_alarm_pressure_status" : { -2023-07-28T20:25:20Z TRACE updated check config_pointset false: "ref" : "BV11.present_value", -2023-07-28T20:25:20Z TRACE updated check config_pointset false: "units" : "No-units" -2023-07-28T20:25:20Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:20Z TRACE updated check config_pointset false: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:20Z TRACE updated check config_pointset false: "units" : "Bars", -2023-07-28T20:25:20Z TRACE updated check config_pointset false: "set_value" : 98 -2023-07-28T20:25:20Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:20Z TRACE updated check config_pointset false: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:20Z TRACE updated check config_pointset false: "ref" : "AV12.present_value", -2023-07-28T20:25:20Z TRACE updated check config_pointset false: "units" : "Degrees-Celsius" -2023-07-28T20:25:20Z TRACE updated check config_pointset false: } -2023-07-28T20:25:20Z TRACE updated check config_pointset false: } -2023-07-28T20:25:20Z TRACE updated check config_pointset false: } -2023-07-28T20:25:20Z TRACE updated check config_gateway false: null -2023-07-28T20:25:20Z TRACE updated check config_localnet false: { -2023-07-28T20:25:20Z TRACE updated check config_localnet false: "families" : { -2023-07-28T20:25:20Z TRACE updated check config_localnet false: "ether" : { -2023-07-28T20:25:20Z TRACE updated check config_localnet false: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:20Z TRACE updated check config_localnet false: }, -2023-07-28T20:25:20Z TRACE updated check config_localnet false: "ipv4" : { -2023-07-28T20:25:20Z TRACE updated check config_localnet false: "addr" : "192.168.2.1" -2023-07-28T20:25:20Z TRACE updated check config_localnet false: } -2023-07-28T20:25:20Z TRACE updated check config_localnet false: } -2023-07-28T20:25:20Z TRACE updated check config_localnet false: } -2023-07-28T20:25:20Z TRACE updated check config_blobset false: null -2023-07-28T20:25:20Z TRACE updated check config_discovery false: null -2023-07-28T20:25:20Z DEBUG Update lastConfigUpdate 2023-07-28T20:25:20Z, because initial setup -2023-07-28T20:25:20Z TRACE stage suspend waiting for starting test wrapper at 11s -2023-07-28T20:25:20Z INFO stage start waiting for config sync at 11s -2023-07-28T20:25:20Z TRACE received command AHU-1/state/update -2023-07-28T20:25:20Z DEBUG received state_update -2023-07-28T20:25:20Z DEBUG Updated state after 1s 2023-07-28T20:25:19Z PS:8733148995582613 -2023-07-28T20:25:20Z INFO Updated state #107: Changed 3 fields: -2023-07-28T20:25:20Z INFO Updated state #107: Set `system.last_config` = `2023-07-28T20:25:17Z` -2023-07-28T20:25:20Z INFO Updated state #107: Set `system.status.timestamp` = `2023-07-28T20:25:19Z` -2023-07-28T20:25:20Z INFO Updated state #107: Set `timestamp` = `2023-07-28T20:25:19Z` -2023-07-28T20:25:20Z DEBUG Updated state has last_config 2023-07-28T20:25:17Z (expecting 2023-07-28T20:25:17Z) -2023-07-28T20:25:20Z TRACE received command AHU-1/state/system -2023-07-28T20:25:20Z TRACE received state_system: { -2023-07-28T20:25:20Z TRACE received state_system: "hardware" : { -2023-07-28T20:25:20Z TRACE received state_system: "make" : "BOS", -2023-07-28T20:25:20Z TRACE received state_system: "model" : "pubber" -2023-07-28T20:25:20Z TRACE received state_system: }, -2023-07-28T20:25:20Z TRACE received state_system: "last_config" : "2023-07-28T20:25:17Z", -2023-07-28T20:25:20Z TRACE received state_system: "operation" : { -2023-07-28T20:25:20Z TRACE received state_system: "operational" : true, -2023-07-28T20:25:20Z TRACE received state_system: "last_start" : "2023-07-28T20:23:12Z", -2023-07-28T20:25:20Z TRACE received state_system: "restart_count" : 3, -2023-07-28T20:25:20Z TRACE received state_system: "mode" : "active" -2023-07-28T20:25:20Z TRACE received state_system: }, -2023-07-28T20:25:20Z TRACE received state_system: "serial_no" : "sequencer-13214", -2023-07-28T20:25:20Z TRACE received state_system: "software" : { -2023-07-28T20:25:20Z TRACE received state_system: "firmware" : "v1" -2023-07-28T20:25:20Z TRACE received state_system: }, -2023-07-28T20:25:20Z TRACE received state_system: "status" : { -2023-07-28T20:25:20Z TRACE received state_system: "message" : "success", -2023-07-28T20:25:20Z TRACE received state_system: "category" : "system.config.apply", -2023-07-28T20:25:20Z TRACE received state_system: "timestamp" : "2023-07-28T20:25:19Z", -2023-07-28T20:25:20Z TRACE received state_system: "level" : 300 -2023-07-28T20:25:20Z TRACE received state_system: }, -2023-07-28T20:25:20Z TRACE received state_system: "timestamp" : "2023-07-28T20:25:19Z", -2023-07-28T20:25:20Z TRACE received state_system: "version" : "1.4.1" -2023-07-28T20:25:20Z TRACE received state_system: } -2023-07-28T20:25:20Z DEBUG Handling device message state/system PS:8733148995582613-0 -2023-07-28T20:25:20Z TRACE Ignoring partial state update -2023-07-28T20:25:20Z TRACE received command AHU-1/state/localnet -2023-07-28T20:25:20Z TRACE received state_localnet: { -2023-07-28T20:25:20Z TRACE received state_localnet: "families" : { -2023-07-28T20:25:20Z TRACE received state_localnet: "ether" : { -2023-07-28T20:25:20Z TRACE received state_localnet: "addr" : "40:1c:83:ca:77:54" -2023-07-28T20:25:20Z TRACE received state_localnet: }, -2023-07-28T20:25:20Z TRACE received state_localnet: "ipv4" : { -2023-07-28T20:25:20Z TRACE received state_localnet: "addr" : "10.0.0.142" -2023-07-28T20:25:20Z TRACE received state_localnet: }, -2023-07-28T20:25:20Z TRACE received state_localnet: "ipv6" : { -2023-07-28T20:25:20Z TRACE received state_localnet: "addr" : "fe80::134f:c1f5:f225:a441" -2023-07-28T20:25:20Z TRACE received state_localnet: } -2023-07-28T20:25:20Z TRACE received state_localnet: }, -2023-07-28T20:25:20Z TRACE received state_localnet: "timestamp" : "2023-07-28T20:25:19Z", -2023-07-28T20:25:20Z TRACE received state_localnet: "version" : "1.4.1" -2023-07-28T20:25:20Z TRACE received state_localnet: } -2023-07-28T20:25:20Z DEBUG Handling device message state/localnet PS:8733148995582613-1 -2023-07-28T20:25:20Z TRACE Ignoring partial state update -2023-07-28T20:25:20Z TRACE received command AHU-1/state/pointset -2023-07-28T20:25:20Z TRACE received state_pointset: { -2023-07-28T20:25:20Z TRACE received state_pointset: "points" : { -2023-07-28T20:25:20Z TRACE received state_pointset: "filter_alarm_pressure_status" : { }, -2023-07-28T20:25:20Z TRACE received state_pointset: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:20Z TRACE received state_pointset: "units" : "Bars", -2023-07-28T20:25:20Z TRACE received state_pointset: "value_state" : "applied" -2023-07-28T20:25:20Z TRACE received state_pointset: }, -2023-07-28T20:25:20Z TRACE received state_pointset: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:20Z TRACE received state_pointset: "units" : "Degrees-Celsius" -2023-07-28T20:25:20Z TRACE received state_pointset: } -2023-07-28T20:25:20Z TRACE received state_pointset: }, -2023-07-28T20:25:20Z TRACE received state_pointset: "timestamp" : "2023-07-28T20:25:19Z", -2023-07-28T20:25:20Z TRACE received state_pointset: "version" : "1.4.1" -2023-07-28T20:25:20Z TRACE received state_pointset: } -2023-07-28T20:25:20Z DEBUG Handling device message state/pointset PS:8733148995582613-2 -2023-07-28T20:25:20Z TRACE Ignoring partial state update -2023-07-28T20:25:20Z TRACE received command AHU-1/config/update -2023-07-28T20:25:20Z DEBUG received config_update -2023-07-28T20:25:20Z DEBUG Removing configTransaction RC:1690575920093 -2023-07-28T20:25:20Z DEBUG last_start changed false, last_start 2023-07-28T20:23:12Z -2023-07-28T20:25:20Z DEBUG Updated config 2023-07-28T20:25:20Z RC:1690575920093 -2023-07-28T20:25:20Z INFO Updated config #074: Changed 0 fields. -2023-07-28T20:25:20Z DEBUG stage finished waiting for config sync at 11s after 0s -2023-07-28T20:25:20Z TRACE stage resume waiting for starting test wrapper at 11s -2023-07-28T20:25:20Z DEBUG Configuration sync took 0s -2023-07-28T20:25:20Z DEBUG wait for config sync pending false -2023-07-28T20:25:20Z DEBUG Update config initial setup: 2023-07-28T20:25:20Z -2023-07-28T20:25:20Z TRACE local local_update: { -2023-07-28T20:25:20Z TRACE local local_update: "timestamp" : "2023-07-28T20:25:20Z", -2023-07-28T20:25:20Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.1", -2023-07-28T20:25:20Z TRACE local local_update: "system" : { -2023-07-28T20:25:20Z TRACE local local_update: "min_loglevel" : 200, -2023-07-28T20:25:20Z TRACE local local_update: "metrics_rate_sec" : 600, -2023-07-28T20:25:20Z TRACE local local_update: "operation" : { -2023-07-28T20:25:20Z TRACE local local_update: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:20Z TRACE local local_update: }, -2023-07-28T20:25:20Z TRACE local local_update: "testing" : { -2023-07-28T20:25:20Z TRACE local local_update: "sequence_name" : "system_last_update" -2023-07-28T20:25:20Z TRACE local local_update: } -2023-07-28T20:25:20Z TRACE local local_update: }, -2023-07-28T20:25:20Z TRACE local local_update: "localnet" : { -2023-07-28T20:25:20Z TRACE local local_update: "families" : { -2023-07-28T20:25:20Z TRACE local local_update: "ether" : { -2023-07-28T20:25:20Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:20Z TRACE local local_update: }, -2023-07-28T20:25:20Z TRACE local local_update: "ipv4" : { -2023-07-28T20:25:20Z TRACE local local_update: "addr" : "192.168.2.1" -2023-07-28T20:25:20Z TRACE local local_update: } -2023-07-28T20:25:20Z TRACE local local_update: } -2023-07-28T20:25:20Z TRACE local local_update: }, -2023-07-28T20:25:20Z TRACE local local_update: "pointset" : { -2023-07-28T20:25:20Z TRACE local local_update: "points" : { -2023-07-28T20:25:20Z TRACE local local_update: "filter_alarm_pressure_status" : { -2023-07-28T20:25:20Z TRACE local local_update: "ref" : "BV11.present_value", -2023-07-28T20:25:20Z TRACE local local_update: "units" : "No-units" -2023-07-28T20:25:20Z TRACE local local_update: }, -2023-07-28T20:25:20Z TRACE local local_update: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:20Z TRACE local local_update: "units" : "Bars", -2023-07-28T20:25:20Z TRACE local local_update: "set_value" : 98 -2023-07-28T20:25:20Z TRACE local local_update: }, -2023-07-28T20:25:20Z TRACE local local_update: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:20Z TRACE local local_update: "ref" : "AV12.present_value", -2023-07-28T20:25:20Z TRACE local local_update: "units" : "Degrees-Celsius" -2023-07-28T20:25:20Z TRACE local local_update: } -2023-07-28T20:25:20Z TRACE local local_update: } -2023-07-28T20:25:20Z TRACE local local_update: } -2023-07-28T20:25:20Z TRACE local local_update: } -2023-07-28T20:25:20Z TRACE stage suspend waiting for starting test wrapper at 11s -2023-07-28T20:25:20Z INFO stage start waiting for device state update at 11s -2023-07-28T20:25:21Z DEBUG system config extra field null -2023-07-28T20:25:21Z TRACE updated check config_system false: { -2023-07-28T20:25:21Z TRACE updated check config_system false: "min_loglevel" : 200, -2023-07-28T20:25:21Z TRACE updated check config_system false: "metrics_rate_sec" : 600, -2023-07-28T20:25:21Z TRACE updated check config_system false: "operation" : { -2023-07-28T20:25:21Z TRACE updated check config_system false: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:21Z TRACE updated check config_system false: }, -2023-07-28T20:25:21Z TRACE updated check config_system false: "testing" : { -2023-07-28T20:25:21Z TRACE updated check config_system false: "sequence_name" : "system_last_update" -2023-07-28T20:25:21Z TRACE updated check config_system false: } -2023-07-28T20:25:21Z TRACE updated check config_system false: } -2023-07-28T20:25:21Z TRACE updated check config_pointset false: { -2023-07-28T20:25:21Z TRACE updated check config_pointset false: "points" : { -2023-07-28T20:25:21Z TRACE updated check config_pointset false: "filter_alarm_pressure_status" : { -2023-07-28T20:25:21Z TRACE updated check config_pointset false: "ref" : "BV11.present_value", -2023-07-28T20:25:21Z TRACE updated check config_pointset false: "units" : "No-units" -2023-07-28T20:25:21Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:21Z TRACE updated check config_pointset false: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:21Z TRACE updated check config_pointset false: "units" : "Bars", -2023-07-28T20:25:21Z TRACE updated check config_pointset false: "set_value" : 98 -2023-07-28T20:25:21Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:21Z TRACE updated check config_pointset false: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:21Z TRACE updated check config_pointset false: "ref" : "AV12.present_value", -2023-07-28T20:25:21Z TRACE updated check config_pointset false: "units" : "Degrees-Celsius" -2023-07-28T20:25:21Z TRACE updated check config_pointset false: } -2023-07-28T20:25:21Z TRACE updated check config_pointset false: } -2023-07-28T20:25:21Z TRACE updated check config_pointset false: } -2023-07-28T20:25:21Z TRACE updated check config_gateway false: null -2023-07-28T20:25:21Z TRACE updated check config_localnet false: { -2023-07-28T20:25:21Z TRACE updated check config_localnet false: "families" : { -2023-07-28T20:25:21Z TRACE updated check config_localnet false: "ether" : { -2023-07-28T20:25:21Z TRACE updated check config_localnet false: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:21Z TRACE updated check config_localnet false: }, -2023-07-28T20:25:21Z TRACE updated check config_localnet false: "ipv4" : { -2023-07-28T20:25:21Z TRACE updated check config_localnet false: "addr" : "192.168.2.1" -2023-07-28T20:25:21Z TRACE updated check config_localnet false: } -2023-07-28T20:25:21Z TRACE updated check config_localnet false: } -2023-07-28T20:25:21Z TRACE updated check config_localnet false: } -2023-07-28T20:25:21Z TRACE updated check config_blobset false: null -2023-07-28T20:25:21Z TRACE updated check config_discovery false: null -2023-07-28T20:25:21Z DEBUG Update config before device state update: 2023-07-28T20:25:20Z -2023-07-28T20:25:21Z TRACE local local_update: { -2023-07-28T20:25:21Z TRACE local local_update: "timestamp" : "2023-07-28T20:25:20Z", -2023-07-28T20:25:21Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.1", -2023-07-28T20:25:21Z TRACE local local_update: "system" : { -2023-07-28T20:25:21Z TRACE local local_update: "min_loglevel" : 200, -2023-07-28T20:25:21Z TRACE local local_update: "metrics_rate_sec" : 600, -2023-07-28T20:25:21Z TRACE local local_update: "operation" : { -2023-07-28T20:25:21Z TRACE local local_update: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:21Z TRACE local local_update: }, -2023-07-28T20:25:21Z TRACE local local_update: "testing" : { -2023-07-28T20:25:21Z TRACE local local_update: "sequence_name" : "system_last_update" -2023-07-28T20:25:21Z TRACE local local_update: } -2023-07-28T20:25:21Z TRACE local local_update: }, -2023-07-28T20:25:21Z TRACE local local_update: "localnet" : { -2023-07-28T20:25:21Z TRACE local local_update: "families" : { -2023-07-28T20:25:21Z TRACE local local_update: "ether" : { -2023-07-28T20:25:21Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:21Z TRACE local local_update: }, -2023-07-28T20:25:21Z TRACE local local_update: "ipv4" : { -2023-07-28T20:25:21Z TRACE local local_update: "addr" : "192.168.2.1" -2023-07-28T20:25:21Z TRACE local local_update: } -2023-07-28T20:25:21Z TRACE local local_update: } -2023-07-28T20:25:21Z TRACE local local_update: }, -2023-07-28T20:25:21Z TRACE local local_update: "pointset" : { -2023-07-28T20:25:21Z TRACE local local_update: "points" : { -2023-07-28T20:25:21Z TRACE local local_update: "filter_alarm_pressure_status" : { -2023-07-28T20:25:21Z TRACE local local_update: "ref" : "BV11.present_value", -2023-07-28T20:25:21Z TRACE local local_update: "units" : "No-units" -2023-07-28T20:25:21Z TRACE local local_update: }, -2023-07-28T20:25:21Z TRACE local local_update: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:21Z TRACE local local_update: "units" : "Bars", -2023-07-28T20:25:21Z TRACE local local_update: "set_value" : 98 -2023-07-28T20:25:21Z TRACE local local_update: }, -2023-07-28T20:25:21Z TRACE local local_update: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:21Z TRACE local local_update: "ref" : "AV12.present_value", -2023-07-28T20:25:21Z TRACE local local_update: "units" : "Degrees-Celsius" -2023-07-28T20:25:21Z TRACE local local_update: } -2023-07-28T20:25:21Z TRACE local local_update: } -2023-07-28T20:25:21Z TRACE local local_update: } -2023-07-28T20:25:21Z TRACE local local_update: } -2023-07-28T20:25:21Z DEBUG stage finished waiting for device state update at 12s after 1s -2023-07-28T20:25:21Z TRACE stage resume waiting for starting test wrapper at 12s -2023-07-28T20:25:21Z TRACE stage suspend waiting for starting test wrapper at 12s -2023-07-28T20:25:21Z INFO stage start waiting for executing test at 12s -2023-07-28T20:25:21Z DEBUG stage begin waiting for executing test at 12s -2023-07-28T20:25:21Z TRACE stage suspend waiting for executing test at 12s -2023-07-28T20:25:21Z INFO stage start waiting for state last_config matches config timestamp at 12s -2023-07-28T20:25:22Z DEBUG system config extra field null -2023-07-28T20:25:22Z TRACE updated check config_system false: { -2023-07-28T20:25:22Z TRACE updated check config_system false: "min_loglevel" : 200, -2023-07-28T20:25:22Z TRACE updated check config_system false: "metrics_rate_sec" : 600, -2023-07-28T20:25:22Z TRACE updated check config_system false: "operation" : { -2023-07-28T20:25:22Z TRACE updated check config_system false: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:22Z TRACE updated check config_system false: }, -2023-07-28T20:25:22Z TRACE updated check config_system false: "testing" : { -2023-07-28T20:25:22Z TRACE updated check config_system false: "sequence_name" : "system_last_update" -2023-07-28T20:25:22Z TRACE updated check config_system false: } -2023-07-28T20:25:22Z TRACE updated check config_system false: } -2023-07-28T20:25:22Z TRACE updated check config_pointset false: { -2023-07-28T20:25:22Z TRACE updated check config_pointset false: "points" : { -2023-07-28T20:25:22Z TRACE updated check config_pointset false: "filter_alarm_pressure_status" : { -2023-07-28T20:25:22Z TRACE updated check config_pointset false: "ref" : "BV11.present_value", -2023-07-28T20:25:22Z TRACE updated check config_pointset false: "units" : "No-units" -2023-07-28T20:25:22Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:22Z TRACE updated check config_pointset false: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:22Z TRACE updated check config_pointset false: "units" : "Bars", -2023-07-28T20:25:22Z TRACE updated check config_pointset false: "set_value" : 98 -2023-07-28T20:25:22Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:22Z TRACE updated check config_pointset false: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:22Z TRACE updated check config_pointset false: "ref" : "AV12.present_value", -2023-07-28T20:25:22Z TRACE updated check config_pointset false: "units" : "Degrees-Celsius" -2023-07-28T20:25:22Z TRACE updated check config_pointset false: } -2023-07-28T20:25:22Z TRACE updated check config_pointset false: } -2023-07-28T20:25:22Z TRACE updated check config_pointset false: } -2023-07-28T20:25:22Z TRACE updated check config_gateway false: null -2023-07-28T20:25:22Z TRACE updated check config_localnet false: { -2023-07-28T20:25:22Z TRACE updated check config_localnet false: "families" : { -2023-07-28T20:25:22Z TRACE updated check config_localnet false: "ether" : { -2023-07-28T20:25:22Z TRACE updated check config_localnet false: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:22Z TRACE updated check config_localnet false: }, -2023-07-28T20:25:22Z TRACE updated check config_localnet false: "ipv4" : { -2023-07-28T20:25:22Z TRACE updated check config_localnet false: "addr" : "192.168.2.1" -2023-07-28T20:25:22Z TRACE updated check config_localnet false: } -2023-07-28T20:25:22Z TRACE updated check config_localnet false: } -2023-07-28T20:25:22Z TRACE updated check config_localnet false: } -2023-07-28T20:25:22Z TRACE updated check config_blobset false: null -2023-07-28T20:25:22Z TRACE updated check config_discovery false: null -2023-07-28T20:25:22Z DEBUG Update config before state last_config matches config timestamp: 2023-07-28T20:25:20Z -2023-07-28T20:25:22Z TRACE local local_update: { -2023-07-28T20:25:22Z TRACE local local_update: "timestamp" : "2023-07-28T20:25:20Z", -2023-07-28T20:25:22Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.1", -2023-07-28T20:25:22Z TRACE local local_update: "system" : { -2023-07-28T20:25:22Z TRACE local local_update: "min_loglevel" : 200, -2023-07-28T20:25:22Z TRACE local local_update: "metrics_rate_sec" : 600, -2023-07-28T20:25:22Z TRACE local local_update: "operation" : { -2023-07-28T20:25:22Z TRACE local local_update: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:22Z TRACE local local_update: }, -2023-07-28T20:25:22Z TRACE local local_update: "testing" : { -2023-07-28T20:25:22Z TRACE local local_update: "sequence_name" : "system_last_update" -2023-07-28T20:25:22Z TRACE local local_update: } -2023-07-28T20:25:22Z TRACE local local_update: }, -2023-07-28T20:25:22Z TRACE local local_update: "localnet" : { -2023-07-28T20:25:22Z TRACE local local_update: "families" : { -2023-07-28T20:25:22Z TRACE local local_update: "ether" : { -2023-07-28T20:25:22Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:22Z TRACE local local_update: }, -2023-07-28T20:25:22Z TRACE local local_update: "ipv4" : { -2023-07-28T20:25:22Z TRACE local local_update: "addr" : "192.168.2.1" -2023-07-28T20:25:22Z TRACE local local_update: } -2023-07-28T20:25:22Z TRACE local local_update: } -2023-07-28T20:25:22Z TRACE local local_update: }, -2023-07-28T20:25:22Z TRACE local local_update: "pointset" : { -2023-07-28T20:25:22Z TRACE local local_update: "points" : { -2023-07-28T20:25:22Z TRACE local local_update: "filter_alarm_pressure_status" : { -2023-07-28T20:25:22Z TRACE local local_update: "ref" : "BV11.present_value", -2023-07-28T20:25:22Z TRACE local local_update: "units" : "No-units" -2023-07-28T20:25:22Z TRACE local local_update: }, -2023-07-28T20:25:22Z TRACE local local_update: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:22Z TRACE local local_update: "units" : "Bars", -2023-07-28T20:25:22Z TRACE local local_update: "set_value" : 98 -2023-07-28T20:25:22Z TRACE local local_update: }, -2023-07-28T20:25:22Z TRACE local local_update: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:22Z TRACE local local_update: "ref" : "AV12.present_value", -2023-07-28T20:25:22Z TRACE local local_update: "units" : "Degrees-Celsius" -2023-07-28T20:25:22Z TRACE local local_update: } -2023-07-28T20:25:22Z TRACE local local_update: } -2023-07-28T20:25:22Z TRACE local local_update: } -2023-07-28T20:25:22Z TRACE local local_update: } -2023-07-28T20:25:22Z TRACE received command AHU-1/state/update -2023-07-28T20:25:22Z DEBUG received state_update -2023-07-28T20:25:22Z DEBUG Updated state after 1s 2023-07-28T20:25:21Z PS:8733158398148185 -2023-07-28T20:25:22Z INFO Updated state #108: Changed 3 fields: -2023-07-28T20:25:22Z INFO Updated state #108: Set `system.last_config` = `2023-07-28T20:25:20Z` -2023-07-28T20:25:22Z INFO Updated state #108: Set `system.status.timestamp` = `2023-07-28T20:25:20Z` -2023-07-28T20:25:22Z INFO Updated state #108: Set `timestamp` = `2023-07-28T20:25:21Z` -2023-07-28T20:25:22Z DEBUG Updated state has last_config 2023-07-28T20:25:20Z (expecting 2023-07-28T20:25:20Z) -2023-07-28T20:25:22Z DEBUG stage finished waiting for state last_config matches config timestamp at 13s after 1s -2023-07-28T20:25:22Z TRACE stage resume waiting for executing test at 13s -2023-07-28T20:25:23Z DEBUG system config extra field null -2023-07-28T20:25:23Z TRACE updated check config_system false: { -2023-07-28T20:25:23Z TRACE updated check config_system false: "min_loglevel" : 200, -2023-07-28T20:25:23Z TRACE updated check config_system false: "metrics_rate_sec" : 600, -2023-07-28T20:25:23Z TRACE updated check config_system false: "operation" : { -2023-07-28T20:25:23Z TRACE updated check config_system false: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:23Z TRACE updated check config_system false: }, -2023-07-28T20:25:23Z TRACE updated check config_system false: "testing" : { -2023-07-28T20:25:23Z TRACE updated check config_system false: "sequence_name" : "system_last_update" -2023-07-28T20:25:23Z TRACE updated check config_system false: } -2023-07-28T20:25:23Z TRACE updated check config_system false: } -2023-07-28T20:25:23Z TRACE updated check config_pointset false: { -2023-07-28T20:25:23Z TRACE updated check config_pointset false: "points" : { -2023-07-28T20:25:23Z TRACE updated check config_pointset false: "filter_alarm_pressure_status" : { -2023-07-28T20:25:23Z TRACE updated check config_pointset false: "ref" : "BV11.present_value", -2023-07-28T20:25:23Z TRACE updated check config_pointset false: "units" : "No-units" -2023-07-28T20:25:23Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:23Z TRACE updated check config_pointset false: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:23Z TRACE updated check config_pointset false: "units" : "Bars", -2023-07-28T20:25:23Z TRACE updated check config_pointset false: "set_value" : 98 -2023-07-28T20:25:23Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:23Z TRACE updated check config_pointset false: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:23Z TRACE updated check config_pointset false: "ref" : "AV12.present_value", -2023-07-28T20:25:23Z TRACE updated check config_pointset false: "units" : "Degrees-Celsius" -2023-07-28T20:25:23Z TRACE updated check config_pointset false: } -2023-07-28T20:25:23Z TRACE updated check config_pointset false: } -2023-07-28T20:25:23Z TRACE updated check config_pointset false: } -2023-07-28T20:25:23Z TRACE updated check config_gateway false: null -2023-07-28T20:25:23Z TRACE updated check config_localnet false: { -2023-07-28T20:25:23Z TRACE updated check config_localnet false: "families" : { -2023-07-28T20:25:23Z TRACE updated check config_localnet false: "ether" : { -2023-07-28T20:25:23Z TRACE updated check config_localnet false: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:23Z TRACE updated check config_localnet false: }, -2023-07-28T20:25:23Z TRACE updated check config_localnet false: "ipv4" : { -2023-07-28T20:25:23Z TRACE updated check config_localnet false: "addr" : "192.168.2.1" -2023-07-28T20:25:23Z TRACE updated check config_localnet false: } -2023-07-28T20:25:23Z TRACE updated check config_localnet false: } -2023-07-28T20:25:23Z TRACE updated check config_localnet false: } -2023-07-28T20:25:23Z TRACE updated check config_blobset false: null -2023-07-28T20:25:23Z TRACE updated check config_discovery false: null -2023-07-28T20:25:23Z DEBUG Forcing config update -2023-07-28T20:25:23Z TRACE updated check config_null false: null -2023-07-28T20:25:23Z DEBUG Update config state update: 2023-07-28T20:25:20Z -2023-07-28T20:25:23Z TRACE local local_update: { -2023-07-28T20:25:23Z TRACE local local_update: "timestamp" : "2023-07-28T20:25:20Z", -2023-07-28T20:25:23Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.1", -2023-07-28T20:25:23Z TRACE local local_update: "system" : { -2023-07-28T20:25:23Z TRACE local local_update: "min_loglevel" : 200, -2023-07-28T20:25:23Z TRACE local local_update: "metrics_rate_sec" : 600, -2023-07-28T20:25:23Z TRACE local local_update: "operation" : { -2023-07-28T20:25:23Z TRACE local local_update: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:23Z TRACE local local_update: }, -2023-07-28T20:25:23Z TRACE local local_update: "testing" : { -2023-07-28T20:25:23Z TRACE local local_update: "sequence_name" : "system_last_update" -2023-07-28T20:25:23Z TRACE local local_update: } -2023-07-28T20:25:23Z TRACE local local_update: }, -2023-07-28T20:25:23Z TRACE local local_update: "localnet" : { -2023-07-28T20:25:23Z TRACE local local_update: "families" : { -2023-07-28T20:25:23Z TRACE local local_update: "ether" : { -2023-07-28T20:25:23Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:23Z TRACE local local_update: }, -2023-07-28T20:25:23Z TRACE local local_update: "ipv4" : { -2023-07-28T20:25:23Z TRACE local local_update: "addr" : "192.168.2.1" -2023-07-28T20:25:23Z TRACE local local_update: } -2023-07-28T20:25:23Z TRACE local local_update: } -2023-07-28T20:25:23Z TRACE local local_update: }, -2023-07-28T20:25:23Z TRACE local local_update: "pointset" : { -2023-07-28T20:25:23Z TRACE local local_update: "points" : { -2023-07-28T20:25:23Z TRACE local local_update: "filter_alarm_pressure_status" : { -2023-07-28T20:25:23Z TRACE local local_update: "ref" : "BV11.present_value", -2023-07-28T20:25:23Z TRACE local local_update: "units" : "No-units" -2023-07-28T20:25:23Z TRACE local local_update: }, -2023-07-28T20:25:23Z TRACE local local_update: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:23Z TRACE local local_update: "units" : "Bars", -2023-07-28T20:25:23Z TRACE local local_update: "set_value" : 98 -2023-07-28T20:25:23Z TRACE local local_update: }, -2023-07-28T20:25:23Z TRACE local local_update: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:23Z TRACE local local_update: "ref" : "AV12.present_value", -2023-07-28T20:25:23Z TRACE local local_update: "units" : "Degrees-Celsius" -2023-07-28T20:25:23Z TRACE local local_update: } -2023-07-28T20:25:23Z TRACE local local_update: } -2023-07-28T20:25:23Z TRACE local local_update: } -2023-07-28T20:25:23Z TRACE local local_update: } -2023-07-28T20:25:23Z TRACE stage suspend waiting for executing test at 14s -2023-07-28T20:25:23Z INFO stage start waiting for received at least one state update at 14s -2023-07-28T20:25:24Z DEBUG system config extra field null -2023-07-28T20:25:24Z TRACE updated check config_system false: { -2023-07-28T20:25:24Z TRACE updated check config_system false: "min_loglevel" : 200, -2023-07-28T20:25:24Z TRACE updated check config_system false: "metrics_rate_sec" : 600, -2023-07-28T20:25:24Z TRACE updated check config_system false: "operation" : { -2023-07-28T20:25:24Z TRACE updated check config_system false: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:24Z TRACE updated check config_system false: }, -2023-07-28T20:25:24Z TRACE updated check config_system false: "testing" : { -2023-07-28T20:25:24Z TRACE updated check config_system false: "sequence_name" : "system_last_update" -2023-07-28T20:25:24Z TRACE updated check config_system false: } -2023-07-28T20:25:24Z TRACE updated check config_system false: } -2023-07-28T20:25:24Z TRACE updated check config_pointset false: { -2023-07-28T20:25:24Z TRACE updated check config_pointset false: "points" : { -2023-07-28T20:25:24Z TRACE updated check config_pointset false: "filter_alarm_pressure_status" : { -2023-07-28T20:25:24Z TRACE updated check config_pointset false: "ref" : "BV11.present_value", -2023-07-28T20:25:24Z TRACE updated check config_pointset false: "units" : "No-units" -2023-07-28T20:25:24Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:24Z TRACE updated check config_pointset false: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:24Z TRACE updated check config_pointset false: "units" : "Bars", -2023-07-28T20:25:24Z TRACE updated check config_pointset false: "set_value" : 98 -2023-07-28T20:25:24Z TRACE updated check config_pointset false: }, -2023-07-28T20:25:24Z TRACE updated check config_pointset false: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:24Z TRACE updated check config_pointset false: "ref" : "AV12.present_value", -2023-07-28T20:25:24Z TRACE updated check config_pointset false: "units" : "Degrees-Celsius" -2023-07-28T20:25:24Z TRACE updated check config_pointset false: } -2023-07-28T20:25:24Z TRACE updated check config_pointset false: } -2023-07-28T20:25:24Z TRACE updated check config_pointset false: } -2023-07-28T20:25:24Z TRACE updated check config_gateway false: null -2023-07-28T20:25:24Z TRACE updated check config_localnet false: { -2023-07-28T20:25:24Z TRACE updated check config_localnet false: "families" : { -2023-07-28T20:25:24Z TRACE updated check config_localnet false: "ether" : { -2023-07-28T20:25:24Z TRACE updated check config_localnet false: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:24Z TRACE updated check config_localnet false: }, -2023-07-28T20:25:24Z TRACE updated check config_localnet false: "ipv4" : { -2023-07-28T20:25:24Z TRACE updated check config_localnet false: "addr" : "192.168.2.1" -2023-07-28T20:25:24Z TRACE updated check config_localnet false: } -2023-07-28T20:25:24Z TRACE updated check config_localnet false: } -2023-07-28T20:25:24Z TRACE updated check config_localnet false: } -2023-07-28T20:25:24Z TRACE updated check config_blobset false: null -2023-07-28T20:25:24Z TRACE updated check config_discovery false: null -2023-07-28T20:25:24Z DEBUG Update config before received at least one state update: 2023-07-28T20:25:20Z -2023-07-28T20:25:24Z TRACE local local_update: { -2023-07-28T20:25:24Z TRACE local local_update: "timestamp" : "2023-07-28T20:25:20Z", -2023-07-28T20:25:24Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.1", -2023-07-28T20:25:24Z TRACE local local_update: "system" : { -2023-07-28T20:25:24Z TRACE local local_update: "min_loglevel" : 200, -2023-07-28T20:25:24Z TRACE local local_update: "metrics_rate_sec" : 600, -2023-07-28T20:25:24Z TRACE local local_update: "operation" : { -2023-07-28T20:25:24Z TRACE local local_update: "last_start" : "2023-07-28T20:23:12Z" -2023-07-28T20:25:24Z TRACE local local_update: }, -2023-07-28T20:25:24Z TRACE local local_update: "testing" : { -2023-07-28T20:25:24Z TRACE local local_update: "sequence_name" : "system_last_update" -2023-07-28T20:25:24Z TRACE local local_update: } -2023-07-28T20:25:24Z TRACE local local_update: }, -2023-07-28T20:25:24Z TRACE local local_update: "localnet" : { -2023-07-28T20:25:24Z TRACE local local_update: "families" : { -2023-07-28T20:25:24Z TRACE local local_update: "ether" : { -2023-07-28T20:25:24Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" -2023-07-28T20:25:24Z TRACE local local_update: }, -2023-07-28T20:25:24Z TRACE local local_update: "ipv4" : { -2023-07-28T20:25:24Z TRACE local local_update: "addr" : "192.168.2.1" -2023-07-28T20:25:24Z TRACE local local_update: } -2023-07-28T20:25:24Z TRACE local local_update: } -2023-07-28T20:25:24Z TRACE local local_update: }, -2023-07-28T20:25:24Z TRACE local local_update: "pointset" : { -2023-07-28T20:25:24Z TRACE local local_update: "points" : { -2023-07-28T20:25:24Z TRACE local local_update: "filter_alarm_pressure_status" : { -2023-07-28T20:25:24Z TRACE local local_update: "ref" : "BV11.present_value", -2023-07-28T20:25:24Z TRACE local local_update: "units" : "No-units" -2023-07-28T20:25:24Z TRACE local local_update: }, -2023-07-28T20:25:24Z TRACE local local_update: "filter_differential_pressure_setpoint" : { -2023-07-28T20:25:24Z TRACE local local_update: "units" : "Bars", -2023-07-28T20:25:24Z TRACE local local_update: "set_value" : 98 -2023-07-28T20:25:24Z TRACE local local_update: }, -2023-07-28T20:25:24Z TRACE local local_update: "filter_differential_pressure_sensor" : { -2023-07-28T20:25:24Z TRACE local local_update: "ref" : "AV12.present_value", -2023-07-28T20:25:24Z TRACE local local_update: "units" : "Degrees-Celsius" -2023-07-28T20:25:24Z TRACE local local_update: } -2023-07-28T20:25:24Z TRACE local local_update: } -2023-07-28T20:25:24Z TRACE local local_update: } -2023-07-28T20:25:24Z TRACE local local_update: } -2023-07-28T20:25:24Z DEBUG stage finished waiting for received at least one state update at 15s after 1s -2023-07-28T20:25:24Z TRACE stage resume waiting for executing test at 15s -2023-07-28T20:25:24Z DEBUG stage done waiting for executing test at 15s -2023-07-28T20:25:24Z NOTICE RESULT pass system system_last_update STABLE 5 Sequence complete -2023-07-28T20:25:24Z NOTICE Sequence complete -2023-07-28T20:25:24Z INFO waiting 12s for more messages... -2023-07-28T20:25:24Z TRACE stage suspend waiting for executing test at 15s -2023-07-28T20:25:24Z INFO stage start waiting for minimum test time at 15s -2023-07-28T20:25:24Z TRACE received command AHU-1/state/system -2023-07-28T20:25:24Z DEBUG Handling device message state/system PS:8733158398148185-0 -2023-07-28T20:25:24Z TRACE Ignoring partial state update -2023-07-28T20:25:24Z TRACE received command AHU-1/state/localnet -2023-07-28T20:25:24Z DEBUG Handling device message state/localnet PS:8733158398148185-1 -2023-07-28T20:25:24Z TRACE Ignoring partial state update -2023-07-28T20:25:24Z TRACE received command AHU-1/state/pointset -2023-07-28T20:25:24Z DEBUG Handling device message state/pointset PS:8733158398148185-2 -2023-07-28T20:25:24Z TRACE Ignoring partial state update -2023-07-28T20:25:24Z TRACE received command AHU-1/event/pointset -2023-07-28T20:25:24Z DEBUG Handling device message event/pointset PS:8731720407412853 -2023-07-28T20:25:24Z TRACE received command AHU-1/event/system -2023-07-28T20:25:24Z DEBUG Handling device message event/system PS:8733139451311105 -2023-07-28T20:25:34Z TRACE received command AHU-1/event/pointset -2023-07-28T20:25:34Z DEBUG Handling device message event/pointset PS:8733148995508592 -2023-07-28T20:25:34Z TRACE received command AHU-1/event/system -2023-07-28T20:25:34Z DEBUG Handling device message event/system PS:8733108896924291 -2023-07-28T20:25:44Z TRACE received command AHU-1/event/pointset -2023-07-28T20:25:44Z DEBUG Handling device message event/pointset PS:8732122066911886 -2023-07-28T20:25:44Z DEBUG stage finished waiting for minimum test time at 35s after 20s -2023-07-28T20:25:44Z TRACE stage resume waiting for executing test at 35s -2023-07-28T20:25:44Z NOTICE SCHEMA pass system system_last_update STABLE event_system No schema violations found -2023-07-28T20:25:44Z NOTICE SCHEMA pass system system_last_update STABLE event_pointset No schema violations found -2023-07-28T20:25:44Z NOTICE SCHEMA pass system system_last_update STABLE state_update No schema violations found -2023-07-28T20:25:44Z NOTICE ending test system_last_update after 35s ################################ +2023-12-08T05:49:39Z NOTICE starting test system_last_update ################################ +2023-12-08T05:49:39Z INFO Stage start waiting for starting test wrapper at 0s +2023-12-08T05:49:47Z INFO Allowing device state change +2023-12-08T05:49:47Z DEBUG Starting reset_config full reset true +2023-12-08T05:49:47Z DEBUG Clear configTransactions and reset device config +2023-12-08T05:49:47Z DEBUG Suppressing exception: java.lang.NullPointerException: Cannot read field "system" because "this.deviceState" is null +2023-12-08T05:49:47Z DEBUG Configuring device last_start to be 1970-01-01T00:01:13Z +2023-12-08T05:49:47Z DEBUG last_start changed true, last_start 1970-01-01T00:01:13Z +2023-12-08T05:49:47Z DEBUG extraFieldChanged false because extra_field null +2023-12-08T05:49:47Z DEBUG extraFieldChanged true because extra_field reset_config +2023-12-08T05:49:48Z DEBUG system config extra field reset_config +2023-12-08T05:49:48Z TRACE updated check config_system: true +2023-12-08T05:49:48Z DEBUG update config_system, configTransaction RC:1702014588915 +2023-12-08T05:49:48Z TRACE local local_system: { +2023-12-08T05:49:48Z TRACE local local_system: "min_loglevel" : 200, +2023-12-08T05:49:48Z TRACE local local_system: "metrics_rate_sec" : 10, +2023-12-08T05:49:48Z TRACE local local_system: "operation" : { +2023-12-08T05:49:48Z TRACE local local_system: "last_start" : "1970-01-01T00:01:13Z" +2023-12-08T05:49:48Z TRACE local local_system: }, +2023-12-08T05:49:48Z TRACE local local_system: "testing" : { +2023-12-08T05:49:48Z TRACE local local_system: "sequence_name" : "reset_config" +2023-12-08T05:49:48Z TRACE local local_system: }, +2023-12-08T05:49:48Z TRACE local local_system: "extra_field" : "reset_config" +2023-12-08T05:49:48Z TRACE local local_system: } +2023-12-08T05:49:48Z TRACE updated check config_pointset: false +2023-12-08T05:49:48Z TRACE updated check config_gateway: false +2023-12-08T05:49:48Z TRACE updated check config_localnet: false +2023-12-08T05:49:48Z TRACE updated check config_blobset: false +2023-12-08T05:49:48Z TRACE updated check config_discovery: false +2023-12-08T05:49:48Z DEBUG Suppressing exception: java.lang.NullPointerException: Cannot read field "system" because "this.deviceState" is null +2023-12-08T05:49:48Z DEBUG Suppressing exception: java.lang.NullPointerException: Cannot read field "system" because "this.deviceState" is null +2023-12-08T05:49:48Z DEBUG Update lastConfigUpdate 2023-12-08T05:49:48Z, because full reset +2023-12-08T05:49:48Z TRACE stage suspend waiting for starting test wrapper at 9s +2023-12-08T05:49:48Z INFO Stage start waiting for config sync at 9s +2023-12-08T05:49:48Z DEBUG Suppressing exception: java.lang.NullPointerException: Cannot read field "system" because "this.deviceState" is null +2023-12-08T05:49:48Z TRACE received command AHU-1/state/update +2023-12-08T05:49:48Z DEBUG received state_update +2023-12-08T05:49:49Z DEBUG Handling update message state_update PS:9105755693477947 +2023-12-08T05:49:49Z DEBUG Updated state after 9s 2023-12-08T05:49:40Z PS:9105755693477947 +2023-12-08T05:49:49Z INFO Initial state #001: { +2023-12-08T05:49:49Z INFO Initial state #001: "timestamp" : "2023-12-08T05:49:40Z", +2023-12-08T05:49:49Z INFO Initial state #001: "version" : "1.4.2", +2023-12-08T05:49:49Z INFO Initial state #001: "system" : { +2023-12-08T05:49:49Z INFO Initial state #001: "last_config" : "2023-12-08T05:49:14Z", +2023-12-08T05:49:49Z INFO Initial state #001: "operation" : { +2023-12-08T05:49:49Z INFO Initial state #001: "operational" : true, +2023-12-08T05:49:49Z INFO Initial state #001: "last_start" : "2023-12-08T05:49:34Z", +2023-12-08T05:49:49Z INFO Initial state #001: "restart_count" : 1, +2023-12-08T05:49:49Z INFO Initial state #001: "mode" : "initial" +2023-12-08T05:49:49Z INFO Initial state #001: }, +2023-12-08T05:49:49Z INFO Initial state #001: "serial_no" : "sequencer-20544", +2023-12-08T05:49:49Z INFO Initial state #001: "hardware" : { +2023-12-08T05:49:49Z INFO Initial state #001: "make" : "BOS", +2023-12-08T05:49:49Z INFO Initial state #001: "model" : "pubber" +2023-12-08T05:49:49Z INFO Initial state #001: }, +2023-12-08T05:49:49Z INFO Initial state #001: "software" : { +2023-12-08T05:49:49Z INFO Initial state #001: "firmware" : "v1" +2023-12-08T05:49:49Z INFO Initial state #001: }, +2023-12-08T05:49:49Z INFO Initial state #001: "status" : { +2023-12-08T05:49:49Z INFO Initial state #001: "message" : "success", +2023-12-08T05:49:49Z INFO Initial state #001: "category" : "system.config.apply", +2023-12-08T05:49:49Z INFO Initial state #001: "timestamp" : "2023-12-08T05:49:38Z", +2023-12-08T05:49:49Z INFO Initial state #001: "level" : 300 +2023-12-08T05:49:49Z INFO Initial state #001: } +2023-12-08T05:49:49Z INFO Initial state #001: }, +2023-12-08T05:49:49Z INFO Initial state #001: "localnet" : { +2023-12-08T05:49:49Z INFO Initial state #001: "families" : { +2023-12-08T05:49:49Z INFO Initial state #001: "ether" : { +2023-12-08T05:49:49Z INFO Initial state #001: "addr" : "40:1c:83:ca:77:54" +2023-12-08T05:49:49Z INFO Initial state #001: }, +2023-12-08T05:49:49Z INFO Initial state #001: "ipv4" : { +2023-12-08T05:49:49Z INFO Initial state #001: "addr" : "10.132.154.140" +2023-12-08T05:49:49Z INFO Initial state #001: }, +2023-12-08T05:49:49Z INFO Initial state #001: "ipv6" : { +2023-12-08T05:49:49Z INFO Initial state #001: "addr" : "fe80::f9e9:cab2:e374:401d" +2023-12-08T05:49:49Z INFO Initial state #001: } +2023-12-08T05:49:49Z INFO Initial state #001: } +2023-12-08T05:49:49Z INFO Initial state #001: }, +2023-12-08T05:49:49Z INFO Initial state #001: "pointset" : { +2023-12-08T05:49:49Z INFO Initial state #001: "points" : { +2023-12-08T05:49:49Z INFO Initial state #001: "filter_alarm_pressure_status" : { }, +2023-12-08T05:49:49Z INFO Initial state #001: "filter_differential_pressure_setpoint" : { +2023-12-08T05:49:49Z INFO Initial state #001: "units" : "Bars", +2023-12-08T05:49:49Z INFO Initial state #001: "value_state" : "applied" +2023-12-08T05:49:49Z INFO Initial state #001: }, +2023-12-08T05:49:49Z INFO Initial state #001: "filter_differential_pressure_sensor" : { +2023-12-08T05:49:49Z INFO Initial state #001: "units" : "Degrees-Celsius" +2023-12-08T05:49:49Z INFO Initial state #001: } +2023-12-08T05:49:49Z INFO Initial state #001: } +2023-12-08T05:49:49Z INFO Initial state #001: } +2023-12-08T05:49:49Z INFO Initial state #001: } +2023-12-08T05:49:49Z NOTICE Received serial number sequencer-20544 +2023-12-08T05:49:49Z DEBUG Updated state has last_config 2023-12-08T05:49:14Z (expecting null) +2023-12-08T05:49:49Z TRACE received command AHU-1/state/system +2023-12-08T05:49:49Z TRACE received state_system: { +2023-12-08T05:49:49Z TRACE received state_system: "hardware" : { +2023-12-08T05:49:49Z TRACE received state_system: "make" : "BOS", +2023-12-08T05:49:49Z TRACE received state_system: "model" : "pubber" +2023-12-08T05:49:49Z TRACE received state_system: }, +2023-12-08T05:49:49Z TRACE received state_system: "last_config" : "2023-12-08T05:49:14Z", +2023-12-08T05:49:49Z TRACE received state_system: "operation" : { +2023-12-08T05:49:49Z TRACE received state_system: "operational" : true, +2023-12-08T05:49:49Z TRACE received state_system: "last_start" : "2023-12-08T05:49:34Z", +2023-12-08T05:49:49Z TRACE received state_system: "restart_count" : 1, +2023-12-08T05:49:49Z TRACE received state_system: "mode" : "initial" +2023-12-08T05:49:49Z TRACE received state_system: }, +2023-12-08T05:49:49Z TRACE received state_system: "serial_no" : "sequencer-20544", +2023-12-08T05:49:49Z TRACE received state_system: "software" : { +2023-12-08T05:49:49Z TRACE received state_system: "firmware" : "v1" +2023-12-08T05:49:49Z TRACE received state_system: }, +2023-12-08T05:49:49Z TRACE received state_system: "status" : { +2023-12-08T05:49:49Z TRACE received state_system: "message" : "success", +2023-12-08T05:49:49Z TRACE received state_system: "category" : "system.config.apply", +2023-12-08T05:49:49Z TRACE received state_system: "timestamp" : "2023-12-08T05:49:38Z", +2023-12-08T05:49:49Z TRACE received state_system: "level" : 300 +2023-12-08T05:49:49Z TRACE received state_system: }, +2023-12-08T05:49:49Z TRACE received state_system: "timestamp" : "2023-12-08T05:49:40Z", +2023-12-08T05:49:49Z TRACE received state_system: "version" : "1.4.2" +2023-12-08T05:49:49Z TRACE received state_system: } +2023-12-08T05:49:49Z DEBUG Handling device message state_system PS:9105755693477947-0 +2023-12-08T05:49:49Z TRACE Ignoring partial state update +2023-12-08T05:49:49Z TRACE received command AHU-1/state/localnet +2023-12-08T05:49:49Z TRACE received state_localnet: { +2023-12-08T05:49:49Z TRACE received state_localnet: "families" : { +2023-12-08T05:49:49Z TRACE received state_localnet: "ether" : { +2023-12-08T05:49:49Z TRACE received state_localnet: "addr" : "40:1c:83:ca:77:54" +2023-12-08T05:49:49Z TRACE received state_localnet: }, +2023-12-08T05:49:49Z TRACE received state_localnet: "ipv4" : { +2023-12-08T05:49:49Z TRACE received state_localnet: "addr" : "10.132.154.140" +2023-12-08T05:49:49Z TRACE received state_localnet: }, +2023-12-08T05:49:49Z TRACE received state_localnet: "ipv6" : { +2023-12-08T05:49:49Z TRACE received state_localnet: "addr" : "fe80::f9e9:cab2:e374:401d" +2023-12-08T05:49:49Z TRACE received state_localnet: } +2023-12-08T05:49:49Z TRACE received state_localnet: }, +2023-12-08T05:49:49Z TRACE received state_localnet: "timestamp" : "2023-12-08T05:49:40Z", +2023-12-08T05:49:49Z TRACE received state_localnet: "version" : "1.4.2" +2023-12-08T05:49:49Z TRACE received state_localnet: } +2023-12-08T05:49:49Z DEBUG Handling device message state_localnet PS:9105755693477947-1 +2023-12-08T05:49:49Z TRACE Ignoring partial state update +2023-12-08T05:49:49Z TRACE received command AHU-1/state/pointset +2023-12-08T05:49:49Z TRACE received state_pointset: { +2023-12-08T05:49:49Z TRACE received state_pointset: "points" : { +2023-12-08T05:49:49Z TRACE received state_pointset: "filter_alarm_pressure_status" : { }, +2023-12-08T05:49:49Z TRACE received state_pointset: "filter_differential_pressure_setpoint" : { +2023-12-08T05:49:49Z TRACE received state_pointset: "units" : "Bars", +2023-12-08T05:49:49Z TRACE received state_pointset: "value_state" : "applied" +2023-12-08T05:49:49Z TRACE received state_pointset: }, +2023-12-08T05:49:49Z TRACE received state_pointset: "filter_differential_pressure_sensor" : { +2023-12-08T05:49:49Z TRACE received state_pointset: "units" : "Degrees-Celsius" +2023-12-08T05:49:49Z TRACE received state_pointset: } +2023-12-08T05:49:49Z TRACE received state_pointset: }, +2023-12-08T05:49:49Z TRACE received state_pointset: "timestamp" : "2023-12-08T05:49:40Z", +2023-12-08T05:49:49Z TRACE received state_pointset: "version" : "1.4.2" +2023-12-08T05:49:49Z TRACE received state_pointset: } +2023-12-08T05:49:49Z DEBUG Handling device message state_pointset PS:9105755693477947-2 +2023-12-08T05:49:49Z TRACE Ignoring partial state update +2023-12-08T05:49:49Z TRACE received command AHU-1/event/pointset +2023-12-08T05:49:49Z TRACE received event_pointset: { +2023-12-08T05:49:49Z TRACE received event_pointset: "points" : { +2023-12-08T05:49:49Z TRACE received event_pointset: "filter_alarm_pressure_status" : { +2023-12-08T05:49:49Z TRACE received event_pointset: "present_value" : true +2023-12-08T05:49:49Z TRACE received event_pointset: }, +2023-12-08T05:49:49Z TRACE received event_pointset: "filter_differential_pressure_setpoint" : { +2023-12-08T05:49:49Z TRACE received event_pointset: "present_value" : 98 +2023-12-08T05:49:49Z TRACE received event_pointset: }, +2023-12-08T05:49:49Z TRACE received event_pointset: "filter_differential_pressure_sensor" : { +2023-12-08T05:49:49Z TRACE received event_pointset: "present_value" : 9 +2023-12-08T05:49:49Z TRACE received event_pointset: } +2023-12-08T05:49:49Z TRACE received event_pointset: }, +2023-12-08T05:49:49Z TRACE received event_pointset: "timestamp" : "2023-12-08T05:49:45Z", +2023-12-08T05:49:49Z TRACE received event_pointset: "version" : "1.4.2" +2023-12-08T05:49:49Z TRACE received event_pointset: } +2023-12-08T05:49:49Z DEBUG Handling device message event_pointset PS:9793378137675201 +2023-12-08T05:49:49Z TRACE received command AHU-1/event/system +2023-12-08T05:49:49Z DEBUG received event_system 2023-12-08T05:49:35Z WARNING device.log: Start waiting 10s for config latch for AHU-1 +2023-12-08T05:49:49Z DEBUG received event_system 2023-12-08T05:49:35Z WARNING device.log: Starting Pubber sender with delay 10s +2023-12-08T05:49:49Z DEBUG received event_system 2023-12-08T05:49:35Z WARNING device.log: Dropping state update until config received... +2023-12-08T05:49:49Z DEBUG received event_system 2023-12-08T05:49:35Z WARNING device.log: Received config for config latch AHU-1 +2023-12-08T05:49:49Z DEBUG received event_system 2023-12-08T05:49:35Z NOTICE system.config.apply: success +2023-12-08T05:49:49Z DEBUG received event_system 2023-12-08T05:49:38Z NOTICE system.config.apply: success +2023-12-08T05:49:49Z DEBUG Handling device message event_system PS:9793757463293315 +2023-12-08T05:49:49Z TRACE received command null/null/error +2023-12-08T05:49:50Z TRACE received command AHU-1/config/update +2023-12-08T05:49:50Z DEBUG received config_update +2023-12-08T05:49:50Z DEBUG Handling update message config_update RC:1702014588915 +2023-12-08T05:49:50Z DEBUG Removed configTransaction RC:1702014588915 +2023-12-08T05:49:50Z DEBUG last_start changed false, last_start 1970-01-01T00:01:13Z +2023-12-08T05:49:50Z DEBUG Updated config 2023-12-08T05:49:50Z RC:1702014588915 +2023-12-08T05:49:50Z INFO Initial config #001: { +2023-12-08T05:49:50Z INFO Initial config #001: "timestamp" : "2023-12-08T05:49:50Z", +2023-12-08T05:49:50Z INFO Initial config #001: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:49:50Z INFO Initial config #001: "system" : { +2023-12-08T05:49:50Z INFO Initial config #001: "min_loglevel" : 200, +2023-12-08T05:49:50Z INFO Initial config #001: "metrics_rate_sec" : 10, +2023-12-08T05:49:50Z INFO Initial config #001: "operation" : { +2023-12-08T05:49:50Z INFO Initial config #001: "last_start" : "1970-01-01T00:01:13Z" +2023-12-08T05:49:50Z INFO Initial config #001: }, +2023-12-08T05:49:50Z INFO Initial config #001: "testing" : { +2023-12-08T05:49:50Z INFO Initial config #001: "sequence_name" : "system_last_update" +2023-12-08T05:49:50Z INFO Initial config #001: } +2023-12-08T05:49:50Z INFO Initial config #001: } +2023-12-08T05:49:50Z INFO Initial config #001: } +2023-12-08T05:49:50Z TRACE received command AHU-1/state/update +2023-12-08T05:49:50Z DEBUG received state_update +2023-12-08T05:49:50Z DEBUG Handling update message state_update PS:9792751159818987 +2023-12-08T05:49:50Z DEBUG Updated state after 0s 2023-12-08T05:49:50Z PS:9792751159818987 +2023-12-08T05:49:50Z INFO Updated state #002: Changed 4 fields: +2023-12-08T05:49:50Z INFO Updated state #002: Set `system.status.level` = `100` +2023-12-08T05:49:50Z INFO Updated state #002: Set `system.status.category` = `system.config.parse` +2023-12-08T05:49:50Z INFO Updated state #002: Set `system.status.timestamp` = `2023-12-08T05:49:50Z` +2023-12-08T05:49:50Z INFO Updated state #002: Set `timestamp` = `2023-12-08T05:49:50Z` +2023-12-08T05:49:50Z DEBUG Updated state has last_config 2023-12-08T05:49:14Z (expecting 2023-12-08T05:49:50Z) +2023-12-08T05:49:50Z TRACE received command AHU-1/state/system +2023-12-08T05:49:50Z TRACE received state_system: { +2023-12-08T05:49:50Z TRACE received state_system: "hardware" : { +2023-12-08T05:49:50Z TRACE received state_system: "make" : "BOS", +2023-12-08T05:49:50Z TRACE received state_system: "model" : "pubber" +2023-12-08T05:49:50Z TRACE received state_system: }, +2023-12-08T05:49:50Z TRACE received state_system: "last_config" : "2023-12-08T05:49:14Z", +2023-12-08T05:49:50Z TRACE received state_system: "operation" : { +2023-12-08T05:49:50Z TRACE received state_system: "operational" : true, +2023-12-08T05:49:50Z TRACE received state_system: "last_start" : "2023-12-08T05:49:34Z", +2023-12-08T05:49:50Z TRACE received state_system: "restart_count" : 1, +2023-12-08T05:49:50Z TRACE received state_system: "mode" : "initial" +2023-12-08T05:49:50Z TRACE received state_system: }, +2023-12-08T05:49:50Z TRACE received state_system: "serial_no" : "sequencer-20544", +2023-12-08T05:49:50Z TRACE received state_system: "software" : { +2023-12-08T05:49:50Z TRACE received state_system: "firmware" : "v1" +2023-12-08T05:49:50Z TRACE received state_system: }, +2023-12-08T05:49:50Z TRACE received state_system: "status" : { +2023-12-08T05:49:50Z TRACE received state_system: "message" : "success", +2023-12-08T05:49:50Z TRACE received state_system: "category" : "system.config.parse", +2023-12-08T05:49:50Z TRACE received state_system: "timestamp" : "2023-12-08T05:49:50Z", +2023-12-08T05:49:50Z TRACE received state_system: "level" : 100 +2023-12-08T05:49:50Z TRACE received state_system: }, +2023-12-08T05:49:50Z TRACE received state_system: "timestamp" : "2023-12-08T05:49:50Z", +2023-12-08T05:49:50Z TRACE received state_system: "version" : "1.4.2" +2023-12-08T05:49:50Z TRACE received state_system: } +2023-12-08T05:49:50Z DEBUG Handling device message state_system PS:9792751159818987-0 +2023-12-08T05:49:50Z TRACE Ignoring partial state update +2023-12-08T05:49:50Z TRACE received command AHU-1/state/localnet +2023-12-08T05:49:50Z TRACE received state_localnet: { +2023-12-08T05:49:50Z TRACE received state_localnet: "families" : { +2023-12-08T05:49:50Z TRACE received state_localnet: "ether" : { +2023-12-08T05:49:50Z TRACE received state_localnet: "addr" : "40:1c:83:ca:77:54" +2023-12-08T05:49:50Z TRACE received state_localnet: }, +2023-12-08T05:49:50Z TRACE received state_localnet: "ipv4" : { +2023-12-08T05:49:50Z TRACE received state_localnet: "addr" : "10.132.154.140" +2023-12-08T05:49:50Z TRACE received state_localnet: }, +2023-12-08T05:49:50Z TRACE received state_localnet: "ipv6" : { +2023-12-08T05:49:50Z TRACE received state_localnet: "addr" : "fe80::f9e9:cab2:e374:401d" +2023-12-08T05:49:50Z TRACE received state_localnet: } +2023-12-08T05:49:50Z TRACE received state_localnet: }, +2023-12-08T05:49:50Z TRACE received state_localnet: "timestamp" : "2023-12-08T05:49:50Z", +2023-12-08T05:49:50Z TRACE received state_localnet: "version" : "1.4.2" +2023-12-08T05:49:50Z TRACE received state_localnet: } +2023-12-08T05:49:50Z DEBUG Handling device message state_localnet PS:9792751159818987-1 +2023-12-08T05:49:50Z TRACE Ignoring partial state update +2023-12-08T05:49:50Z TRACE received command AHU-1/state/pointset +2023-12-08T05:49:50Z TRACE received state_pointset: { +2023-12-08T05:49:50Z TRACE received state_pointset: "points" : { +2023-12-08T05:49:50Z TRACE received state_pointset: "filter_alarm_pressure_status" : { }, +2023-12-08T05:49:50Z TRACE received state_pointset: "filter_differential_pressure_setpoint" : { +2023-12-08T05:49:50Z TRACE received state_pointset: "units" : "Bars", +2023-12-08T05:49:50Z TRACE received state_pointset: "value_state" : "applied" +2023-12-08T05:49:50Z TRACE received state_pointset: }, +2023-12-08T05:49:50Z TRACE received state_pointset: "filter_differential_pressure_sensor" : { +2023-12-08T05:49:50Z TRACE received state_pointset: "units" : "Degrees-Celsius" +2023-12-08T05:49:50Z TRACE received state_pointset: } +2023-12-08T05:49:50Z TRACE received state_pointset: }, +2023-12-08T05:49:50Z TRACE received state_pointset: "timestamp" : "2023-12-08T05:49:50Z", +2023-12-08T05:49:50Z TRACE received state_pointset: "version" : "1.4.2" +2023-12-08T05:49:50Z TRACE received state_pointset: } +2023-12-08T05:49:50Z DEBUG Handling device message state_pointset PS:9792751159818987-2 +2023-12-08T05:49:50Z TRACE Ignoring partial state update +2023-12-08T05:49:50Z TRACE received command AHU-1/config/update +2023-12-08T05:49:50Z DEBUG received config_update +2023-12-08T05:49:50Z DEBUG Handling update message config_update PS:9792751159818987 +2023-12-08T05:49:50Z DEBUG last_start changed true, last_start 2023-12-08T05:49:34Z +2023-12-08T05:49:50Z DEBUG Updated config 2023-12-08T05:49:50Z PS:9792751159818987 +2023-12-08T05:49:50Z INFO Updated config #002: Changed 0 fields. +2023-12-08T05:49:50Z DEBUG Stage finished waiting for config sync at 10s after 1s +2023-12-08T05:49:50Z TRACE Stage resume waiting for starting test wrapper at 10s +2023-12-08T05:49:50Z DEBUG Configuration sync took 2s +2023-12-08T05:49:50Z DEBUG wait for config sync pending false +2023-12-08T05:49:50Z DEBUG Update config full reset: 2023-12-08T05:49:50Z +2023-12-08T05:49:50Z TRACE local local_update: { +2023-12-08T05:49:50Z TRACE local local_update: "timestamp" : "2023-12-08T05:49:50Z", +2023-12-08T05:49:50Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:49:50Z TRACE local local_update: "system" : { +2023-12-08T05:49:50Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:49:50Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:49:50Z TRACE local local_update: "operation" : { +2023-12-08T05:49:50Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:49:50Z TRACE local local_update: }, +2023-12-08T05:49:50Z TRACE local local_update: "testing" : { +2023-12-08T05:49:50Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:49:50Z TRACE local local_update: } +2023-12-08T05:49:50Z TRACE local local_update: } +2023-12-08T05:49:50Z TRACE local local_update: } +2023-12-08T05:49:50Z TRACE Update config full reset: Add `timestamp` = `generated timestamp` +2023-12-08T05:49:50Z TRACE stage suspend waiting for starting test wrapper at 10s +2023-12-08T05:49:50Z INFO Stage start waiting for no applicable system status at 10s +2023-12-08T05:49:51Z DEBUG system config extra field reset_config +2023-12-08T05:49:51Z TRACE updated check config_system: true +2023-12-08T05:49:51Z DEBUG update config_system, configTransaction RC:1702014591619 +2023-12-08T05:49:51Z TRACE local local_system: { +2023-12-08T05:49:51Z TRACE local local_system: "min_loglevel" : 200, +2023-12-08T05:49:51Z TRACE local local_system: "metrics_rate_sec" : 10, +2023-12-08T05:49:51Z TRACE local local_system: "operation" : { +2023-12-08T05:49:51Z TRACE local local_system: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:49:51Z TRACE local local_system: }, +2023-12-08T05:49:51Z TRACE local local_system: "testing" : { +2023-12-08T05:49:51Z TRACE local local_system: "sequence_name" : "system_last_update" +2023-12-08T05:49:51Z TRACE local local_system: }, +2023-12-08T05:49:51Z TRACE local local_system: "extra_field" : "reset_config" +2023-12-08T05:49:51Z TRACE local local_system: } +2023-12-08T05:49:51Z TRACE updated check config_pointset: false +2023-12-08T05:49:51Z TRACE updated check config_gateway: false +2023-12-08T05:49:51Z TRACE updated check config_localnet: false +2023-12-08T05:49:51Z TRACE updated check config_blobset: false +2023-12-08T05:49:51Z TRACE updated check config_discovery: false +2023-12-08T05:49:51Z DEBUG Update lastConfigUpdate 2023-12-08T05:49:51Z, because before no applicable system status +2023-12-08T05:49:51Z TRACE stage suspend waiting for no applicable system status at 11s +2023-12-08T05:49:51Z INFO Stage start waiting for config sync at 11s +2023-12-08T05:49:51Z TRACE received command AHU-1/config/update +2023-12-08T05:49:51Z DEBUG received config_update +2023-12-08T05:49:51Z DEBUG Handling update message config_update RC:1702014591619 +2023-12-08T05:49:51Z DEBUG Removed configTransaction RC:1702014591619 +2023-12-08T05:49:51Z DEBUG last_start changed false, last_start 2023-12-08T05:49:34Z +2023-12-08T05:49:51Z DEBUG Updated config 2023-12-08T05:49:51Z RC:1702014591619 +2023-12-08T05:49:51Z INFO Updated config #003: Changed 0 fields. +2023-12-08T05:49:51Z DEBUG Stage finished waiting for config sync at 11s after 0s +2023-12-08T05:49:51Z TRACE Stage resume waiting for no applicable system status at 11s +2023-12-08T05:49:51Z DEBUG Configuration sync took 0s +2023-12-08T05:49:51Z DEBUG wait for config sync pending false +2023-12-08T05:49:51Z DEBUG Update config before no applicable system status: 2023-12-08T05:49:51Z +2023-12-08T05:49:51Z TRACE local local_update: { +2023-12-08T05:49:51Z TRACE local local_update: "timestamp" : "2023-12-08T05:49:51Z", +2023-12-08T05:49:51Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:49:51Z TRACE local local_update: "system" : { +2023-12-08T05:49:51Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:49:51Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:49:51Z TRACE local local_update: "operation" : { +2023-12-08T05:49:51Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:49:51Z TRACE local local_update: }, +2023-12-08T05:49:51Z TRACE local local_update: "testing" : { +2023-12-08T05:49:51Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:49:51Z TRACE local local_update: } +2023-12-08T05:49:51Z TRACE local local_update: } +2023-12-08T05:49:51Z TRACE local local_update: } +2023-12-08T05:49:51Z DEBUG Status level: 100 +2023-12-08T05:49:51Z DEBUG Stage finished waiting for no applicable system status at 11s after 1s +2023-12-08T05:49:51Z TRACE Stage resume waiting for starting test wrapper at 11s +2023-12-08T05:49:51Z DEBUG Status level: 100 +2023-12-08T05:49:51Z DEBUG Clear configTransactions and reset device config +2023-12-08T05:49:51Z DEBUG Reading generated config file /home/peringknife/udmi/sites/udmi_site_model/devices/AHU-1/out/generated_config.json +2023-12-08T05:49:51Z DEBUG Configuring device last_start to be 2023-12-08T05:49:34Z +2023-12-08T05:49:51Z DEBUG last_start changed true, last_start 2023-12-08T05:49:34Z +2023-12-08T05:49:51Z DEBUG extraFieldChanged true because extra_field null +2023-12-08T05:49:52Z DEBUG system config extra field null +2023-12-08T05:49:52Z TRACE updated check config_system: true +2023-12-08T05:49:52Z DEBUG update config_system, configTransaction RC:1702014592859 +2023-12-08T05:49:52Z TRACE local local_system: { +2023-12-08T05:49:52Z TRACE local local_system: "min_loglevel" : 200, +2023-12-08T05:49:52Z TRACE local local_system: "metrics_rate_sec" : 10, +2023-12-08T05:49:52Z TRACE local local_system: "operation" : { +2023-12-08T05:49:52Z TRACE local local_system: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:49:52Z TRACE local local_system: }, +2023-12-08T05:49:52Z TRACE local local_system: "testing" : { +2023-12-08T05:49:52Z TRACE local local_system: "sequence_name" : "system_last_update" +2023-12-08T05:49:52Z TRACE local local_system: } +2023-12-08T05:49:52Z TRACE local local_system: } +2023-12-08T05:49:52Z TRACE updated check config_pointset: true +2023-12-08T05:49:52Z DEBUG update config_pointset, configTransaction RC:1702014592869 +2023-12-08T05:49:52Z TRACE local local_pointset: { +2023-12-08T05:49:52Z TRACE local local_pointset: "points" : { +2023-12-08T05:49:52Z TRACE local local_pointset: "filter_alarm_pressure_status" : { +2023-12-08T05:49:52Z TRACE local local_pointset: "ref" : "BV11.present_value", +2023-12-08T05:49:52Z TRACE local local_pointset: "units" : "No-units" +2023-12-08T05:49:52Z TRACE local local_pointset: }, +2023-12-08T05:49:52Z TRACE local local_pointset: "filter_differential_pressure_setpoint" : { +2023-12-08T05:49:52Z TRACE local local_pointset: "units" : "Bars", +2023-12-08T05:49:52Z TRACE local local_pointset: "set_value" : 98 +2023-12-08T05:49:52Z TRACE local local_pointset: }, +2023-12-08T05:49:52Z TRACE local local_pointset: "filter_differential_pressure_sensor" : { +2023-12-08T05:49:52Z TRACE local local_pointset: "ref" : "AV12.present_value", +2023-12-08T05:49:52Z TRACE local local_pointset: "units" : "Degrees-Celsius" +2023-12-08T05:49:52Z TRACE local local_pointset: } +2023-12-08T05:49:52Z TRACE local local_pointset: } +2023-12-08T05:49:52Z TRACE local local_pointset: } +2023-12-08T05:49:52Z TRACE updated check config_gateway: false +2023-12-08T05:49:52Z TRACE updated check config_localnet: true +2023-12-08T05:49:52Z DEBUG update config_localnet, configTransaction RC:1702014592883 +2023-12-08T05:49:52Z TRACE local local_localnet: { +2023-12-08T05:49:52Z TRACE local local_localnet: "families" : { +2023-12-08T05:49:52Z TRACE local local_localnet: "ether" : { +2023-12-08T05:49:52Z TRACE local local_localnet: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:49:52Z TRACE local local_localnet: }, +2023-12-08T05:49:52Z TRACE local local_localnet: "ipv4" : { +2023-12-08T05:49:52Z TRACE local local_localnet: "addr" : "192.168.2.1" +2023-12-08T05:49:52Z TRACE local local_localnet: } +2023-12-08T05:49:52Z TRACE local local_localnet: } +2023-12-08T05:49:52Z TRACE local local_localnet: } +2023-12-08T05:49:52Z TRACE updated check config_blobset: false +2023-12-08T05:49:52Z TRACE updated check config_discovery: false +2023-12-08T05:49:52Z DEBUG Update lastConfigUpdate 2023-12-08T05:49:52Z, because soft reset +2023-12-08T05:49:52Z TRACE stage suspend waiting for starting test wrapper at 13s +2023-12-08T05:49:52Z INFO Stage start waiting for config sync at 13s +2023-12-08T05:49:52Z TRACE received command AHU-1/state/update +2023-12-08T05:49:52Z DEBUG received state_update +2023-12-08T05:49:52Z DEBUG Handling update message state_update PS:9792711869841787 +2023-12-08T05:49:52Z DEBUG Updated state after 0s 2023-12-08T05:49:52Z PS:9792711869841787 +2023-12-08T05:49:52Z INFO Updated state #003: Changed 6 fields: +2023-12-08T05:49:52Z INFO Updated state #003: Set `system.last_config` = `2023-12-08T05:49:51Z` +2023-12-08T05:49:52Z INFO Updated state #003: Set `system.status.level` = `300` +2023-12-08T05:49:52Z INFO Updated state #003: Set `system.status.category` = `system.config.apply` +2023-12-08T05:49:52Z INFO Updated state #003: Set `system.status.timestamp` = `2023-12-08T05:49:51Z` +2023-12-08T05:49:52Z INFO Updated state #003: Set `timestamp` = `2023-12-08T05:49:52Z` +2023-12-08T05:49:52Z INFO Updated state #003: Remove `pointset` +2023-12-08T05:49:52Z DEBUG Updated state has last_config 2023-12-08T05:49:51Z (expecting null) +2023-12-08T05:49:52Z TRACE received command AHU-1/state/system +2023-12-08T05:49:52Z TRACE received state_system: { +2023-12-08T05:49:52Z TRACE received state_system: "hardware" : { +2023-12-08T05:49:52Z TRACE received state_system: "make" : "BOS", +2023-12-08T05:49:52Z TRACE received state_system: "model" : "pubber" +2023-12-08T05:49:52Z TRACE received state_system: }, +2023-12-08T05:49:52Z TRACE received state_system: "last_config" : "2023-12-08T05:49:51Z", +2023-12-08T05:49:52Z TRACE received state_system: "operation" : { +2023-12-08T05:49:52Z TRACE received state_system: "operational" : true, +2023-12-08T05:49:52Z TRACE received state_system: "last_start" : "2023-12-08T05:49:34Z", +2023-12-08T05:49:52Z TRACE received state_system: "restart_count" : 1, +2023-12-08T05:49:52Z TRACE received state_system: "mode" : "initial" +2023-12-08T05:49:52Z TRACE received state_system: }, +2023-12-08T05:49:52Z TRACE received state_system: "serial_no" : "sequencer-20544", +2023-12-08T05:49:52Z TRACE received state_system: "software" : { +2023-12-08T05:49:52Z TRACE received state_system: "firmware" : "v1" +2023-12-08T05:49:52Z TRACE received state_system: }, +2023-12-08T05:49:52Z TRACE received state_system: "status" : { +2023-12-08T05:49:52Z TRACE received state_system: "message" : "success", +2023-12-08T05:49:52Z TRACE received state_system: "category" : "system.config.apply", +2023-12-08T05:49:52Z TRACE received state_system: "timestamp" : "2023-12-08T05:49:51Z", +2023-12-08T05:49:52Z TRACE received state_system: "level" : 300 +2023-12-08T05:49:52Z TRACE received state_system: }, +2023-12-08T05:49:52Z TRACE received state_system: "timestamp" : "2023-12-08T05:49:52Z", +2023-12-08T05:49:52Z TRACE received state_system: "version" : "1.4.2" +2023-12-08T05:49:52Z TRACE received state_system: } +2023-12-08T05:49:52Z DEBUG Handling device message state_system PS:9792711869841787-0 +2023-12-08T05:49:52Z TRACE Ignoring partial state update +2023-12-08T05:49:52Z TRACE received command AHU-1/state/localnet +2023-12-08T05:49:52Z TRACE received state_localnet: { +2023-12-08T05:49:52Z TRACE received state_localnet: "families" : { +2023-12-08T05:49:52Z TRACE received state_localnet: "ether" : { +2023-12-08T05:49:52Z TRACE received state_localnet: "addr" : "40:1c:83:ca:77:54" +2023-12-08T05:49:52Z TRACE received state_localnet: }, +2023-12-08T05:49:52Z TRACE received state_localnet: "ipv4" : { +2023-12-08T05:49:52Z TRACE received state_localnet: "addr" : "10.132.154.140" +2023-12-08T05:49:52Z TRACE received state_localnet: }, +2023-12-08T05:49:52Z TRACE received state_localnet: "ipv6" : { +2023-12-08T05:49:52Z TRACE received state_localnet: "addr" : "fe80::f9e9:cab2:e374:401d" +2023-12-08T05:49:52Z TRACE received state_localnet: } +2023-12-08T05:49:52Z TRACE received state_localnet: }, +2023-12-08T05:49:52Z TRACE received state_localnet: "timestamp" : "2023-12-08T05:49:52Z", +2023-12-08T05:49:52Z TRACE received state_localnet: "version" : "1.4.2" +2023-12-08T05:49:52Z TRACE received state_localnet: } +2023-12-08T05:49:52Z DEBUG Handling device message state_localnet PS:9792711869841787-1 +2023-12-08T05:49:52Z TRACE Ignoring partial state update +2023-12-08T05:49:53Z TRACE received command AHU-1/config/update +2023-12-08T05:49:53Z DEBUG received config_update +2023-12-08T05:49:53Z DEBUG Handling update message config_update RC:1702014592883 +2023-12-08T05:49:53Z DEBUG Removed configTransaction RC:1702014592883 +2023-12-08T05:49:53Z DEBUG last_start changed false, last_start 2023-12-08T05:49:34Z +2023-12-08T05:49:53Z DEBUG Updated config 2023-12-08T05:49:53Z RC:1702014592883 +2023-12-08T05:49:53Z INFO Updated config #004: Changed 2 fields: +2023-12-08T05:49:53Z INFO Updated config #004: Add `pointset` = { "points": { "filter_alarm_pressure_status": { "ref": `BV11.present_value`, "units": `No-units` }, "filter_differential_pressure_setpoint": { "set_value": `98`, "units": `Bars` }, "filter_differential_pressure_sensor": { "ref": `AV12.present_value`, "units": `Degrees-Celsius` } } } +2023-12-08T05:49:53Z INFO Updated config #004: Add `localnet` = { "families": { "ether": { "addr": { "CASE_INSENSITIVE_ORDER": { } } }, "ipv4": { "addr": { "CASE_INSENSITIVE_ORDER": { } } } } } +2023-12-08T05:49:54Z TRACE received command AHU-1/config/update +2023-12-08T05:49:54Z DEBUG received config_update +2023-12-08T05:49:54Z DEBUG Handling update message config_update RC:1702014592859 +2023-12-08T05:49:54Z DEBUG Removed configTransaction RC:1702014592859 +2023-12-08T05:49:54Z DEBUG last_start changed false, last_start 2023-12-08T05:49:34Z +2023-12-08T05:49:54Z DEBUG Updated config 2023-12-08T05:49:54Z RC:1702014592859 +2023-12-08T05:49:54Z INFO Updated config #005: Changed 0 fields. +2023-12-08T05:49:54Z TRACE received command AHU-1/config/update +2023-12-08T05:49:54Z DEBUG received config_update +2023-12-08T05:49:54Z DEBUG Handling update message config_update RC:1702014592869 +2023-12-08T05:49:54Z DEBUG Removed configTransaction RC:1702014592869 +2023-12-08T05:49:54Z DEBUG last_start changed false, last_start 2023-12-08T05:49:34Z +2023-12-08T05:49:54Z DEBUG Updated config 2023-12-08T05:49:54Z RC:1702014592869 +2023-12-08T05:49:54Z INFO Updated config #006: Changed 0 fields. +2023-12-08T05:49:54Z DEBUG Status level: 300 +2023-12-08T05:49:54Z DEBUG Stage finished waiting for config sync at 14s after 1s +2023-12-08T05:49:54Z TRACE Stage resume waiting for starting test wrapper at 14s +2023-12-08T05:49:54Z DEBUG Configuration sync took 2s +2023-12-08T05:49:54Z DEBUG wait for config sync pending false +2023-12-08T05:49:54Z DEBUG Update config soft reset: 2023-12-08T05:49:54Z +2023-12-08T05:49:54Z TRACE local local_update: { +2023-12-08T05:49:54Z TRACE local local_update: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:49:54Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:49:54Z TRACE local local_update: "system" : { +2023-12-08T05:49:54Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:49:54Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:49:54Z TRACE local local_update: "operation" : { +2023-12-08T05:49:54Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:49:54Z TRACE local local_update: }, +2023-12-08T05:49:54Z TRACE local local_update: "testing" : { +2023-12-08T05:49:54Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:49:54Z TRACE local local_update: } +2023-12-08T05:49:54Z TRACE local local_update: }, +2023-12-08T05:49:54Z TRACE local local_update: "localnet" : { +2023-12-08T05:49:54Z TRACE local local_update: "families" : { +2023-12-08T05:49:54Z TRACE local local_update: "ether" : { +2023-12-08T05:49:54Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:49:54Z TRACE local local_update: }, +2023-12-08T05:49:54Z TRACE local local_update: "ipv4" : { +2023-12-08T05:49:54Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:49:54Z TRACE local local_update: } +2023-12-08T05:49:54Z TRACE local local_update: } +2023-12-08T05:49:54Z TRACE local local_update: }, +2023-12-08T05:49:54Z TRACE local local_update: "pointset" : { +2023-12-08T05:49:54Z TRACE local local_update: "points" : { +2023-12-08T05:49:54Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:49:54Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:49:54Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:49:54Z TRACE local local_update: }, +2023-12-08T05:49:54Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:49:54Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:49:54Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:49:54Z TRACE local local_update: }, +2023-12-08T05:49:54Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:49:54Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:49:54Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:49:54Z TRACE local local_update: } +2023-12-08T05:49:54Z TRACE local local_update: } +2023-12-08T05:49:54Z TRACE local local_update: } +2023-12-08T05:49:54Z TRACE local local_update: } +2023-12-08T05:49:54Z TRACE Update config soft reset: Add `pointset` = { "points": { "filter_alarm_pressure_status": { "ref": `BV11.present_value`, "units": `No-units` }, "filter_differential_pressure_setpoint": { "set_value": `98`, "units": `Bars` }, "filter_differential_pressure_sensor": { "ref": `AV12.present_value`, "units": `Degrees-Celsius` } } } +2023-12-08T05:49:54Z TRACE Update config soft reset: Add `localnet` = { "families": { "ether": { "addr": { "CASE_INSENSITIVE_ORDER": { } } }, "ipv4": { "addr": { "CASE_INSENSITIVE_ORDER": { } } } } } +2023-12-08T05:49:54Z DEBUG Done with reset_config +2023-12-08T05:49:54Z TRACE stage suspend waiting for starting test wrapper at 14s +2023-12-08T05:49:54Z INFO Stage start waiting for state last_config sync at 14s +2023-12-08T05:49:55Z DEBUG system config extra field null +2023-12-08T05:49:55Z TRACE updated check config_system: false +2023-12-08T05:49:55Z TRACE updated check config_pointset: false +2023-12-08T05:49:55Z TRACE updated check config_gateway: false +2023-12-08T05:49:55Z TRACE updated check config_localnet: false +2023-12-08T05:49:55Z TRACE updated check config_blobset: false +2023-12-08T05:49:55Z TRACE updated check config_discovery: false +2023-12-08T05:49:55Z DEBUG Update config Before state last_config sync: 2023-12-08T05:49:54Z +2023-12-08T05:49:55Z TRACE local local_update: { +2023-12-08T05:49:55Z TRACE local local_update: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:49:55Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:49:55Z TRACE local local_update: "system" : { +2023-12-08T05:49:55Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:49:55Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:49:55Z TRACE local local_update: "operation" : { +2023-12-08T05:49:55Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:49:55Z TRACE local local_update: }, +2023-12-08T05:49:55Z TRACE local local_update: "testing" : { +2023-12-08T05:49:55Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:49:55Z TRACE local local_update: } +2023-12-08T05:49:55Z TRACE local local_update: }, +2023-12-08T05:49:55Z TRACE local local_update: "localnet" : { +2023-12-08T05:49:55Z TRACE local local_update: "families" : { +2023-12-08T05:49:55Z TRACE local local_update: "ether" : { +2023-12-08T05:49:55Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:49:55Z TRACE local local_update: }, +2023-12-08T05:49:55Z TRACE local local_update: "ipv4" : { +2023-12-08T05:49:55Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:49:55Z TRACE local local_update: } +2023-12-08T05:49:55Z TRACE local local_update: } +2023-12-08T05:49:55Z TRACE local local_update: }, +2023-12-08T05:49:55Z TRACE local local_update: "pointset" : { +2023-12-08T05:49:55Z TRACE local local_update: "points" : { +2023-12-08T05:49:55Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:49:55Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:49:55Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:49:55Z TRACE local local_update: }, +2023-12-08T05:49:55Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:49:55Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:49:55Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:49:55Z TRACE local local_update: }, +2023-12-08T05:49:55Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:49:55Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:49:55Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:49:55Z TRACE local local_update: } +2023-12-08T05:49:55Z TRACE local local_update: } +2023-12-08T05:49:55Z TRACE local local_update: } +2023-12-08T05:49:55Z TRACE local local_update: } +2023-12-08T05:49:55Z TRACE received command AHU-1/state/update +2023-12-08T05:49:55Z DEBUG received state_update +2023-12-08T05:49:55Z DEBUG Handling update message state_update PS:9792539778084013 +2023-12-08T05:49:55Z DEBUG Updated state after 1s 2023-12-08T05:49:54Z PS:9792539778084013 +2023-12-08T05:49:55Z INFO Updated state #004: Changed 3 fields: +2023-12-08T05:49:55Z INFO Updated state #004: Set `system.last_config` = `2023-12-08T05:49:54Z` +2023-12-08T05:49:55Z INFO Updated state #004: Set `system.status.timestamp` = `2023-12-08T05:49:54Z` +2023-12-08T05:49:55Z INFO Updated state #004: Set `timestamp` = `2023-12-08T05:49:54Z` +2023-12-08T05:49:55Z DEBUG Updated state has last_config 2023-12-08T05:49:54Z (expecting 2023-12-08T05:49:54Z) +2023-12-08T05:49:55Z DEBUG Status level: 300 +2023-12-08T05:49:55Z DEBUG Stage finished waiting for state last_config sync at 15s after 1s +2023-12-08T05:49:55Z TRACE Stage resume waiting for starting test wrapper at 15s +2023-12-08T05:49:55Z INFO Disallowing device state change +2023-12-08T05:49:56Z DEBUG system config extra field null +2023-12-08T05:49:56Z TRACE updated check config_system: false +2023-12-08T05:49:56Z TRACE updated check config_pointset: false +2023-12-08T05:49:56Z TRACE updated check config_gateway: false +2023-12-08T05:49:56Z TRACE updated check config_localnet: false +2023-12-08T05:49:56Z TRACE updated check config_blobset: false +2023-12-08T05:49:56Z TRACE updated check config_discovery: false +2023-12-08T05:49:56Z DEBUG Update config initial setup: 2023-12-08T05:49:54Z +2023-12-08T05:49:56Z TRACE local local_update: { +2023-12-08T05:49:56Z TRACE local local_update: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:49:56Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:49:56Z TRACE local local_update: "system" : { +2023-12-08T05:49:56Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:49:56Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:49:56Z TRACE local local_update: "operation" : { +2023-12-08T05:49:56Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:49:56Z TRACE local local_update: }, +2023-12-08T05:49:56Z TRACE local local_update: "testing" : { +2023-12-08T05:49:56Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:49:56Z TRACE local local_update: } +2023-12-08T05:49:56Z TRACE local local_update: }, +2023-12-08T05:49:56Z TRACE local local_update: "localnet" : { +2023-12-08T05:49:56Z TRACE local local_update: "families" : { +2023-12-08T05:49:56Z TRACE local local_update: "ether" : { +2023-12-08T05:49:56Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:49:56Z TRACE local local_update: }, +2023-12-08T05:49:56Z TRACE local local_update: "ipv4" : { +2023-12-08T05:49:56Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:49:56Z TRACE local local_update: } +2023-12-08T05:49:56Z TRACE local local_update: } +2023-12-08T05:49:56Z TRACE local local_update: }, +2023-12-08T05:49:56Z TRACE local local_update: "pointset" : { +2023-12-08T05:49:56Z TRACE local local_update: "points" : { +2023-12-08T05:49:56Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:49:56Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:49:56Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:49:56Z TRACE local local_update: }, +2023-12-08T05:49:56Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:49:56Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:49:56Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:49:56Z TRACE local local_update: }, +2023-12-08T05:49:56Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:49:56Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:49:56Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:49:56Z TRACE local local_update: } +2023-12-08T05:49:56Z TRACE local local_update: } +2023-12-08T05:49:56Z TRACE local local_update: } +2023-12-08T05:49:56Z TRACE local local_update: } +2023-12-08T05:49:56Z DEBUG Waiting for device stateTransaction RC:1702014596645 (was null) +2023-12-08T05:49:56Z TRACE stage suspend waiting for starting test wrapper at 16s +2023-12-08T05:49:56Z INFO Stage start waiting for state query at 16s +2023-12-08T05:49:56Z TRACE received command AHU-1/state/system +2023-12-08T05:49:56Z TRACE received state_system: { +2023-12-08T05:49:56Z TRACE received state_system: "hardware" : { +2023-12-08T05:49:56Z TRACE received state_system: "make" : "BOS", +2023-12-08T05:49:56Z TRACE received state_system: "model" : "pubber" +2023-12-08T05:49:56Z TRACE received state_system: }, +2023-12-08T05:49:56Z TRACE received state_system: "last_config" : "2023-12-08T05:49:54Z", +2023-12-08T05:49:56Z TRACE received state_system: "operation" : { +2023-12-08T05:49:56Z TRACE received state_system: "operational" : true, +2023-12-08T05:49:56Z TRACE received state_system: "last_start" : "2023-12-08T05:49:34Z", +2023-12-08T05:49:56Z TRACE received state_system: "restart_count" : 1, +2023-12-08T05:49:56Z TRACE received state_system: "mode" : "initial" +2023-12-08T05:49:56Z TRACE received state_system: }, +2023-12-08T05:49:56Z TRACE received state_system: "serial_no" : "sequencer-20544", +2023-12-08T05:49:56Z TRACE received state_system: "software" : { +2023-12-08T05:49:56Z TRACE received state_system: "firmware" : "v1" +2023-12-08T05:49:56Z TRACE received state_system: }, +2023-12-08T05:49:56Z TRACE received state_system: "status" : { +2023-12-08T05:49:56Z TRACE received state_system: "message" : "success", +2023-12-08T05:49:56Z TRACE received state_system: "category" : "system.config.apply", +2023-12-08T05:49:56Z TRACE received state_system: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:49:56Z TRACE received state_system: "level" : 300 +2023-12-08T05:49:56Z TRACE received state_system: }, +2023-12-08T05:49:56Z TRACE received state_system: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:49:56Z TRACE received state_system: "version" : "1.4.2" +2023-12-08T05:49:56Z TRACE received state_system: } +2023-12-08T05:49:56Z DEBUG Handling device message state_system PS:9792539778084013-0 +2023-12-08T05:49:56Z TRACE Ignoring partial state update +2023-12-08T05:49:56Z TRACE received command AHU-1/state/localnet +2023-12-08T05:49:56Z TRACE received state_localnet: { +2023-12-08T05:49:56Z TRACE received state_localnet: "families" : { +2023-12-08T05:49:56Z TRACE received state_localnet: "ether" : { +2023-12-08T05:49:56Z TRACE received state_localnet: "addr" : "40:1c:83:ca:77:54" +2023-12-08T05:49:56Z TRACE received state_localnet: }, +2023-12-08T05:49:56Z TRACE received state_localnet: "ipv4" : { +2023-12-08T05:49:56Z TRACE received state_localnet: "addr" : "10.132.154.140" +2023-12-08T05:49:56Z TRACE received state_localnet: }, +2023-12-08T05:49:56Z TRACE received state_localnet: "ipv6" : { +2023-12-08T05:49:56Z TRACE received state_localnet: "addr" : "fe80::f9e9:cab2:e374:401d" +2023-12-08T05:49:56Z TRACE received state_localnet: } +2023-12-08T05:49:56Z TRACE received state_localnet: }, +2023-12-08T05:49:56Z TRACE received state_localnet: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:49:56Z TRACE received state_localnet: "version" : "1.4.2" +2023-12-08T05:49:56Z TRACE received state_localnet: } +2023-12-08T05:49:56Z DEBUG Handling device message state_localnet PS:9792539778084013-1 +2023-12-08T05:49:56Z TRACE Ignoring partial state update +2023-12-08T05:49:56Z TRACE received command AHU-1/event/system +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:50Z WARNING device.log: Terminating PointsetManager sender +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:50Z WARNING device.log: Starting PointsetManager sender with delay 0s +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:50Z NOTICE system.config.apply: success +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:50Z INFO device.log: Device AHU-1 config handler +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:50Z INFO device.log: 2023-12-08T05:49:50Z received config 2023-12-08T05:49:50Z +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:50Z WARNING device.log: Starting PointsetManager sender with delay 0s +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:50Z NOTICE system.config.apply: success +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:51Z INFO device.log: Device AHU-1 config handler +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:51Z INFO device.log: 2023-12-08T05:49:51Z received config 2023-12-08T05:49:51Z +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:51Z WARNING device.log: Starting PointsetManager sender with delay 0s +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:51Z NOTICE system.config.apply: success +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:52Z INFO device.log: Update state 2023-12-08T05:49:52Z last_config 2023-12-08T05:49:51Z +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:53Z INFO device.log: Device AHU-1 config handler +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:53Z INFO device.log: 2023-12-08T05:49:53Z received config 2023-12-08T05:49:53Z +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:53Z WARNING device.log: Starting PointsetManager sender with delay 0s +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:53Z NOTICE system.config.apply: success +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:54Z INFO device.log: Device AHU-1 config handler +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:54Z INFO device.log: 2023-12-08T05:49:54Z received config 2023-12-08T05:49:54Z +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:54Z WARNING device.log: Starting PointsetManager sender with delay 0s +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:54Z NOTICE system.config.apply: success +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:54Z INFO device.log: Update state 2023-12-08T05:49:54Z last_config 2023-12-08T05:49:54Z +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:54Z INFO device.log: Device AHU-1 config handler +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:54Z INFO device.log: 2023-12-08T05:49:54Z received config 2023-12-08T05:49:54Z +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:54Z WARNING device.log: Starting PointsetManager sender with delay 10s +2023-12-08T05:49:56Z DEBUG received event_system 2023-12-08T05:49:54Z NOTICE system.config.apply: success +2023-12-08T05:49:56Z DEBUG Handling device message event_system PS:9106410344164306 +2023-12-08T05:49:56Z TRACE received command AHU-1/state/update +2023-12-08T05:49:56Z DEBUG received state_update +2023-12-08T05:49:57Z DEBUG Handling update message state_update RC:1702014596645 +2023-12-08T05:49:57Z DEBUG Removed stateTransaction RC:1702014596645 +2023-12-08T05:49:57Z WARNING Ignoring out-of-order state update 2023-12-08T05:49:40Z RC:1702014596645 +2023-12-08T05:49:57Z DEBUG Status level: 300 +2023-12-08T05:49:57Z DEBUG Stage finished waiting for state query at 17s after 0s +2023-12-08T05:49:57Z TRACE Stage resume waiting for starting test wrapper at 17s +2023-12-08T05:49:57Z TRACE stage suspend waiting for starting test wrapper at 17s +2023-12-08T05:49:57Z INFO Stage start waiting for device state update at 17s +2023-12-08T05:49:58Z DEBUG system config extra field null +2023-12-08T05:49:58Z TRACE updated check config_system: false +2023-12-08T05:49:58Z TRACE updated check config_pointset: false +2023-12-08T05:49:58Z TRACE updated check config_gateway: false +2023-12-08T05:49:58Z TRACE updated check config_localnet: false +2023-12-08T05:49:58Z TRACE updated check config_blobset: false +2023-12-08T05:49:58Z TRACE updated check config_discovery: false +2023-12-08T05:49:58Z DEBUG Update config before device state update: 2023-12-08T05:49:54Z +2023-12-08T05:49:58Z TRACE local local_update: { +2023-12-08T05:49:58Z TRACE local local_update: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:49:58Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:49:58Z TRACE local local_update: "system" : { +2023-12-08T05:49:58Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:49:58Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:49:58Z TRACE local local_update: "operation" : { +2023-12-08T05:49:58Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:49:58Z TRACE local local_update: }, +2023-12-08T05:49:58Z TRACE local local_update: "testing" : { +2023-12-08T05:49:58Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:49:58Z TRACE local local_update: } +2023-12-08T05:49:58Z TRACE local local_update: }, +2023-12-08T05:49:58Z TRACE local local_update: "localnet" : { +2023-12-08T05:49:58Z TRACE local local_update: "families" : { +2023-12-08T05:49:58Z TRACE local local_update: "ether" : { +2023-12-08T05:49:58Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:49:58Z TRACE local local_update: }, +2023-12-08T05:49:58Z TRACE local local_update: "ipv4" : { +2023-12-08T05:49:58Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:49:58Z TRACE local local_update: } +2023-12-08T05:49:58Z TRACE local local_update: } +2023-12-08T05:49:58Z TRACE local local_update: }, +2023-12-08T05:49:58Z TRACE local local_update: "pointset" : { +2023-12-08T05:49:58Z TRACE local local_update: "points" : { +2023-12-08T05:49:58Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:49:58Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:49:58Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:49:58Z TRACE local local_update: }, +2023-12-08T05:49:58Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:49:58Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:49:58Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:49:58Z TRACE local local_update: }, +2023-12-08T05:49:58Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:49:58Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:49:58Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:49:58Z TRACE local local_update: } +2023-12-08T05:49:58Z TRACE local local_update: } +2023-12-08T05:49:58Z TRACE local local_update: } +2023-12-08T05:49:58Z TRACE local local_update: } +2023-12-08T05:49:58Z DEBUG Status level: 300 +2023-12-08T05:49:58Z DEBUG Stage finished waiting for device state update at 18s after 1s +2023-12-08T05:49:58Z TRACE Stage resume waiting for starting test wrapper at 18s +2023-12-08T05:49:58Z DEBUG Status level: 300 +2023-12-08T05:49:58Z TRACE stage suspend waiting for starting test wrapper at 18s +2023-12-08T05:49:58Z INFO Stage start waiting for state last_config sync at 18s +2023-12-08T05:49:59Z DEBUG system config extra field null +2023-12-08T05:49:59Z TRACE updated check config_system: false +2023-12-08T05:49:59Z TRACE updated check config_pointset: false +2023-12-08T05:49:59Z TRACE updated check config_gateway: false +2023-12-08T05:49:59Z TRACE updated check config_localnet: false +2023-12-08T05:49:59Z TRACE updated check config_blobset: false +2023-12-08T05:49:59Z TRACE updated check config_discovery: false +2023-12-08T05:49:59Z DEBUG Update config Before state last_config sync: 2023-12-08T05:49:54Z +2023-12-08T05:49:59Z TRACE local local_update: { +2023-12-08T05:49:59Z TRACE local local_update: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:49:59Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:49:59Z TRACE local local_update: "system" : { +2023-12-08T05:49:59Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:49:59Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:49:59Z TRACE local local_update: "operation" : { +2023-12-08T05:49:59Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:49:59Z TRACE local local_update: }, +2023-12-08T05:49:59Z TRACE local local_update: "testing" : { +2023-12-08T05:49:59Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:49:59Z TRACE local local_update: } +2023-12-08T05:49:59Z TRACE local local_update: }, +2023-12-08T05:49:59Z TRACE local local_update: "localnet" : { +2023-12-08T05:49:59Z TRACE local local_update: "families" : { +2023-12-08T05:49:59Z TRACE local local_update: "ether" : { +2023-12-08T05:49:59Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:49:59Z TRACE local local_update: }, +2023-12-08T05:49:59Z TRACE local local_update: "ipv4" : { +2023-12-08T05:49:59Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:49:59Z TRACE local local_update: } +2023-12-08T05:49:59Z TRACE local local_update: } +2023-12-08T05:49:59Z TRACE local local_update: }, +2023-12-08T05:49:59Z TRACE local local_update: "pointset" : { +2023-12-08T05:49:59Z TRACE local local_update: "points" : { +2023-12-08T05:49:59Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:49:59Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:49:59Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:49:59Z TRACE local local_update: }, +2023-12-08T05:49:59Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:49:59Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:49:59Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:49:59Z TRACE local local_update: }, +2023-12-08T05:49:59Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:49:59Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:49:59Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:49:59Z TRACE local local_update: } +2023-12-08T05:49:59Z TRACE local local_update: } +2023-12-08T05:49:59Z TRACE local local_update: } +2023-12-08T05:49:59Z TRACE local local_update: } +2023-12-08T05:49:59Z DEBUG Status level: 300 +2023-12-08T05:49:59Z DEBUG Stage finished waiting for state last_config sync at 19s after 1s +2023-12-08T05:49:59Z TRACE Stage resume waiting for starting test wrapper at 19s +2023-12-08T05:49:59Z TRACE stage suspend waiting for starting test wrapper at 19s +2023-12-08T05:49:59Z INFO Stage start waiting for executing test at 19s +2023-12-08T05:49:59Z DEBUG stage begin waiting for executing test at 19s +2023-12-08T05:49:59Z TRACE stage suspend waiting for executing test at 19s +2023-12-08T05:49:59Z INFO Stage start waiting for state last_config matches first config timestamp at 19s +2023-12-08T05:50:00Z DEBUG system config extra field null +2023-12-08T05:50:00Z TRACE updated check config_system: false +2023-12-08T05:50:00Z TRACE updated check config_pointset: false +2023-12-08T05:50:00Z TRACE updated check config_gateway: false +2023-12-08T05:50:00Z TRACE updated check config_localnet: false +2023-12-08T05:50:00Z TRACE updated check config_blobset: false +2023-12-08T05:50:00Z TRACE updated check config_discovery: false +2023-12-08T05:50:00Z DEBUG Update config before state last_config matches first config timestamp: 2023-12-08T05:49:54Z +2023-12-08T05:50:00Z TRACE local local_update: { +2023-12-08T05:50:00Z TRACE local local_update: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:50:00Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:50:00Z TRACE local local_update: "system" : { +2023-12-08T05:50:00Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:50:00Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:50:00Z TRACE local local_update: "operation" : { +2023-12-08T05:50:00Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:50:00Z TRACE local local_update: }, +2023-12-08T05:50:00Z TRACE local local_update: "testing" : { +2023-12-08T05:50:00Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:50:00Z TRACE local local_update: } +2023-12-08T05:50:00Z TRACE local local_update: }, +2023-12-08T05:50:00Z TRACE local local_update: "localnet" : { +2023-12-08T05:50:00Z TRACE local local_update: "families" : { +2023-12-08T05:50:00Z TRACE local local_update: "ether" : { +2023-12-08T05:50:00Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:50:00Z TRACE local local_update: }, +2023-12-08T05:50:00Z TRACE local local_update: "ipv4" : { +2023-12-08T05:50:00Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:50:00Z TRACE local local_update: } +2023-12-08T05:50:00Z TRACE local local_update: } +2023-12-08T05:50:00Z TRACE local local_update: }, +2023-12-08T05:50:00Z TRACE local local_update: "pointset" : { +2023-12-08T05:50:00Z TRACE local local_update: "points" : { +2023-12-08T05:50:00Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:50:00Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:50:00Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:50:00Z TRACE local local_update: }, +2023-12-08T05:50:00Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:00Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:50:00Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:50:00Z TRACE local local_update: }, +2023-12-08T05:50:00Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:00Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:50:00Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:50:00Z TRACE local local_update: } +2023-12-08T05:50:00Z TRACE local local_update: } +2023-12-08T05:50:00Z TRACE local local_update: } +2023-12-08T05:50:00Z TRACE local local_update: } +2023-12-08T05:50:00Z DEBUG Status level: 300 +2023-12-08T05:50:00Z DEBUG Stage finished waiting for state last_config matches first config timestamp at 20s after 1s +2023-12-08T05:50:00Z TRACE Stage resume waiting for executing test at 20s +2023-12-08T05:50:00Z TRACE stage suspend waiting for executing test at 20s +2023-12-08T05:50:00Z INFO Stage start waiting for state update complete at 20s +2023-12-08T05:50:01Z DEBUG system config extra field null +2023-12-08T05:50:01Z TRACE updated check config_system: false +2023-12-08T05:50:01Z TRACE updated check config_pointset: false +2023-12-08T05:50:01Z TRACE updated check config_gateway: false +2023-12-08T05:50:01Z TRACE updated check config_localnet: false +2023-12-08T05:50:01Z TRACE updated check config_blobset: false +2023-12-08T05:50:01Z TRACE updated check config_discovery: false +2023-12-08T05:50:01Z DEBUG Update config before state update complete: 2023-12-08T05:49:54Z +2023-12-08T05:50:01Z TRACE local local_update: { +2023-12-08T05:50:01Z TRACE local local_update: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:50:01Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:50:01Z TRACE local local_update: "system" : { +2023-12-08T05:50:01Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:50:01Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:50:01Z TRACE local local_update: "operation" : { +2023-12-08T05:50:01Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:50:01Z TRACE local local_update: }, +2023-12-08T05:50:01Z TRACE local local_update: "testing" : { +2023-12-08T05:50:01Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:50:01Z TRACE local local_update: } +2023-12-08T05:50:01Z TRACE local local_update: }, +2023-12-08T05:50:01Z TRACE local local_update: "localnet" : { +2023-12-08T05:50:01Z TRACE local local_update: "families" : { +2023-12-08T05:50:01Z TRACE local local_update: "ether" : { +2023-12-08T05:50:01Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:50:01Z TRACE local local_update: }, +2023-12-08T05:50:01Z TRACE local local_update: "ipv4" : { +2023-12-08T05:50:01Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:50:01Z TRACE local local_update: } +2023-12-08T05:50:01Z TRACE local local_update: } +2023-12-08T05:50:01Z TRACE local local_update: }, +2023-12-08T05:50:01Z TRACE local local_update: "pointset" : { +2023-12-08T05:50:01Z TRACE local local_update: "points" : { +2023-12-08T05:50:01Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:50:01Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:50:01Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:50:01Z TRACE local local_update: }, +2023-12-08T05:50:01Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:01Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:50:01Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:50:01Z TRACE local local_update: }, +2023-12-08T05:50:01Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:01Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:50:01Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:50:01Z TRACE local local_update: } +2023-12-08T05:50:01Z TRACE local local_update: } +2023-12-08T05:50:01Z TRACE local local_update: } +2023-12-08T05:50:01Z TRACE local local_update: } +2023-12-08T05:50:01Z TRACE received command AHU-1/reply/update +2023-12-08T05:50:01Z TRACE received command AHU-1/state/update +2023-12-08T05:50:01Z DEBUG received state_update +2023-12-08T05:50:01Z DEBUG Handling update message state_update PS:9106208948243115 +2023-12-08T05:50:01Z DEBUG Updated state after 5s 2023-12-08T05:49:56Z PS:9106208948243115 +2023-12-08T05:50:01Z INFO Updated state #006: Changed 2 fields: +2023-12-08T05:50:01Z INFO Updated state #006: Add `pointset` = { "points": { "filter_alarm_pressure_status": { }, "filter_differential_pressure_setpoint": { "value_state": `applied`, "units": `Bars` }, "filter_differential_pressure_sensor": { "units": `Degrees-Celsius` } } } +2023-12-08T05:50:01Z INFO Updated state #006: Set `timestamp` = `2023-12-08T05:49:56Z` +2023-12-08T05:50:01Z WARNING Unexpected state change: Add `pointset` = { "points": { "filter_alarm_pressure_status": { }, "filter_differential_pressure_setpoint": { "value_state": `applied`, "units": `Bars` }, "filter_differential_pressure_sensor": { "units": `Degrees-Celsius` } } } +2023-12-08T05:50:01Z DEBUG Updated state has last_config 2023-12-08T05:49:54Z (expecting 2023-12-08T05:49:54Z) +2023-12-08T05:50:01Z DEBUG Status level: 300 +2023-12-08T05:50:01Z DEBUG Stage finished waiting for state update complete at 21s after 1s +2023-12-08T05:50:01Z TRACE Stage resume waiting for executing test at 21s +2023-12-08T05:50:02Z DEBUG system config extra field null +2023-12-08T05:50:02Z TRACE updated check config_system: false +2023-12-08T05:50:02Z TRACE updated check config_pointset: false +2023-12-08T05:50:02Z TRACE updated check config_gateway: false +2023-12-08T05:50:02Z TRACE updated check config_localnet: false +2023-12-08T05:50:02Z TRACE updated check config_blobset: false +2023-12-08T05:50:02Z TRACE updated check config_discovery: false +2023-12-08T05:50:02Z DEBUG Forcing config update +2023-12-08T05:50:02Z TRACE updated check config_update: true +2023-12-08T05:50:02Z DEBUG update config_update, configTransaction RC:1702014602057 +2023-12-08T05:50:02Z TRACE local local_update: { +2023-12-08T05:50:02Z TRACE local local_update: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:50:02Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:50:02Z TRACE local local_update: "system" : { +2023-12-08T05:50:02Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:50:02Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:50:02Z TRACE local local_update: "operation" : { +2023-12-08T05:50:02Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "testing" : { +2023-12-08T05:50:02Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "localnet" : { +2023-12-08T05:50:02Z TRACE local local_update: "families" : { +2023-12-08T05:50:02Z TRACE local local_update: "ether" : { +2023-12-08T05:50:02Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "ipv4" : { +2023-12-08T05:50:02Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "pointset" : { +2023-12-08T05:50:02Z TRACE local local_update: "points" : { +2023-12-08T05:50:02Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:50:02Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:50:02Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:02Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:50:02Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:02Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:50:02Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z DEBUG Update lastConfigUpdate 2023-12-08T05:50:02Z, because trigger another config update +2023-12-08T05:50:02Z TRACE stage suspend waiting for executing test at 22s +2023-12-08T05:50:02Z INFO Stage start waiting for config sync at 22s +2023-12-08T05:50:02Z TRACE received command AHU-1/state/system +2023-12-08T05:50:02Z TRACE received state_system: { +2023-12-08T05:50:02Z TRACE received state_system: "hardware" : { +2023-12-08T05:50:02Z TRACE received state_system: "make" : "BOS", +2023-12-08T05:50:02Z TRACE received state_system: "model" : "pubber" +2023-12-08T05:50:02Z TRACE received state_system: }, +2023-12-08T05:50:02Z TRACE received state_system: "last_config" : "2023-12-08T05:49:54Z", +2023-12-08T05:50:02Z TRACE received state_system: "operation" : { +2023-12-08T05:50:02Z TRACE received state_system: "operational" : true, +2023-12-08T05:50:02Z TRACE received state_system: "last_start" : "2023-12-08T05:49:34Z", +2023-12-08T05:50:02Z TRACE received state_system: "restart_count" : 1, +2023-12-08T05:50:02Z TRACE received state_system: "mode" : "initial" +2023-12-08T05:50:02Z TRACE received state_system: }, +2023-12-08T05:50:02Z TRACE received state_system: "serial_no" : "sequencer-20544", +2023-12-08T05:50:02Z TRACE received state_system: "software" : { +2023-12-08T05:50:02Z TRACE received state_system: "firmware" : "v1" +2023-12-08T05:50:02Z TRACE received state_system: }, +2023-12-08T05:50:02Z TRACE received state_system: "status" : { +2023-12-08T05:50:02Z TRACE received state_system: "message" : "success", +2023-12-08T05:50:02Z TRACE received state_system: "category" : "system.config.apply", +2023-12-08T05:50:02Z TRACE received state_system: "timestamp" : "2023-12-08T05:49:54Z", +2023-12-08T05:50:02Z TRACE received state_system: "level" : 300 +2023-12-08T05:50:02Z TRACE received state_system: }, +2023-12-08T05:50:02Z TRACE received state_system: "timestamp" : "2023-12-08T05:49:56Z", +2023-12-08T05:50:02Z TRACE received state_system: "version" : "1.4.2" +2023-12-08T05:50:02Z TRACE received state_system: } +2023-12-08T05:50:02Z DEBUG Handling device message state_system PS:9106208948243115-0 +2023-12-08T05:50:02Z TRACE Ignoring partial state update +2023-12-08T05:50:02Z TRACE received command AHU-1/state/localnet +2023-12-08T05:50:02Z TRACE received state_localnet: { +2023-12-08T05:50:02Z TRACE received state_localnet: "families" : { +2023-12-08T05:50:02Z TRACE received state_localnet: "ether" : { +2023-12-08T05:50:02Z TRACE received state_localnet: "addr" : "40:1c:83:ca:77:54" +2023-12-08T05:50:02Z TRACE received state_localnet: }, +2023-12-08T05:50:02Z TRACE received state_localnet: "ipv4" : { +2023-12-08T05:50:02Z TRACE received state_localnet: "addr" : "10.132.154.140" +2023-12-08T05:50:02Z TRACE received state_localnet: }, +2023-12-08T05:50:02Z TRACE received state_localnet: "ipv6" : { +2023-12-08T05:50:02Z TRACE received state_localnet: "addr" : "fe80::f9e9:cab2:e374:401d" +2023-12-08T05:50:02Z TRACE received state_localnet: } +2023-12-08T05:50:02Z TRACE received state_localnet: }, +2023-12-08T05:50:02Z TRACE received state_localnet: "timestamp" : "2023-12-08T05:49:56Z", +2023-12-08T05:50:02Z TRACE received state_localnet: "version" : "1.4.2" +2023-12-08T05:50:02Z TRACE received state_localnet: } +2023-12-08T05:50:02Z DEBUG Handling device message state_localnet PS:9106208948243115-1 +2023-12-08T05:50:02Z TRACE Ignoring partial state update +2023-12-08T05:50:02Z TRACE received command AHU-1/state/pointset +2023-12-08T05:50:02Z TRACE received state_pointset: { +2023-12-08T05:50:02Z TRACE received state_pointset: "points" : { +2023-12-08T05:50:02Z TRACE received state_pointset: "filter_alarm_pressure_status" : { }, +2023-12-08T05:50:02Z TRACE received state_pointset: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:02Z TRACE received state_pointset: "units" : "Bars", +2023-12-08T05:50:02Z TRACE received state_pointset: "value_state" : "applied" +2023-12-08T05:50:02Z TRACE received state_pointset: }, +2023-12-08T05:50:02Z TRACE received state_pointset: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:02Z TRACE received state_pointset: "units" : "Degrees-Celsius" +2023-12-08T05:50:02Z TRACE received state_pointset: } +2023-12-08T05:50:02Z TRACE received state_pointset: }, +2023-12-08T05:50:02Z TRACE received state_pointset: "timestamp" : "2023-12-08T05:49:56Z", +2023-12-08T05:50:02Z TRACE received state_pointset: "version" : "1.4.2" +2023-12-08T05:50:02Z TRACE received state_pointset: } +2023-12-08T05:50:02Z DEBUG Handling device message state_pointset PS:9106208948243115-2 +2023-12-08T05:50:02Z TRACE Ignoring partial state update +2023-12-08T05:50:02Z TRACE received command null/null/error +2023-12-08T05:50:02Z TRACE received command AHU-1/config/update +2023-12-08T05:50:02Z DEBUG received config_update +2023-12-08T05:50:02Z DEBUG Handling update message config_update RC:1702014602057 +2023-12-08T05:50:02Z DEBUG Removed configTransaction RC:1702014602057 +2023-12-08T05:50:02Z DEBUG last_start changed false, last_start 2023-12-08T05:49:34Z +2023-12-08T05:50:02Z DEBUG Updated config 2023-12-08T05:50:02Z RC:1702014602057 +2023-12-08T05:50:02Z INFO Updated config #007: Changed 0 fields. +2023-12-08T05:50:02Z DEBUG Status level: 300 +2023-12-08T05:50:02Z DEBUG Stage finished waiting for config sync at 22s after 0s +2023-12-08T05:50:02Z TRACE Stage resume waiting for executing test at 22s +2023-12-08T05:50:02Z DEBUG Configuration sync took 0s +2023-12-08T05:50:02Z DEBUG wait for config sync pending false +2023-12-08T05:50:02Z DEBUG Update config trigger another config update: 2023-12-08T05:50:02Z +2023-12-08T05:50:02Z TRACE local local_update: { +2023-12-08T05:50:02Z TRACE local local_update: "timestamp" : "2023-12-08T05:50:02Z", +2023-12-08T05:50:02Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:50:02Z TRACE local local_update: "system" : { +2023-12-08T05:50:02Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:50:02Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:50:02Z TRACE local local_update: "operation" : { +2023-12-08T05:50:02Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "testing" : { +2023-12-08T05:50:02Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "localnet" : { +2023-12-08T05:50:02Z TRACE local local_update: "families" : { +2023-12-08T05:50:02Z TRACE local local_update: "ether" : { +2023-12-08T05:50:02Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "ipv4" : { +2023-12-08T05:50:02Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "pointset" : { +2023-12-08T05:50:02Z TRACE local local_update: "points" : { +2023-12-08T05:50:02Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:50:02Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:50:02Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:02Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:50:02Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:50:02Z TRACE local local_update: }, +2023-12-08T05:50:02Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:02Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:50:02Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE local local_update: } +2023-12-08T05:50:02Z TRACE stage suspend waiting for executing test at 22s +2023-12-08T05:50:02Z INFO Stage start waiting for state last_config matches new config timestamp at 22s +2023-12-08T05:50:03Z DEBUG system config extra field null +2023-12-08T05:50:03Z TRACE updated check config_system: false +2023-12-08T05:50:03Z TRACE updated check config_pointset: false +2023-12-08T05:50:03Z TRACE updated check config_gateway: false +2023-12-08T05:50:03Z TRACE updated check config_localnet: false +2023-12-08T05:50:03Z TRACE updated check config_blobset: false +2023-12-08T05:50:03Z TRACE updated check config_discovery: false +2023-12-08T05:50:03Z DEBUG Update config before state last_config matches new config timestamp: 2023-12-08T05:50:02Z +2023-12-08T05:50:03Z TRACE local local_update: { +2023-12-08T05:50:03Z TRACE local local_update: "timestamp" : "2023-12-08T05:50:02Z", +2023-12-08T05:50:03Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:50:03Z TRACE local local_update: "system" : { +2023-12-08T05:50:03Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:50:03Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:50:03Z TRACE local local_update: "operation" : { +2023-12-08T05:50:03Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:50:03Z TRACE local local_update: }, +2023-12-08T05:50:03Z TRACE local local_update: "testing" : { +2023-12-08T05:50:03Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:50:03Z TRACE local local_update: } +2023-12-08T05:50:03Z TRACE local local_update: }, +2023-12-08T05:50:03Z TRACE local local_update: "localnet" : { +2023-12-08T05:50:03Z TRACE local local_update: "families" : { +2023-12-08T05:50:03Z TRACE local local_update: "ether" : { +2023-12-08T05:50:03Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:50:03Z TRACE local local_update: }, +2023-12-08T05:50:03Z TRACE local local_update: "ipv4" : { +2023-12-08T05:50:03Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:50:03Z TRACE local local_update: } +2023-12-08T05:50:03Z TRACE local local_update: } +2023-12-08T05:50:03Z TRACE local local_update: }, +2023-12-08T05:50:03Z TRACE local local_update: "pointset" : { +2023-12-08T05:50:03Z TRACE local local_update: "points" : { +2023-12-08T05:50:03Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:50:03Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:50:03Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:50:03Z TRACE local local_update: }, +2023-12-08T05:50:03Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:03Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:50:03Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:50:03Z TRACE local local_update: }, +2023-12-08T05:50:03Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:03Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:50:03Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:50:03Z TRACE local local_update: } +2023-12-08T05:50:03Z TRACE local local_update: } +2023-12-08T05:50:03Z TRACE local local_update: } +2023-12-08T05:50:03Z TRACE local local_update: } +2023-12-08T05:50:03Z TRACE received command AHU-1/state/update +2023-12-08T05:50:03Z DEBUG received state_update +2023-12-08T05:50:03Z DEBUG Handling update message state_update PS:9793159036195486 +2023-12-08T05:50:03Z DEBUG Updated state after 1s 2023-12-08T05:50:02Z PS:9793159036195486 +2023-12-08T05:50:03Z INFO Updated state #007: Changed 4 fields: +2023-12-08T05:50:03Z INFO Updated state #007: Set `system.status.level` = `100` +2023-12-08T05:50:03Z INFO Updated state #007: Set `system.status.category` = `system.config.parse` +2023-12-08T05:50:03Z INFO Updated state #007: Set `system.status.timestamp` = `2023-12-08T05:50:02Z` +2023-12-08T05:50:03Z INFO Updated state #007: Set `timestamp` = `2023-12-08T05:50:02Z` +2023-12-08T05:50:03Z DEBUG Updated state has last_config 2023-12-08T05:49:54Z (expecting 2023-12-08T05:50:02Z) +2023-12-08T05:50:03Z TRACE received command AHU-1/state/system +2023-12-08T05:50:03Z TRACE received state_system: { +2023-12-08T05:50:03Z TRACE received state_system: "hardware" : { +2023-12-08T05:50:03Z TRACE received state_system: "make" : "BOS", +2023-12-08T05:50:03Z TRACE received state_system: "model" : "pubber" +2023-12-08T05:50:03Z TRACE received state_system: }, +2023-12-08T05:50:03Z TRACE received state_system: "last_config" : "2023-12-08T05:49:54Z", +2023-12-08T05:50:03Z TRACE received state_system: "operation" : { +2023-12-08T05:50:03Z TRACE received state_system: "operational" : true, +2023-12-08T05:50:03Z TRACE received state_system: "last_start" : "2023-12-08T05:49:34Z", +2023-12-08T05:50:03Z TRACE received state_system: "restart_count" : 1, +2023-12-08T05:50:03Z TRACE received state_system: "mode" : "initial" +2023-12-08T05:50:03Z TRACE received state_system: }, +2023-12-08T05:50:03Z TRACE received state_system: "serial_no" : "sequencer-20544", +2023-12-08T05:50:03Z TRACE received state_system: "software" : { +2023-12-08T05:50:03Z TRACE received state_system: "firmware" : "v1" +2023-12-08T05:50:03Z TRACE received state_system: }, +2023-12-08T05:50:03Z TRACE received state_system: "status" : { +2023-12-08T05:50:03Z TRACE received state_system: "message" : "success", +2023-12-08T05:50:03Z TRACE received state_system: "category" : "system.config.parse", +2023-12-08T05:50:03Z TRACE received state_system: "timestamp" : "2023-12-08T05:50:02Z", +2023-12-08T05:50:03Z TRACE received state_system: "level" : 100 +2023-12-08T05:50:03Z TRACE received state_system: }, +2023-12-08T05:50:03Z TRACE received state_system: "timestamp" : "2023-12-08T05:50:02Z", +2023-12-08T05:50:03Z TRACE received state_system: "version" : "1.4.2" +2023-12-08T05:50:03Z TRACE received state_system: } +2023-12-08T05:50:03Z DEBUG Handling device message state_system PS:9793159036195486-0 +2023-12-08T05:50:03Z TRACE Ignoring partial state update +2023-12-08T05:50:03Z TRACE received command AHU-1/state/localnet +2023-12-08T05:50:03Z TRACE received state_localnet: { +2023-12-08T05:50:03Z TRACE received state_localnet: "families" : { +2023-12-08T05:50:03Z TRACE received state_localnet: "ether" : { +2023-12-08T05:50:03Z TRACE received state_localnet: "addr" : "40:1c:83:ca:77:54" +2023-12-08T05:50:03Z TRACE received state_localnet: }, +2023-12-08T05:50:03Z TRACE received state_localnet: "ipv4" : { +2023-12-08T05:50:03Z TRACE received state_localnet: "addr" : "10.132.154.140" +2023-12-08T05:50:03Z TRACE received state_localnet: }, +2023-12-08T05:50:03Z TRACE received state_localnet: "ipv6" : { +2023-12-08T05:50:03Z TRACE received state_localnet: "addr" : "fe80::f9e9:cab2:e374:401d" +2023-12-08T05:50:03Z TRACE received state_localnet: } +2023-12-08T05:50:03Z TRACE received state_localnet: }, +2023-12-08T05:50:03Z TRACE received state_localnet: "timestamp" : "2023-12-08T05:50:02Z", +2023-12-08T05:50:03Z TRACE received state_localnet: "version" : "1.4.2" +2023-12-08T05:50:03Z TRACE received state_localnet: } +2023-12-08T05:50:03Z DEBUG Handling device message state_localnet PS:9793159036195486-1 +2023-12-08T05:50:03Z TRACE Ignoring partial state update +2023-12-08T05:50:03Z TRACE received command AHU-1/state/pointset +2023-12-08T05:50:03Z TRACE received state_pointset: { +2023-12-08T05:50:03Z TRACE received state_pointset: "points" : { +2023-12-08T05:50:03Z TRACE received state_pointset: "filter_alarm_pressure_status" : { }, +2023-12-08T05:50:03Z TRACE received state_pointset: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:03Z TRACE received state_pointset: "units" : "Bars", +2023-12-08T05:50:03Z TRACE received state_pointset: "value_state" : "applied" +2023-12-08T05:50:03Z TRACE received state_pointset: }, +2023-12-08T05:50:03Z TRACE received state_pointset: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:03Z TRACE received state_pointset: "units" : "Degrees-Celsius" +2023-12-08T05:50:03Z TRACE received state_pointset: } +2023-12-08T05:50:03Z TRACE received state_pointset: }, +2023-12-08T05:50:03Z TRACE received state_pointset: "timestamp" : "2023-12-08T05:50:02Z", +2023-12-08T05:50:03Z TRACE received state_pointset: "version" : "1.4.2" +2023-12-08T05:50:03Z TRACE received state_pointset: } +2023-12-08T05:50:03Z DEBUG Handling device message state_pointset PS:9793159036195486-2 +2023-12-08T05:50:03Z TRACE Ignoring partial state update +2023-12-08T05:50:04Z TRACE received command AHU-1/state/update +2023-12-08T05:50:04Z DEBUG received state_update +2023-12-08T05:50:04Z DEBUG Handling update message state_update PS:9790128410620932 +2023-12-08T05:50:04Z DEBUG Updated state after 0s 2023-12-08T05:50:04Z PS:9790128410620932 +2023-12-08T05:50:04Z INFO Updated state #008: Changed 4 fields: +2023-12-08T05:50:04Z INFO Updated state #008: Set `system.last_config` = `2023-12-08T05:50:02Z` +2023-12-08T05:50:04Z INFO Updated state #008: Set `system.status.level` = `300` +2023-12-08T05:50:04Z INFO Updated state #008: Set `system.status.category` = `system.config.apply` +2023-12-08T05:50:04Z INFO Updated state #008: Set `timestamp` = `2023-12-08T05:50:04Z` +2023-12-08T05:50:04Z DEBUG Updated state has last_config 2023-12-08T05:50:02Z (expecting 2023-12-08T05:50:02Z) +2023-12-08T05:50:04Z DEBUG Status level: 300 +2023-12-08T05:50:04Z DEBUG Stage finished waiting for state last_config matches new config timestamp at 24s after 2s +2023-12-08T05:50:04Z TRACE Stage resume waiting for executing test at 24s +2023-12-08T05:50:04Z TRACE stage suspend waiting for executing test at 24s +2023-12-08T05:50:04Z INFO Stage start waiting for state update complete at 24s +2023-12-08T05:50:05Z DEBUG system config extra field null +2023-12-08T05:50:05Z TRACE updated check config_system: false +2023-12-08T05:50:05Z TRACE updated check config_pointset: false +2023-12-08T05:50:05Z TRACE updated check config_gateway: false +2023-12-08T05:50:05Z TRACE updated check config_localnet: false +2023-12-08T05:50:05Z TRACE updated check config_blobset: false +2023-12-08T05:50:05Z TRACE updated check config_discovery: false +2023-12-08T05:50:05Z DEBUG Update config before state update complete: 2023-12-08T05:50:02Z +2023-12-08T05:50:05Z TRACE local local_update: { +2023-12-08T05:50:05Z TRACE local local_update: "timestamp" : "2023-12-08T05:50:02Z", +2023-12-08T05:50:05Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:50:05Z TRACE local local_update: "system" : { +2023-12-08T05:50:05Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:50:05Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:50:05Z TRACE local local_update: "operation" : { +2023-12-08T05:50:05Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:50:05Z TRACE local local_update: }, +2023-12-08T05:50:05Z TRACE local local_update: "testing" : { +2023-12-08T05:50:05Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:50:05Z TRACE local local_update: } +2023-12-08T05:50:05Z TRACE local local_update: }, +2023-12-08T05:50:05Z TRACE local local_update: "localnet" : { +2023-12-08T05:50:05Z TRACE local local_update: "families" : { +2023-12-08T05:50:05Z TRACE local local_update: "ether" : { +2023-12-08T05:50:05Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:50:05Z TRACE local local_update: }, +2023-12-08T05:50:05Z TRACE local local_update: "ipv4" : { +2023-12-08T05:50:05Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:50:05Z TRACE local local_update: } +2023-12-08T05:50:05Z TRACE local local_update: } +2023-12-08T05:50:05Z TRACE local local_update: }, +2023-12-08T05:50:05Z TRACE local local_update: "pointset" : { +2023-12-08T05:50:05Z TRACE local local_update: "points" : { +2023-12-08T05:50:05Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:50:05Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:50:05Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:50:05Z TRACE local local_update: }, +2023-12-08T05:50:05Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:05Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:50:05Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:50:05Z TRACE local local_update: }, +2023-12-08T05:50:05Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:05Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:50:05Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:50:05Z TRACE local local_update: } +2023-12-08T05:50:05Z TRACE local local_update: } +2023-12-08T05:50:05Z TRACE local local_update: } +2023-12-08T05:50:05Z TRACE local local_update: } +2023-12-08T05:50:05Z DEBUG Status level: 300 +2023-12-08T05:50:05Z DEBUG Stage finished waiting for state update complete at 25s after 1s +2023-12-08T05:50:05Z TRACE Stage resume waiting for executing test at 25s +2023-12-08T05:50:06Z DEBUG system config extra field null +2023-12-08T05:50:06Z TRACE updated check config_system: false +2023-12-08T05:50:06Z TRACE updated check config_pointset: false +2023-12-08T05:50:06Z TRACE updated check config_gateway: false +2023-12-08T05:50:06Z TRACE updated check config_localnet: false +2023-12-08T05:50:06Z TRACE updated check config_blobset: false +2023-12-08T05:50:06Z TRACE updated check config_discovery: false +2023-12-08T05:50:06Z DEBUG Forcing config update +2023-12-08T05:50:06Z TRACE updated check config_update: true +2023-12-08T05:50:06Z DEBUG update config_update, configTransaction RC:1702014606556 +2023-12-08T05:50:06Z TRACE local local_update: { +2023-12-08T05:50:06Z TRACE local local_update: "timestamp" : "2023-12-08T05:50:02Z", +2023-12-08T05:50:06Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:50:06Z TRACE local local_update: "system" : { +2023-12-08T05:50:06Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:50:06Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:50:06Z TRACE local local_update: "operation" : { +2023-12-08T05:50:06Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "testing" : { +2023-12-08T05:50:06Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "localnet" : { +2023-12-08T05:50:06Z TRACE local local_update: "families" : { +2023-12-08T05:50:06Z TRACE local local_update: "ether" : { +2023-12-08T05:50:06Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "ipv4" : { +2023-12-08T05:50:06Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "pointset" : { +2023-12-08T05:50:06Z TRACE local local_update: "points" : { +2023-12-08T05:50:06Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:50:06Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:50:06Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:06Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:50:06Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:06Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:50:06Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z DEBUG Update lastConfigUpdate 2023-12-08T05:50:06Z, because trigger another config update +2023-12-08T05:50:06Z TRACE stage suspend waiting for executing test at 26s +2023-12-08T05:50:06Z INFO Stage start waiting for config sync at 26s +2023-12-08T05:50:06Z TRACE received command AHU-1/state/system +2023-12-08T05:50:06Z TRACE received state_system: { +2023-12-08T05:50:06Z TRACE received state_system: "hardware" : { +2023-12-08T05:50:06Z TRACE received state_system: "make" : "BOS", +2023-12-08T05:50:06Z TRACE received state_system: "model" : "pubber" +2023-12-08T05:50:06Z TRACE received state_system: }, +2023-12-08T05:50:06Z TRACE received state_system: "last_config" : "2023-12-08T05:50:02Z", +2023-12-08T05:50:06Z TRACE received state_system: "operation" : { +2023-12-08T05:50:06Z TRACE received state_system: "operational" : true, +2023-12-08T05:50:06Z TRACE received state_system: "last_start" : "2023-12-08T05:49:34Z", +2023-12-08T05:50:06Z TRACE received state_system: "restart_count" : 1, +2023-12-08T05:50:06Z TRACE received state_system: "mode" : "initial" +2023-12-08T05:50:06Z TRACE received state_system: }, +2023-12-08T05:50:06Z TRACE received state_system: "serial_no" : "sequencer-20544", +2023-12-08T05:50:06Z TRACE received state_system: "software" : { +2023-12-08T05:50:06Z TRACE received state_system: "firmware" : "v1" +2023-12-08T05:50:06Z TRACE received state_system: }, +2023-12-08T05:50:06Z TRACE received state_system: "status" : { +2023-12-08T05:50:06Z TRACE received state_system: "message" : "success", +2023-12-08T05:50:06Z TRACE received state_system: "category" : "system.config.apply", +2023-12-08T05:50:06Z TRACE received state_system: "timestamp" : "2023-12-08T05:50:02Z", +2023-12-08T05:50:06Z TRACE received state_system: "level" : 300 +2023-12-08T05:50:06Z TRACE received state_system: }, +2023-12-08T05:50:06Z TRACE received state_system: "timestamp" : "2023-12-08T05:50:04Z", +2023-12-08T05:50:06Z TRACE received state_system: "version" : "1.4.2" +2023-12-08T05:50:06Z TRACE received state_system: } +2023-12-08T05:50:06Z DEBUG Handling device message state_system PS:9790128410620932-0 +2023-12-08T05:50:06Z TRACE Ignoring partial state update +2023-12-08T05:50:06Z TRACE received command AHU-1/state/localnet +2023-12-08T05:50:06Z TRACE received state_localnet: { +2023-12-08T05:50:06Z TRACE received state_localnet: "families" : { +2023-12-08T05:50:06Z TRACE received state_localnet: "ether" : { +2023-12-08T05:50:06Z TRACE received state_localnet: "addr" : "40:1c:83:ca:77:54" +2023-12-08T05:50:06Z TRACE received state_localnet: }, +2023-12-08T05:50:06Z TRACE received state_localnet: "ipv4" : { +2023-12-08T05:50:06Z TRACE received state_localnet: "addr" : "10.132.154.140" +2023-12-08T05:50:06Z TRACE received state_localnet: }, +2023-12-08T05:50:06Z TRACE received state_localnet: "ipv6" : { +2023-12-08T05:50:06Z TRACE received state_localnet: "addr" : "fe80::f9e9:cab2:e374:401d" +2023-12-08T05:50:06Z TRACE received state_localnet: } +2023-12-08T05:50:06Z TRACE received state_localnet: }, +2023-12-08T05:50:06Z TRACE received state_localnet: "timestamp" : "2023-12-08T05:50:04Z", +2023-12-08T05:50:06Z TRACE received state_localnet: "version" : "1.4.2" +2023-12-08T05:50:06Z TRACE received state_localnet: } +2023-12-08T05:50:06Z DEBUG Handling device message state_localnet PS:9790128410620932-1 +2023-12-08T05:50:06Z TRACE Ignoring partial state update +2023-12-08T05:50:06Z TRACE received command AHU-1/state/pointset +2023-12-08T05:50:06Z TRACE received state_pointset: { +2023-12-08T05:50:06Z TRACE received state_pointset: "points" : { +2023-12-08T05:50:06Z TRACE received state_pointset: "filter_alarm_pressure_status" : { }, +2023-12-08T05:50:06Z TRACE received state_pointset: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:06Z TRACE received state_pointset: "units" : "Bars", +2023-12-08T05:50:06Z TRACE received state_pointset: "value_state" : "applied" +2023-12-08T05:50:06Z TRACE received state_pointset: }, +2023-12-08T05:50:06Z TRACE received state_pointset: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:06Z TRACE received state_pointset: "units" : "Degrees-Celsius" +2023-12-08T05:50:06Z TRACE received state_pointset: } +2023-12-08T05:50:06Z TRACE received state_pointset: }, +2023-12-08T05:50:06Z TRACE received state_pointset: "timestamp" : "2023-12-08T05:50:04Z", +2023-12-08T05:50:06Z TRACE received state_pointset: "version" : "1.4.2" +2023-12-08T05:50:06Z TRACE received state_pointset: } +2023-12-08T05:50:06Z DEBUG Handling device message state_pointset PS:9790128410620932-2 +2023-12-08T05:50:06Z TRACE Ignoring partial state update +2023-12-08T05:50:06Z TRACE received command AHU-1/event/pointset +2023-12-08T05:50:06Z TRACE received event_pointset: { +2023-12-08T05:50:06Z TRACE received event_pointset: "points" : { +2023-12-08T05:50:06Z TRACE received event_pointset: "filter_alarm_pressure_status" : { +2023-12-08T05:50:06Z TRACE received event_pointset: "present_value" : false +2023-12-08T05:50:06Z TRACE received event_pointset: }, +2023-12-08T05:50:06Z TRACE received event_pointset: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:06Z TRACE received event_pointset: "present_value" : 98 +2023-12-08T05:50:06Z TRACE received event_pointset: }, +2023-12-08T05:50:06Z TRACE received event_pointset: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:06Z TRACE received event_pointset: "present_value" : 10 +2023-12-08T05:50:06Z TRACE received event_pointset: } +2023-12-08T05:50:06Z TRACE received event_pointset: }, +2023-12-08T05:50:06Z TRACE received event_pointset: "timestamp" : "2023-12-08T05:50:04Z", +2023-12-08T05:50:06Z TRACE received event_pointset: "version" : "1.4.2" +2023-12-08T05:50:06Z TRACE received event_pointset: } +2023-12-08T05:50:06Z DEBUG Handling device message event_pointset PS:9792899842026442 +2023-12-08T05:50:06Z TRACE received command AHU-1/config/update +2023-12-08T05:50:06Z DEBUG received config_update +2023-12-08T05:50:06Z DEBUG Handling update message config_update RC:1702014606556 +2023-12-08T05:50:06Z DEBUG Removed configTransaction RC:1702014606556 +2023-12-08T05:50:06Z DEBUG last_start changed false, last_start 2023-12-08T05:49:34Z +2023-12-08T05:50:06Z DEBUG Updated config 2023-12-08T05:50:06Z RC:1702014606556 +2023-12-08T05:50:06Z INFO Updated config #008: Changed 0 fields. +2023-12-08T05:50:06Z DEBUG Status level: 300 +2023-12-08T05:50:06Z DEBUG Stage finished waiting for config sync at 27s after 0s +2023-12-08T05:50:06Z TRACE Stage resume waiting for executing test at 27s +2023-12-08T05:50:06Z DEBUG Configuration sync took 0s +2023-12-08T05:50:06Z DEBUG wait for config sync pending false +2023-12-08T05:50:06Z DEBUG Update config trigger another config update: 2023-12-08T05:50:06Z +2023-12-08T05:50:06Z TRACE local local_update: { +2023-12-08T05:50:06Z TRACE local local_update: "timestamp" : "2023-12-08T05:50:06Z", +2023-12-08T05:50:06Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:50:06Z TRACE local local_update: "system" : { +2023-12-08T05:50:06Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:50:06Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:50:06Z TRACE local local_update: "operation" : { +2023-12-08T05:50:06Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "testing" : { +2023-12-08T05:50:06Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "localnet" : { +2023-12-08T05:50:06Z TRACE local local_update: "families" : { +2023-12-08T05:50:06Z TRACE local local_update: "ether" : { +2023-12-08T05:50:06Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "ipv4" : { +2023-12-08T05:50:06Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "pointset" : { +2023-12-08T05:50:06Z TRACE local local_update: "points" : { +2023-12-08T05:50:06Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:50:06Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:50:06Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:06Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:50:06Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:50:06Z TRACE local local_update: }, +2023-12-08T05:50:06Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:06Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:50:06Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE local local_update: } +2023-12-08T05:50:06Z TRACE stage suspend waiting for executing test at 27s +2023-12-08T05:50:06Z INFO Stage start waiting for state last_config matches last config timestamp at 27s +2023-12-08T05:50:07Z DEBUG system config extra field null +2023-12-08T05:50:07Z TRACE updated check config_system: false +2023-12-08T05:50:07Z TRACE updated check config_pointset: false +2023-12-08T05:50:07Z TRACE updated check config_gateway: false +2023-12-08T05:50:07Z TRACE updated check config_localnet: false +2023-12-08T05:50:07Z TRACE updated check config_blobset: false +2023-12-08T05:50:07Z TRACE updated check config_discovery: false +2023-12-08T05:50:07Z DEBUG Update config before state last_config matches last config timestamp: 2023-12-08T05:50:06Z +2023-12-08T05:50:07Z TRACE local local_update: { +2023-12-08T05:50:07Z TRACE local local_update: "timestamp" : "2023-12-08T05:50:06Z", +2023-12-08T05:50:07Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:50:07Z TRACE local local_update: "system" : { +2023-12-08T05:50:07Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:50:07Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:50:07Z TRACE local local_update: "operation" : { +2023-12-08T05:50:07Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:50:07Z TRACE local local_update: }, +2023-12-08T05:50:07Z TRACE local local_update: "testing" : { +2023-12-08T05:50:07Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:50:07Z TRACE local local_update: } +2023-12-08T05:50:07Z TRACE local local_update: }, +2023-12-08T05:50:07Z TRACE local local_update: "localnet" : { +2023-12-08T05:50:07Z TRACE local local_update: "families" : { +2023-12-08T05:50:07Z TRACE local local_update: "ether" : { +2023-12-08T05:50:07Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:50:07Z TRACE local local_update: }, +2023-12-08T05:50:07Z TRACE local local_update: "ipv4" : { +2023-12-08T05:50:07Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:50:07Z TRACE local local_update: } +2023-12-08T05:50:07Z TRACE local local_update: } +2023-12-08T05:50:07Z TRACE local local_update: }, +2023-12-08T05:50:07Z TRACE local local_update: "pointset" : { +2023-12-08T05:50:07Z TRACE local local_update: "points" : { +2023-12-08T05:50:07Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:50:07Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:50:07Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:50:07Z TRACE local local_update: }, +2023-12-08T05:50:07Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:07Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:50:07Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:50:07Z TRACE local local_update: }, +2023-12-08T05:50:07Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:07Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:50:07Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:50:07Z TRACE local local_update: } +2023-12-08T05:50:07Z TRACE local local_update: } +2023-12-08T05:50:07Z TRACE local local_update: } +2023-12-08T05:50:07Z TRACE local local_update: } +2023-12-08T05:50:07Z TRACE received command AHU-1/event/system +2023-12-08T05:50:07Z DEBUG received event_system 2023-12-08T05:49:56Z INFO device.log: Update state 2023-12-08T05:49:56Z last_config 2023-12-08T05:49:54Z +2023-12-08T05:50:07Z DEBUG received event_system 2023-12-08T05:50:02Z INFO device.log: Device AHU-1 config handler +2023-12-08T05:50:07Z DEBUG received event_system 2023-12-08T05:50:02Z INFO device.log: Update state 2023-12-08T05:50:02Z last_config 2023-12-08T05:49:54Z +2023-12-08T05:50:07Z DEBUG received event_system 2023-12-08T05:50:02Z INFO device.log: 2023-12-08T05:50:02Z received config 2023-12-08T05:50:02Z +2023-12-08T05:50:07Z DEBUG received event_system 2023-12-08T05:50:02Z NOTICE system.config.apply: success +2023-12-08T05:50:07Z DEBUG received event_system 2023-12-08T05:50:04Z INFO device.log: Update state 2023-12-08T05:50:04Z last_config 2023-12-08T05:50:02Z +2023-12-08T05:50:07Z DEBUG Handling device message event_system PS:9793162560796901 +2023-12-08T05:50:07Z TRACE received command AHU-1/state/update +2023-12-08T05:50:07Z DEBUG received state_update +2023-12-08T05:50:08Z DEBUG Handling update message state_update PS:9793234726380721 +2023-12-08T05:50:08Z DEBUG Updated state after 2s 2023-12-08T05:50:06Z PS:9793234726380721 +2023-12-08T05:50:08Z INFO Updated state #009: Changed 4 fields: +2023-12-08T05:50:08Z INFO Updated state #009: Set `system.status.level` = `100` +2023-12-08T05:50:08Z INFO Updated state #009: Set `system.status.category` = `system.config.parse` +2023-12-08T05:50:08Z INFO Updated state #009: Set `system.status.timestamp` = `2023-12-08T05:50:06Z` +2023-12-08T05:50:08Z INFO Updated state #009: Set `timestamp` = `2023-12-08T05:50:06Z` +2023-12-08T05:50:08Z DEBUG Updated state has last_config 2023-12-08T05:50:02Z (expecting 2023-12-08T05:50:06Z) +2023-12-08T05:50:08Z TRACE received command AHU-1/state/system +2023-12-08T05:50:08Z TRACE received state_system: { +2023-12-08T05:50:08Z TRACE received state_system: "hardware" : { +2023-12-08T05:50:08Z TRACE received state_system: "make" : "BOS", +2023-12-08T05:50:08Z TRACE received state_system: "model" : "pubber" +2023-12-08T05:50:08Z TRACE received state_system: }, +2023-12-08T05:50:08Z TRACE received state_system: "last_config" : "2023-12-08T05:50:02Z", +2023-12-08T05:50:08Z TRACE received state_system: "operation" : { +2023-12-08T05:50:08Z TRACE received state_system: "operational" : true, +2023-12-08T05:50:08Z TRACE received state_system: "last_start" : "2023-12-08T05:49:34Z", +2023-12-08T05:50:08Z TRACE received state_system: "restart_count" : 1, +2023-12-08T05:50:08Z TRACE received state_system: "mode" : "initial" +2023-12-08T05:50:08Z TRACE received state_system: }, +2023-12-08T05:50:08Z TRACE received state_system: "serial_no" : "sequencer-20544", +2023-12-08T05:50:08Z TRACE received state_system: "software" : { +2023-12-08T05:50:08Z TRACE received state_system: "firmware" : "v1" +2023-12-08T05:50:08Z TRACE received state_system: }, +2023-12-08T05:50:08Z TRACE received state_system: "status" : { +2023-12-08T05:50:08Z TRACE received state_system: "message" : "success", +2023-12-08T05:50:08Z TRACE received state_system: "category" : "system.config.parse", +2023-12-08T05:50:08Z TRACE received state_system: "timestamp" : "2023-12-08T05:50:06Z", +2023-12-08T05:50:08Z TRACE received state_system: "level" : 100 +2023-12-08T05:50:08Z TRACE received state_system: }, +2023-12-08T05:50:08Z TRACE received state_system: "timestamp" : "2023-12-08T05:50:06Z", +2023-12-08T05:50:08Z TRACE received state_system: "version" : "1.4.2" +2023-12-08T05:50:08Z TRACE received state_system: } +2023-12-08T05:50:08Z DEBUG Handling device message state_system PS:9793234726380721-0 +2023-12-08T05:50:08Z TRACE Ignoring partial state update +2023-12-08T05:50:08Z TRACE received command AHU-1/state/localnet +2023-12-08T05:50:08Z TRACE received state_localnet: { +2023-12-08T05:50:08Z TRACE received state_localnet: "families" : { +2023-12-08T05:50:08Z TRACE received state_localnet: "ether" : { +2023-12-08T05:50:08Z TRACE received state_localnet: "addr" : "40:1c:83:ca:77:54" +2023-12-08T05:50:08Z TRACE received state_localnet: }, +2023-12-08T05:50:08Z TRACE received state_localnet: "ipv4" : { +2023-12-08T05:50:08Z TRACE received state_localnet: "addr" : "10.132.154.140" +2023-12-08T05:50:08Z TRACE received state_localnet: }, +2023-12-08T05:50:08Z TRACE received state_localnet: "ipv6" : { +2023-12-08T05:50:08Z TRACE received state_localnet: "addr" : "fe80::f9e9:cab2:e374:401d" +2023-12-08T05:50:08Z TRACE received state_localnet: } +2023-12-08T05:50:08Z TRACE received state_localnet: }, +2023-12-08T05:50:08Z TRACE received state_localnet: "timestamp" : "2023-12-08T05:50:06Z", +2023-12-08T05:50:08Z TRACE received state_localnet: "version" : "1.4.2" +2023-12-08T05:50:08Z TRACE received state_localnet: } +2023-12-08T05:50:08Z DEBUG Handling device message state_localnet PS:9793234726380721-1 +2023-12-08T05:50:08Z TRACE Ignoring partial state update +2023-12-08T05:50:08Z TRACE received command AHU-1/state/pointset +2023-12-08T05:50:08Z TRACE received state_pointset: { +2023-12-08T05:50:08Z TRACE received state_pointset: "points" : { +2023-12-08T05:50:08Z TRACE received state_pointset: "filter_alarm_pressure_status" : { }, +2023-12-08T05:50:08Z TRACE received state_pointset: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:08Z TRACE received state_pointset: "units" : "Bars", +2023-12-08T05:50:08Z TRACE received state_pointset: "value_state" : "applied" +2023-12-08T05:50:08Z TRACE received state_pointset: }, +2023-12-08T05:50:08Z TRACE received state_pointset: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:08Z TRACE received state_pointset: "units" : "Degrees-Celsius" +2023-12-08T05:50:08Z TRACE received state_pointset: } +2023-12-08T05:50:08Z TRACE received state_pointset: }, +2023-12-08T05:50:08Z TRACE received state_pointset: "timestamp" : "2023-12-08T05:50:06Z", +2023-12-08T05:50:08Z TRACE received state_pointset: "version" : "1.4.2" +2023-12-08T05:50:08Z TRACE received state_pointset: } +2023-12-08T05:50:08Z DEBUG Handling device message state_pointset PS:9793234726380721-2 +2023-12-08T05:50:08Z TRACE Ignoring partial state update +2023-12-08T05:50:08Z TRACE received command null/null/error +2023-12-08T05:50:09Z TRACE received command AHU-1/state/update +2023-12-08T05:50:09Z DEBUG received state_update +2023-12-08T05:50:09Z DEBUG Handling update message state_update PS:9792646882707524 +2023-12-08T05:50:09Z DEBUG Updated state after 1s 2023-12-08T05:50:08Z PS:9792646882707524 +2023-12-08T05:50:09Z INFO Updated state #010: Changed 4 fields: +2023-12-08T05:50:09Z INFO Updated state #010: Set `system.last_config` = `2023-12-08T05:50:06Z` +2023-12-08T05:50:09Z INFO Updated state #010: Set `system.status.level` = `300` +2023-12-08T05:50:09Z INFO Updated state #010: Set `system.status.category` = `system.config.apply` +2023-12-08T05:50:09Z INFO Updated state #010: Set `timestamp` = `2023-12-08T05:50:08Z` +2023-12-08T05:50:09Z DEBUG Updated state has last_config 2023-12-08T05:50:06Z (expecting 2023-12-08T05:50:06Z) +2023-12-08T05:50:09Z DEBUG Status level: 300 +2023-12-08T05:50:09Z DEBUG Stage finished waiting for state last_config matches last config timestamp at 29s after 2s +2023-12-08T05:50:09Z TRACE Stage resume waiting for executing test at 29s +2023-12-08T05:50:09Z TRACE stage suspend waiting for executing test at 29s +2023-12-08T05:50:09Z INFO Stage start waiting for state update complete at 29s +2023-12-08T05:50:10Z DEBUG system config extra field null +2023-12-08T05:50:10Z TRACE updated check config_system: false +2023-12-08T05:50:10Z TRACE updated check config_pointset: false +2023-12-08T05:50:10Z TRACE updated check config_gateway: false +2023-12-08T05:50:10Z TRACE updated check config_localnet: false +2023-12-08T05:50:10Z TRACE updated check config_blobset: false +2023-12-08T05:50:10Z TRACE updated check config_discovery: false +2023-12-08T05:50:10Z DEBUG Update config before state update complete: 2023-12-08T05:50:06Z +2023-12-08T05:50:10Z TRACE local local_update: { +2023-12-08T05:50:10Z TRACE local local_update: "timestamp" : "2023-12-08T05:50:06Z", +2023-12-08T05:50:10Z TRACE local local_update: "version" : "@@@cloud udmi version###1.4.2-66-gd207962a3", +2023-12-08T05:50:10Z TRACE local local_update: "system" : { +2023-12-08T05:50:10Z TRACE local local_update: "min_loglevel" : 200, +2023-12-08T05:50:10Z TRACE local local_update: "metrics_rate_sec" : 10, +2023-12-08T05:50:10Z TRACE local local_update: "operation" : { +2023-12-08T05:50:10Z TRACE local local_update: "last_start" : "2023-12-08T05:49:34Z" +2023-12-08T05:50:10Z TRACE local local_update: }, +2023-12-08T05:50:10Z TRACE local local_update: "testing" : { +2023-12-08T05:50:10Z TRACE local local_update: "sequence_name" : "system_last_update" +2023-12-08T05:50:10Z TRACE local local_update: } +2023-12-08T05:50:10Z TRACE local local_update: }, +2023-12-08T05:50:10Z TRACE local local_update: "localnet" : { +2023-12-08T05:50:10Z TRACE local local_update: "families" : { +2023-12-08T05:50:10Z TRACE local local_update: "ether" : { +2023-12-08T05:50:10Z TRACE local local_update: "addr" : "00:50:b6:ed:5f:77" +2023-12-08T05:50:10Z TRACE local local_update: }, +2023-12-08T05:50:10Z TRACE local local_update: "ipv4" : { +2023-12-08T05:50:10Z TRACE local local_update: "addr" : "192.168.2.1" +2023-12-08T05:50:10Z TRACE local local_update: } +2023-12-08T05:50:10Z TRACE local local_update: } +2023-12-08T05:50:10Z TRACE local local_update: }, +2023-12-08T05:50:10Z TRACE local local_update: "pointset" : { +2023-12-08T05:50:10Z TRACE local local_update: "points" : { +2023-12-08T05:50:10Z TRACE local local_update: "filter_alarm_pressure_status" : { +2023-12-08T05:50:10Z TRACE local local_update: "ref" : "BV11.present_value", +2023-12-08T05:50:10Z TRACE local local_update: "units" : "No-units" +2023-12-08T05:50:10Z TRACE local local_update: }, +2023-12-08T05:50:10Z TRACE local local_update: "filter_differential_pressure_setpoint" : { +2023-12-08T05:50:10Z TRACE local local_update: "units" : "Bars", +2023-12-08T05:50:10Z TRACE local local_update: "set_value" : 98 +2023-12-08T05:50:10Z TRACE local local_update: }, +2023-12-08T05:50:10Z TRACE local local_update: "filter_differential_pressure_sensor" : { +2023-12-08T05:50:10Z TRACE local local_update: "ref" : "AV12.present_value", +2023-12-08T05:50:10Z TRACE local local_update: "units" : "Degrees-Celsius" +2023-12-08T05:50:10Z TRACE local local_update: } +2023-12-08T05:50:10Z TRACE local local_update: } +2023-12-08T05:50:10Z TRACE local local_update: } +2023-12-08T05:50:10Z TRACE local local_update: } +2023-12-08T05:50:10Z DEBUG Status level: 300 +2023-12-08T05:50:10Z DEBUG Stage finished waiting for state update complete at 30s after 1s +2023-12-08T05:50:10Z TRACE Stage resume waiting for executing test at 30s +2023-12-08T05:50:10Z DEBUG stage done waiting for executing test at 30s +2023-12-08T05:50:10Z DEBUG Removing implicit system capability LAST_CONFIG +2023-12-08T05:50:10Z NOTICE RESULT pass system system_last_update STABLE 5/5 Sequence complete +2023-12-08T05:50:10Z NOTICE Sequence complete +2023-12-08T05:50:10Z INFO waiting 3s for more messages... +2023-12-08T05:50:10Z TRACE stage suspend waiting for executing test at 30s +2023-12-08T05:50:10Z INFO Stage start waiting for minimum test time at 30s +2023-12-08T05:50:10Z TRACE received command AHU-1/state/system +2023-12-08T05:50:10Z DEBUG Handling device message state_system PS:9792646882707524-0 +2023-12-08T05:50:10Z TRACE Ignoring partial state update +2023-12-08T05:50:10Z TRACE received command AHU-1/state/localnet +2023-12-08T05:50:10Z DEBUG Handling device message state_localnet PS:9792646882707524-1 +2023-12-08T05:50:10Z TRACE Ignoring partial state update +2023-12-08T05:50:10Z TRACE received command AHU-1/state/pointset +2023-12-08T05:50:10Z DEBUG Handling device message state_pointset PS:9792646882707524-2 +2023-12-08T05:50:10Z TRACE Ignoring partial state update +2023-12-08T05:50:14Z TRACE received command AHU-1/event/pointset +2023-12-08T05:50:14Z DEBUG Handling device message event_pointset PS:9106514635980066 +2023-12-08T05:50:14Z DEBUG Status level: 300 +2023-12-08T05:50:14Z DEBUG Stage finished waiting for minimum test time at 34s after 4s +2023-12-08T05:50:14Z TRACE Stage resume waiting for executing test at 34s +2023-12-08T05:50:14Z NOTICE SCHEMA pass system system_last_update STABLE event_system No schema violations found +2023-12-08T05:50:14Z NOTICE SCHEMA pass system system_last_update STABLE state_update No schema violations found +2023-12-08T05:50:14Z NOTICE SCHEMA fail system system_last_update STABLE device_state Unexpected device state changes: pointset +2023-12-08T05:50:14Z NOTICE ending test system_last_update after 34s ################################ diff --git a/validator/sequences/system_last_update/state_localnet.attr b/validator/sequences/system_last_update/state_localnet.attr index c54588f507..9b5d228764 100644 --- a/validator/sequences/system_last_update/state_localnet.attr +++ b/validator/sequences/system_last_update/state_localnet.attr @@ -1,9 +1,10 @@ { "deviceId" : "AHU-1", "deviceNumId" : "123456789101112", - "deviceRegistryId" : "ZZ-TRI-FECTA", - "projectId" : "bos-peringknife-dev", + "deviceRegistryId" : "peringknife~ZZ-TRI-FECTA", + "projectId" : "bos-platform-dev", + "transactionId" : "PS:9792646882707524-1", + "publishTime" : "2023-12-08T05:50:09Z", "subFolder" : "localnet", - "subType" : "state", - "transactionId" : "PS:8733158398148185-1" + "subType" : "state" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/state_localnet.json b/validator/sequences/system_last_update/state_localnet.json index 7ffca139ac..b5978f2917 100644 --- a/validator/sequences/system_last_update/state_localnet.json +++ b/validator/sequences/system_last_update/state_localnet.json @@ -4,12 +4,12 @@ "addr" : "40:1c:83:ca:77:54" }, "ipv4" : { - "addr" : "10.0.0.142" + "addr" : "10.132.154.140" }, "ipv6" : { - "addr" : "fe80::134f:c1f5:f225:a441" + "addr" : "fe80::f9e9:cab2:e374:401d" } }, - "timestamp" : "2023-07-28T20:25:19Z", - "version" : "1.4.1" + "timestamp" : "2023-12-08T05:50:06Z", + "version" : "1.4.2" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/state_pointset.attr b/validator/sequences/system_last_update/state_pointset.attr index 7045b85de2..9d1cccd9f7 100644 --- a/validator/sequences/system_last_update/state_pointset.attr +++ b/validator/sequences/system_last_update/state_pointset.attr @@ -1,9 +1,10 @@ { "deviceId" : "AHU-1", "deviceNumId" : "123456789101112", - "deviceRegistryId" : "ZZ-TRI-FECTA", - "projectId" : "bos-peringknife-dev", + "deviceRegistryId" : "peringknife~ZZ-TRI-FECTA", + "projectId" : "bos-platform-dev", + "transactionId" : "PS:9792646882707524-2", + "publishTime" : "2023-12-08T05:50:09Z", "subFolder" : "pointset", - "subType" : "state", - "transactionId" : "PS:8733158398148185-2" + "subType" : "state" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/state_pointset.json b/validator/sequences/system_last_update/state_pointset.json index 837be64571..ea2e40156c 100644 --- a/validator/sequences/system_last_update/state_pointset.json +++ b/validator/sequences/system_last_update/state_pointset.json @@ -9,6 +9,6 @@ "units" : "Degrees-Celsius" } }, - "timestamp" : "2023-07-28T20:25:19Z", - "version" : "1.4.1" + "timestamp" : "2023-12-08T05:50:06Z", + "version" : "1.4.2" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/state_system.attr b/validator/sequences/system_last_update/state_system.attr index cd93fb90ca..8e31339e39 100644 --- a/validator/sequences/system_last_update/state_system.attr +++ b/validator/sequences/system_last_update/state_system.attr @@ -1,9 +1,10 @@ { "deviceId" : "AHU-1", "deviceNumId" : "123456789101112", - "deviceRegistryId" : "ZZ-TRI-FECTA", - "projectId" : "bos-peringknife-dev", + "deviceRegistryId" : "peringknife~ZZ-TRI-FECTA", + "projectId" : "bos-platform-dev", + "transactionId" : "PS:9792646882707524-0", + "publishTime" : "2023-12-08T05:50:09Z", "subFolder" : "system", - "subType" : "state", - "transactionId" : "PS:8733158398148185-0" + "subType" : "state" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/state_system.json b/validator/sequences/system_last_update/state_system.json index c0e045b75f..1a33a3d689 100644 --- a/validator/sequences/system_last_update/state_system.json +++ b/validator/sequences/system_last_update/state_system.json @@ -3,23 +3,23 @@ "make" : "BOS", "model" : "pubber" }, - "last_config" : "2023-07-28T20:25:17Z", + "last_config" : "2023-12-08T05:50:02Z", "operation" : { "operational" : true, - "last_start" : "2023-07-28T20:23:12Z", - "restart_count" : 3, - "mode" : "active" + "last_start" : "2023-12-08T05:49:34Z", + "restart_count" : 1, + "mode" : "initial" }, - "serial_no" : "sequencer-13214", + "serial_no" : "sequencer-20544", "software" : { "firmware" : "v1" }, "status" : { "message" : "success", - "category" : "system.config.apply", - "timestamp" : "2023-07-28T20:25:19Z", - "level" : 300 + "category" : "system.config.parse", + "timestamp" : "2023-12-08T05:50:06Z", + "level" : 100 }, - "timestamp" : "2023-07-28T20:25:19Z", - "version" : "1.4.1" + "timestamp" : "2023-12-08T05:50:06Z", + "version" : "1.4.2" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/state_update.attr b/validator/sequences/system_last_update/state_update.attr index 94d2057201..4f0f48d95e 100644 --- a/validator/sequences/system_last_update/state_update.attr +++ b/validator/sequences/system_last_update/state_update.attr @@ -1,9 +1,10 @@ { "deviceId" : "AHU-1", "deviceNumId" : "123456789101112", - "deviceRegistryId" : "ZZ-TRI-FECTA", - "projectId" : "bos-peringknife-dev", + "deviceRegistryId" : "peringknife~ZZ-TRI-FECTA", + "projectId" : "bos-platform-dev", + "transactionId" : "PS:9792646882707524", + "publishTime" : "2023-12-08T05:50:09Z", "subFolder" : "update", - "subType" : "state", - "transactionId" : "PS:8733158398148185" + "subType" : "state" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/state_update.json b/validator/sequences/system_last_update/state_update.json index 3269b50b28..1ad1361a39 100644 --- a/validator/sequences/system_last_update/state_update.json +++ b/validator/sequences/system_last_update/state_update.json @@ -5,10 +5,10 @@ "addr" : "40:1c:83:ca:77:54" }, "ipv4" : { - "addr" : "10.0.0.142" + "addr" : "10.132.154.140" }, "ipv6" : { - "addr" : "fe80::134f:c1f5:f225:a441" + "addr" : "fe80::f9e9:cab2:e374:401d" } } }, @@ -25,14 +25,14 @@ } }, "system" : { - "last_config" : "2023-07-28T20:25:20Z", + "last_config" : "2023-12-08T05:50:06Z", "operation" : { "operational" : true, - "last_start" : "2023-07-28T20:23:12Z", - "restart_count" : 3, - "mode" : "active" + "last_start" : "2023-12-08T05:49:34Z", + "restart_count" : 1, + "mode" : "initial" }, - "serial_no" : "sequencer-13214", + "serial_no" : "sequencer-20544", "hardware" : { "make" : "BOS", "model" : "pubber" @@ -43,10 +43,10 @@ "status" : { "message" : "success", "category" : "system.config.apply", - "timestamp" : "2023-07-28T20:25:20Z", + "timestamp" : "2023-12-08T05:50:06Z", "level" : 300 } }, - "timestamp" : "2023-07-28T20:25:21Z", - "version" : "1.4.1" + "timestamp" : "2023-12-08T05:50:08Z", + "version" : "1.4.2" } \ No newline at end of file diff --git a/validator/sequences/system_last_update/state_validation.attr b/validator/sequences/system_last_update/state_validation.attr deleted file mode 100644 index f7952913a8..0000000000 --- a/validator/sequences/system_last_update/state_validation.attr +++ /dev/null @@ -1,9 +0,0 @@ -{ - "deviceId" : "AHU-1", - "deviceNumId" : "123456789101112", - "deviceRegistryId" : "ZZ-TRI-FECTA", - "projectId" : "bos-peringknife-dev", - "subFolder" : "validation", - "subType" : "state", - "transactionId" : "1678207112477" -} \ No newline at end of file diff --git a/validator/sequences/system_last_update/state_validation.json b/validator/sequences/system_last_update/state_validation.json deleted file mode 100644 index bac25e172d..0000000000 --- a/validator/sequences/system_last_update/state_validation.json +++ /dev/null @@ -1,147 +0,0 @@ -{ - "features" : { - "endpoint" : { - "sequences" : { - "endpoint_connection_retry" : { - "summary" : "Check repeated endpoint with same information gets retried.", - "stage" : "alpha", - "result" : "pass", - "status" : { - "message" : "Sequence complete", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:35:58Z", - "level" : 400 - } - }, - "endpoint_connection_bad_hash" : { - "summary" : "Failed connection because of bad hash.", - "stage" : "alpha", - "result" : "pass", - "status" : { - "message" : "Sequence complete", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:36:48Z", - "level" : 400 - } - }, - "endpoint_connection_success_reconnect" : { - "summary" : "Check a successful reconnect to the same endpoint.", - "stage" : "alpha", - "result" : "pass", - "status" : { - "message" : "Sequence complete", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:36:28Z", - "level" : 400 - } - }, - "endpoint_connection_success_alternate" : { - "summary" : "Check connection to an alternate project.", - "stage" : "alpha", - "result" : "pass", - "status" : { - "message" : "Sequence complete", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:37:38Z", - "level" : 400 - } - }, - "endpoint_connection_error" : { - "summary" : "Push endpoint config message to device that results in a connection error.", - "stage" : "alpha", - "result" : "pass", - "status" : { - "message" : "Sequence complete", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:34:36Z", - "level" : 400 - } - } - } - }, - "system" : { - "sequences" : { - "system_last_update" : { - "summary" : "Check that last_update state is correctly set in response to a config update.", - "stage" : "stable", - "result" : "start", - "status" : { - "message" : "Starting test", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:38:32Z", - "level" : 200 - } - }, - "valid_serial_no" : { - "stage" : "alpha", - "result" : "pass", - "status" : { - "message" : "Sequence complete", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:38:32Z", - "level" : 400 - } - } - } - }, - "writeback" : { - "sequences" : { - "writeback_failure" : { - "stage" : "alpha", - "result" : "pass", - "status" : { - "message" : "Sequence complete", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:33:32Z", - "level" : 400 - } - }, - "writeback_success" : { - "summary" : "Implements UDMI writeback and can successfully writeback to a point", - "stage" : "alpha", - "result" : "pass", - "status" : { - "message" : "Sequence complete", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:32:54Z", - "level" : 400 - } - }, - "writeback_invalid" : { - "stage" : "alpha", - "result" : "pass", - "status" : { - "message" : "Sequence complete", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:33:17Z", - "level" : 400 - } - } - } - }, - "system.mode" : { - "sequences" : { - "system_mode_restart" : { - "summary" : "Restart and connect to same endpoint and expect it returns.", - "stage" : "alpha", - "result" : "pass", - "status" : { - "message" : "Sequence complete", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:38:21Z", - "level" : 400 - } - } - } - } - }, - "start_time" : "2023-03-07T16:32:07Z", - "status" : { - "message" : "Starting sequence run for device AHU-1", - "category" : "validation.feature.sequence", - "timestamp" : "2023-03-07T16:32:07Z", - "level" : 300 - }, - "timestamp" : "2023-03-07T16:38:32Z", - "version" : "1.4.0-221-g632b879b" -} \ No newline at end of file diff --git a/validator/sequences/system_last_update/system.log b/validator/sequences/system_last_update/system.log index ae9dc6bd68..bd3caeff24 100644 --- a/validator/sequences/system_last_update/system.log +++ b/validator/sequences/system_last_update/system.log @@ -1,18 +1,38 @@ -2023-07-28T20:25:24Z NOTICE Sequence complete -2023-07-28T20:25:17Z DEBUG success -2023-07-28T20:25:17Z DEBUG State update defer -13926ms -2023-07-28T20:25:17Z INFO update state 2023-07-28T20:25:17Z last_config 2023-07-28T20:24:59Z -2023-07-28T20:25:17Z DEBUG success -2023-07-28T20:25:17Z INFO Config handler -2023-07-28T20:25:17Z DEBUG State update (extra_config) -2023-07-28T20:25:17Z DEBUG Config update (system_last_update) -2023-07-28T20:25:17Z INFO 2023-07-28T20:25:17Z received config 2023-07-28T20:25:17Z -2023-07-28T20:25:17Z NOTICE success -2023-07-28T20:25:19Z INFO Config handler -2023-07-28T20:25:19Z INFO 2023-07-28T20:25:19Z received config 2023-07-28T20:25:17Z -2023-07-28T20:25:19Z NOTICE success -2023-07-28T20:25:19Z INFO update state 2023-07-28T20:25:19Z last_config 2023-07-28T20:25:17Z -2023-07-28T20:25:20Z INFO Config handler -2023-07-28T20:25:20Z INFO 2023-07-28T20:25:20Z received config 2023-07-28T20:25:20Z -2023-07-28T20:25:20Z NOTICE success -2023-07-28T20:25:21Z INFO update state 2023-07-28T20:25:21Z last_config 2023-07-28T20:25:20Z +2023-12-08T05:49:35Z WARNING Start waiting 10s for config latch for AHU-1 +2023-12-08T05:49:35Z WARNING Starting Pubber sender with delay 10s +2023-12-08T05:49:35Z WARNING Dropping state update until config received... +2023-12-08T05:49:35Z WARNING Received config for config latch AHU-1 +2023-12-08T05:49:35Z NOTICE success +2023-12-08T05:49:38Z NOTICE success +2023-12-08T05:49:50Z WARNING Terminating PointsetManager sender +2023-12-08T05:49:50Z WARNING Starting PointsetManager sender with delay 0s +2023-12-08T05:49:50Z NOTICE success +2023-12-08T05:49:50Z INFO Device AHU-1 config handler +2023-12-08T05:49:50Z INFO 2023-12-08T05:49:50Z received config 2023-12-08T05:49:50Z +2023-12-08T05:49:50Z WARNING Starting PointsetManager sender with delay 0s +2023-12-08T05:49:50Z NOTICE success +2023-12-08T05:49:51Z INFO Device AHU-1 config handler +2023-12-08T05:49:51Z INFO 2023-12-08T05:49:51Z received config 2023-12-08T05:49:51Z +2023-12-08T05:49:51Z WARNING Starting PointsetManager sender with delay 0s +2023-12-08T05:49:51Z NOTICE success +2023-12-08T05:49:52Z INFO Update state 2023-12-08T05:49:52Z last_config 2023-12-08T05:49:51Z +2023-12-08T05:49:53Z INFO Device AHU-1 config handler +2023-12-08T05:49:53Z INFO 2023-12-08T05:49:53Z received config 2023-12-08T05:49:53Z +2023-12-08T05:49:53Z WARNING Starting PointsetManager sender with delay 0s +2023-12-08T05:49:53Z NOTICE success +2023-12-08T05:49:54Z INFO Device AHU-1 config handler +2023-12-08T05:49:54Z INFO 2023-12-08T05:49:54Z received config 2023-12-08T05:49:54Z +2023-12-08T05:49:54Z WARNING Starting PointsetManager sender with delay 0s +2023-12-08T05:49:54Z NOTICE success +2023-12-08T05:49:54Z INFO Update state 2023-12-08T05:49:54Z last_config 2023-12-08T05:49:54Z +2023-12-08T05:49:54Z INFO Device AHU-1 config handler +2023-12-08T05:49:54Z INFO 2023-12-08T05:49:54Z received config 2023-12-08T05:49:54Z +2023-12-08T05:49:54Z WARNING Starting PointsetManager sender with delay 10s +2023-12-08T05:49:54Z NOTICE success +2023-12-08T05:49:56Z INFO Update state 2023-12-08T05:49:56Z last_config 2023-12-08T05:49:54Z +2023-12-08T05:50:02Z INFO Device AHU-1 config handler +2023-12-08T05:50:02Z INFO Update state 2023-12-08T05:50:02Z last_config 2023-12-08T05:49:54Z +2023-12-08T05:50:02Z INFO 2023-12-08T05:50:02Z received config 2023-12-08T05:50:02Z +2023-12-08T05:50:02Z NOTICE success +2023-12-08T05:50:04Z INFO Update state 2023-12-08T05:50:04Z last_config 2023-12-08T05:50:02Z +2023-12-08T05:50:10Z NOTICE Sequence complete diff --git a/validator/src/main/java/com/google/daq/mqtt/sequencer/SequenceBase.java b/validator/src/main/java/com/google/daq/mqtt/sequencer/SequenceBase.java index d103453597..24bf50e754 100644 --- a/validator/src/main/java/com/google/daq/mqtt/sequencer/SequenceBase.java +++ b/validator/src/main/java/com/google/daq/mqtt/sequencer/SequenceBase.java @@ -1970,6 +1970,10 @@ protected String lastConfigUpdatedString() { return lastConfigUpdated() ? null : ""; } + protected boolean deviceStateComplete() { + return deviceState.system != null && deviceState.pointset != null; + } + protected boolean lastConfigUpdated() { Date expectedConfig = deviceConfig.timestamp; Date lastConfig = deviceState.system.last_config; diff --git a/validator/src/main/java/com/google/daq/mqtt/sequencer/sequences/ConfigSequences.java b/validator/src/main/java/com/google/daq/mqtt/sequencer/sequences/ConfigSequences.java index e38c963b76..15263eeded 100644 --- a/validator/src/main/java/com/google/daq/mqtt/sequencer/sequences/ConfigSequences.java +++ b/validator/src/main/java/com/google/daq/mqtt/sequencer/sequences/ConfigSequences.java @@ -55,8 +55,13 @@ public class ConfigSequences extends SequenceBase { @ValidateSchema(SubFolder.SYSTEM) public void system_last_update() { untilTrue("state last_config matches first config timestamp", this::lastConfigUpdated); + untilTrue("state update complete", this::deviceStateComplete); forceConfigUpdate("trigger another config update"); untilTrue("state last_config matches new config timestamp", this::lastConfigUpdated); + untilTrue("state update complete", this::deviceStateComplete); + forceConfigUpdate("trigger another config update"); + untilTrue("state last_config matches last config timestamp", this::lastConfigUpdated); + untilTrue("state update complete", this::deviceStateComplete); } @Test