rsmp-nordic / rsmp_validator

Official RSMP Nordic automated test tool, build with Ruby and Rpec.
https://rsmp-nordic.github.io/rsmp_validator/
MIT License
4 stars 2 forks source link

ITC-3 failures on core 3.1.3 #438

Closed emiltin closed 2 months ago

emiltin commented 2 months ago

We tried testing the ITC-3 on all the core version that is says it supports.

We see these failures on 3.1.3:

rspec ./spec/site/tlc/alarm_spec.rb:29 # Site::Traffic Light Controller Alarm Alarm A0302 is raised when input is activated
rspec ./spec/site/tlc/alarm_spec.rb:58 # Site::Traffic Light Controller Alarm A0302 can be acknowledged
rspec ./spec/site/tlc/alarm_spec.rb:109 # Site::Traffic Light Controller Alarm A0302 can be suspended and resumed
rspec ./spec/site/tlc/clock_spec.rb:220 # Site::Traffic Light Controller Clock is used for alarm timestamp

We can open individual issues for each as needed.

Test run: https://github.com/rsmp-nordic/rsmp_validator/actions/runs/10808667811/job/29982139513

sveitech commented 2 months ago

We are having trouble debugging this issue. I can re-create the issue locally, but it seems like the validator is ignoring or discarding some messages.

When running core 3.1.5, I can see that our side is correctly sending out an Alarm message stating that the alarm has been deactivated:

THis is what our client is sending:

[{    "mType": "rSMsg",    "type": "Alarm",    "mId": "710757d0-5015-4d1a-8244-79da1a9a9e69",    "ntsOId": "",    "xNId": "",    "cId": "AA+BBCCC=DDDDL002",    "aCId": "A0302",    "xACId": "Control Block 2: Det Logic 2 (<DET LOGIC NAME>) has a short-circuit failure at inp.",    "xNACId": "",    "aSp": "Issue",    "ack": "notAcknowledged",    "aS": "inActive",    "sS": "notSuspended",    "aTs": "2024-09-11T12:29:25.449Z",    "cat": "D",    "pri": "3",    "rvs": []}]

And this is the validator receiving it:

    2024-09-11T12:29:25.451Z  56060  AA+BBCCC=DDD         AA+BBCCC=DDDDL002    7107  Received Alarm, A0302 Issue [notAcknowledged,inActive,notSuspended]  {
    "mType": "rSMsg",
    "type": "Alarm",
    "mId": "710757d0-5015-4d1a-8244-79da1a9a9e69",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDDL002",
    "aCId": "A0302",
    "xACId": "Control Block 2: Det Logic 2 (<DET LOGIC NAME>) has a short-circuit failure at inp.",
    "xNACId": "",
    "aSp": "Issue",
    "ack": "notAcknowledged",
    "aS": "inActive",
    "sS": "notSuspended",
    "aTs": "2024-09-11T12:29:25.449Z",
    "cat": "D",
    "pri": "3",
    "rvs": []

Notice the same mId.

Now this is what happens when I use core 3.1.2:

This is what we send:

[{    "mType": "rSMsg",    "type": "Alarm",    "mId": "39386575-1cf1-4fd8-9801-15be235ba861",    "ntsOId": "",    "xNId": "",    "cId": "AA+BBCCC=DDDDL002",    "aCId": "A0302",    "xACId": "Control Block 2: Det Logic 2 (<DET LOGIC NAME>) has a short-circuit failure at inp.",    "xNACId": "",    "aSp": "Issue",    "ack": "notAcknowledged",    "aS": "inactive",    "sS": "notSuspended",    "aTs": "2024-09-11T12:31:16.942Z",    "cat": "D",    "pri": "3",    "rvs": []}]

But this alarm never shows up in the validator output. Is this due to the schema issues discussed in #437 ? Are the alarms being discarded if they are not schema-matched?

cd /home/daniel/projects/daniel/rsmpd/tests/rsmp_validator/../../modules/rsmp_validator; \
SITE_CONFIG=/home/daniel/projects/daniel/rsmpd/tests/rsmp_validator/swarco_itc3.yaml \
bundle exec rspec spec/site \
    --pattern spec/site/tlc/alarm_spec.rb \
    --format Validator::Details
/home/daniel/projects/daniel/rsmpd/modules/rsmp_validator/vendor/bundle/ruby/3.2.0/gems/io-event-1.6.5/lib/io/event/support.rb:27: warning: IO::Buffer is experimental and both the Ruby and C interface may change in the future!
  Run options: exclude {:sxl=>[unless relevant for 1.0.13], :core=>[unless relevant for 3.1.2]}

    > Initial site connection check
    > Waiting for site to connect
    2024-09-11T12:31:10.981Z  -      -                    -                    -     Starting supervisor on port 12111
    2024-09-11T12:31:16.366Z  35670  -                    -                    -     Site connected from 127.0.0.1:35670
    2024-09-11T12:31:16.366Z  35670  AA+BBCCC=DDD         -                    -     Using site settings for guest
    2024-09-11T12:31:16.367Z  -      -                    -                    -     Validating using core version 3.1.2
    2024-09-11T12:31:16.370Z  35670  AA+BBCCC=DDD         -                    436c  Received Version message for site AA+BBCCC=DDD  {
    "mType": "rSMsg",
    "type": "Version",
    "mId": "436c6125-628c-495d-b33a-b105721da317",
    "siteId": [
        {
            "sId": "AA+BBCCC=DDD"
        }
    ],
    "RSMP": [
        {
            "vers": "3.1.2"
        },
        {
            "vers": "3.1.3"
        },
        {
            "vers": "3.1.4"
        },
        {
            "vers": "3.1.5"
        },
        {
            "vers": "3.2.0"
        }
    ],
    "SXL": "1.0.15"
}
    2024-09-11T12:31:16.371Z  35670  AA+BBCCC=DDD         -                    -     Starting timer with interval 1 seconds
    > Waiting for handskake to complete
    2024-09-11T12:31:16.372Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for Version 436c  {"mType":"rSMsg","type":"MessageAck","oMId":"436c6125-628c-495d-b33a-b105721da317"}
    2024-09-11T12:31:16.373Z  35670  AA+BBCCC=DDD         -                    5f79  Sent Version  {"mType":"rSMsg","type":"Version","RSMP":[{"vers":"3.1.2"}],"siteId":[{"sId":"AA+BBCCC=DDD"}],"SXL":"1.0.15","mId":"5f79395f-4902-446b-8d9e-b66158737cdc"}
    2024-09-11T12:31:16.373Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for Version 5f79  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "5f79395f-4902-446b-8d9e-b66158737cdc"
}
    2024-09-11T12:31:16.375Z  35670  AA+BBCCC=DDD         -                    2443  Received Watchdog  {
    "mType": "rSMsg",
    "type": "Watchdog",
    "mId": "2443a858-2d1d-4ae9-a763-845e75a2a8d4",
    "wTs": "2024-09-11T12:31:16.373Z"
}
    2024-09-11T12:31:16.375Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for Watchdog 2443  {"mType":"rSMsg","type":"MessageAck","oMId":"2443a858-2d1d-4ae9-a763-845e75a2a8d4"}
    2024-09-11T12:31:16.376Z  35670  AA+BBCCC=DDD         -                    e8f8  Sent Watchdog  {"mType":"rSMsg","type":"Watchdog","wTs":"2024-09-11T12:31:16.375Z","mId":"e8f8c266-9790-4312-a201-2a1b76ad8a1b"}
    2024-09-11T12:31:16.378Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for Watchdog e8f8  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "e8f8c266-9790-4312-a201-2a1b76ad8a1b"
}
    2024-09-11T12:31:16.378Z  35670  AA+BBCCC=DDD         -                    -     Connection to site AA+BBCCC=DDD established, using core 3.1.2, tlc 1.0.15
    2024-09-11T12:31:16.379Z  35670  AA+BBCCC=DDD         -                    -     Starting watchdog with interval 20 seconds
    2024-09-11T12:31:16.395Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    189a  Received Alarm, A0002 Issue [notAcknowledged,active,notSuspended]  {
    "mType": "rSMsg",
    "type": "Alarm",
    "mId": "189a769b-54e4-4eb4-b1f3-24542ca88611",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "aCId": "A0002",
    "xACId": "Traffic Algo: Det Logic 12 (<DET LOGIC NAME>) has an OFF failure.",
    "xNACId": "",
    "aSp": "Issue",
    "ack": "notAcknowledged",
    "aS": "active",
    "sS": "notSuspended",
    "aTs": "2024-09-11T12:31:16.220Z",
    "cat": "D",
    "pri": "3",
    "rvs": []
}
    2024-09-11T12:31:16.395Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for Alarm 189a  {"mType":"rSMsg","type":"MessageAck","oMId":"189a769b-54e4-4eb4-b1f3-24542ca88611"}
    2024-09-11T12:31:16.397Z  35670  AA+BBCCC=DDD         -                    -     Added component AA+BBCCC=DDDDL004 with the inferred type ComponentProxy
    2024-09-11T12:31:16.397Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDDL004    0836  Received Alarm, A0302 Issue [notAcknowledged,active,notSuspended]  {
    "mType": "rSMsg",
    "type": "Alarm",
    "mId": "0836c40e-0290-4d82-ba95-f87408138641",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDDL004",
    "aCId": "A0302",
    "xACId": "Traffic Algo: Det Logic 4 (<DET LOGIC NAME>) has an OFF failure.",
    "xNACId": "",
    "aSp": "Issue",
    "ack": "notAcknowledged",
    "aS": "active",
    "sS": "notSuspended",
    "aTs": "2024-09-11T12:31:16.220Z",
    "cat": "D",
    "pri": "3",
    "rvs": [
        {
            "n": "detector",
            "v": "4"
        },
        {
            "n": "errormode",
            "v": "off"
        },
        {
            "n": "logicerror",
            "v": ""
        },
        {
            "n": "manual",
            "v": "False"
        },
        {
            "n": "type",
            "v": "loop"
        }
    ]
}
    2024-09-11T12:31:16.398Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for Alarm 0836  {"mType":"rSMsg","type":"MessageAck","oMId":"0836c40e-0290-4d82-ba95-f87408138641"}
    2024-09-11T12:31:16.399Z  35670  AA+BBCCC=DDD         -                    -     Added component AA+BBCCC=DDDDL005 with the inferred type ComponentProxy
    2024-09-11T12:31:16.400Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDDL005    1e7f  Received Alarm, A0302 Issue [notAcknowledged,active,notSuspended]  {
    "mType": "rSMsg",
    "type": "Alarm",
    "mId": "1e7ff521-7c3d-4d3d-b37b-8ddc6ceaf087",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDDL005",
    "aCId": "A0302",
    "xACId": "Traffic Algo: Det Logic 5 (<DET LOGIC NAME>) has an OFF failure.",
    "xNACId": "",
    "aSp": "Issue",
    "ack": "notAcknowledged",
    "aS": "active",
    "sS": "notSuspended",
    "aTs": "2024-09-11T12:31:16.220Z",
    "cat": "D",
    "pri": "3",
    "rvs": [
        {
            "n": "detector",
            "v": "5"
        },
        {
            "n": "errormode",
            "v": "off"
        },
        {
            "n": "logicerror",
            "v": ""
        },
        {
            "n": "manual",
            "v": "False"
        },
        {
            "n": "type",
            "v": "loop"
        }
    ]
}
    2024-09-11T12:31:16.400Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for Alarm 1e7f  {"mType":"rSMsg","type":"MessageAck","oMId":"1e7ff521-7c3d-4d3d-b37b-8ddc6ceaf087"}
    2024-09-11T12:31:16.402Z  35670  AA+BBCCC=DDD         -                    -     Added component AA+BBCCC=DDDDL006 with the inferred type ComponentProxy
    2024-09-11T12:31:16.402Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDDL006    2222  Received Alarm, A0302 Issue [notAcknowledged,active,notSuspended]  {
    "mType": "rSMsg",
    "type": "Alarm",
    "mId": "22221a70-4516-4de9-b006-c83e614fd4a1",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDDL006",
    "aCId": "A0302",
    "xACId": "Traffic Algo: Det Logic 6 (<DET LOGIC NAME>) has an OFF failure.",
    "xNACId": "",
    "aSp": "Issue",
    "ack": "notAcknowledged",
    "aS": "active",
    "sS": "notSuspended",
    "aTs": "2024-09-11T12:31:16.220Z",
    "cat": "D",
    "pri": "3",
    "rvs": [
        {
            "n": "detector",
            "v": "6"
        },
        {
            "n": "errormode",
            "v": "off"
        },
        {
            "n": "logicerror",
            "v": ""
        },
        {
            "n": "manual",
            "v": "False"
        },
        {
            "n": "type",
            "v": "loop"
        }
    ]
}
    2024-09-11T12:31:16.403Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for Alarm 2222  {"mType":"rSMsg","type":"MessageAck","oMId":"22221a70-4516-4de9-b006-c83e614fd4a1"}
    2024-09-11T12:31:16.404Z  35670  AA+BBCCC=DDD         -                    -     Added component AA+BBCCC=DDDDL007 with the inferred type ComponentProxy
    2024-09-11T12:31:16.404Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDDL007    419a  Received Alarm, A0302 Issue [notAcknowledged,active,notSuspended]  {
    "mType": "rSMsg",
    "type": "Alarm",
    "mId": "419ac241-5577-48e1-840b-adfc05072367",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDDL007",
    "aCId": "A0302",
    "xACId": "Traffic Algo: Det Logic 7 (<DET LOGIC NAME>) has an OFF failure.",
    "xNACId": "",
    "aSp": "Issue",
    "ack": "notAcknowledged",
    "aS": "active",
    "sS": "notSuspended",
    "aTs": "2024-09-11T12:31:16.220Z",
    "cat": "D",
    "pri": "3",
    "rvs": [
        {
            "n": "detector",
            "v": "7"
        },
        {
            "n": "errormode",
            "v": "off"
        },
        {
            "n": "logicerror",
            "v": ""
        },
        {
            "n": "manual",
            "v": "False"
        },
        {
            "n": "type",
            "v": "loop"
        }
    ]
}
    2024-09-11T12:31:16.405Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for Alarm 419a  {"mType":"rSMsg","type":"MessageAck","oMId":"419ac241-5577-48e1-840b-adfc05072367"}
    2024-09-11T12:31:16.406Z  35670  AA+BBCCC=DDD         -                    -     Added component AA+BBCCC=DDDDL008 with the inferred type ComponentProxy
    2024-09-11T12:31:16.407Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDDL008    3804  Received Alarm, A0302 Issue [notAcknowledged,active,notSuspended]  {
    "mType": "rSMsg",
    "type": "Alarm",
    "mId": "3804823e-7746-4f01-b724-c67e5c482a97",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDDL008",
    "aCId": "A0302",
    "xACId": "Traffic Algo: Det Logic 8 (<DET LOGIC NAME>) has an OFF failure.",
    "xNACId": "",
    "aSp": "Issue",
    "ack": "notAcknowledged",
    "aS": "active",
    "sS": "notSuspended",
    "aTs": "2024-09-11T12:31:16.220Z",
    "cat": "D",
    "pri": "3",
    "rvs": [
        {
            "n": "detector",
            "v": "8"
        },
        {
            "n": "errormode",
            "v": "off"
        },
        {
            "n": "logicerror",
            "v": ""
        },
        {
            "n": "manual",
            "v": "False"
        },
        {
            "n": "type",
            "v": "loop"
        }
    ]
}
    2024-09-11T12:31:16.407Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for Alarm 3804  {"mType":"rSMsg","type":"MessageAck","oMId":"3804823e-7746-4f01-b724-c67e5c482a97"}
    2024-09-11T12:31:16.409Z  35670  AA+BBCCC=DDD         -                    -     Added component AA+BBCCC=DDDDL009 with the inferred type ComponentProxy
    2024-09-11T12:31:16.409Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDDL009    2463  Received Alarm, A0302 Issue [notAcknowledged,active,notSuspended]  {
    "mType": "rSMsg",
    "type": "Alarm",
    "mId": "2463b9ea-5e88-4adc-91ea-d36b2d517796",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDDL009",
    "aCId": "A0302",
    "xACId": "Traffic Algo: Det Logic 9 (<DET LOGIC NAME>) has an OFF failure.",
    "xNACId": "",
    "aSp": "Issue",
    "ack": "notAcknowledged",
    "aS": "active",
    "sS": "notSuspended",
    "aTs": "2024-09-11T12:31:16.220Z",
    "cat": "D",
    "pri": "3",
    "rvs": [
        {
            "n": "detector",
            "v": "9"
        },
        {
            "n": "errormode",
            "v": "off"
        },
        {
            "n": "logicerror",
            "v": ""
        },
        {
            "n": "manual",
            "v": "False"
        },
        {
            "n": "type",
            "v": "loop"
        }
    ]
}
    2024-09-11T12:31:16.409Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for Alarm 2463  {"mType":"rSMsg","type":"MessageAck","oMId":"2463b9ea-5e88-4adc-91ea-d36b2d517796"}
    2024-09-11T12:31:16.411Z  35670  AA+BBCCC=DDD         -                    -     Added component AA+BBCCC=DDDDL010 with the inferred type ComponentProxy
    2024-09-11T12:31:16.411Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDDL010    580b  Received Alarm, A0302 Issue [notAcknowledged,active,notSuspended]  {
    "mType": "rSMsg",
    "type": "Alarm",
    "mId": "580bd78f-153e-4438-b855-585c70a64e2a",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDDL010",
    "aCId": "A0302",
    "xACId": "Traffic Algo: Det Logic 10 (<DET LOGIC NAME>) has an OFF failure.",
    "xNACId": "",
    "aSp": "Issue",
    "ack": "notAcknowledged",
    "aS": "active",
    "sS": "notSuspended",
    "aTs": "2024-09-11T12:31:16.220Z",
    "cat": "D",
    "pri": "3",
    "rvs": [
        {
            "n": "detector",
            "v": "10"
        },
        {
            "n": "errormode",
            "v": "off"
        },
        {
            "n": "logicerror",
            "v": ""
        },
        {
            "n": "manual",
            "v": "False"
        },
        {
            "n": "type",
            "v": "loop"
        }
    ]
}
    2024-09-11T12:31:16.411Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for Alarm 580b  {"mType":"rSMsg","type":"MessageAck","oMId":"580bd78f-153e-4438-b855-585c70a64e2a"}
    > Ready
    

Site::Traffic Light Controller Alarm Alarm A0302 is raised when input is activated
    > Force input 2 to False
    2024-09-11T12:31:16.412Z  35670  AA+BBCCC=DDD         -                    -     Collect 1338: Waiting for CommandResponse matching {"M0019"=>{"setInput"=>{"securityCode"=>"default", "status"=>"True", "input"=>"2", "inputValue"=>"False"}}}
    2024-09-11T12:31:16.418Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    df0f  Sent CommandRequest  {"mType":"rSMsg","type":"CommandRequest","cId":"AA+BBCCC=DDDEEFFF","arg":[{"cCI":"M0019","cO":"setInput","n":"securityCode","v":"default"},{"cCI":"M0019","cO":"setInput","n":"status","v":"True"},{"cCI":"M0019","cO":"setInput","n":"input","v":"2"},{"cCI":"M0019","cO":"setInput","n":"inputValue","v":"False"}],"mId":"df0fc9ea-4db9-45f5-bda2-3d77bb6ef7d5","ntsOId":"","xNId":""}
    2024-09-11T12:31:16.419Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for CommandRequest df0f  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "df0fc9ea-4db9-45f5-bda2-3d77bb6ef7d5"
}
    2024-09-11T12:31:16.428Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    df0f  Received CommandResponse  {
    "mType": "rSMsg",
    "type": "CommandResponse",
    "mId": "df0fc9ea-4db9-45f5-bda2-3d77bb6ef7d5",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "cTS": "2024-09-11T12:31:16.375Z",
    "rvs": [
        {
            "cCI": "M0019",
            "n": "input",
            "age": "recent",
            "v": "2"
        },
        {
            "cCI": "M0019",
            "n": "inputValue",
            "age": "recent",
            "v": "False"
        },
        {
            "cCI": "M0019",
            "n": "securityCode",
            "age": "recent",
            "v": "default"
        },
        {
            "cCI": "M0019",
            "n": "status",
            "age": "recent",
            "v": "True"
        }
    ]
}
    2024-09-11T12:31:16.428Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for CommandResponse df0f  {"mType":"rSMsg","type":"MessageAck","oMId":"df0fc9ea-4db9-45f5-bda2-3d77bb6ef7d5"}
    2024-09-11T12:31:16.428Z  35670  AA+BBCCC=DDD         -                    -     Command response df0f collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"securityCode", "v"=>"default"}, item {"cCI"=>"M0019", "n"=>"securityCode", "age"=>"recent", "v"=>"default"}
    2024-09-11T12:31:16.428Z  35670  AA+BBCCC=DDD         -                    -     Command response df0f collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"status", "v"=>"True"}, item {"cCI"=>"M0019", "n"=>"status", "age"=>"recent", "v"=>"True"}
    2024-09-11T12:31:16.429Z  35670  AA+BBCCC=DDD         -                    -     Command response df0f collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"input", "v"=>"2"}, item {"cCI"=>"M0019", "n"=>"input", "age"=>"recent", "v"=>"2"}
    2024-09-11T12:31:16.429Z  35670  AA+BBCCC=DDD         -                    -     Command response df0f collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"inputValue", "v"=>"False"}, item {"cCI"=>"M0019", "n"=>"inputValue", "age"=>"recent", "v"=>"False"}
    2024-09-11T12:31:16.429Z  35670  AA+BBCCC=DDD         -                    -     Collect 1338: Completed with {"M0019"=>{"setInput"=>{"securityCode"=>"default", "status"=>"True", "input"=>"2", "inputValue"=>"False"}}}
    > Wait for input 2 to be forced to False
    2024-09-11T12:31:16.429Z  35670  AA+BBCCC=DDD         -                    -     Collect 1360: Waiting for StatusUpdate/StatusResponse matching {"S0029"=>{"status"=>/^.{1}1/}, "S0003"=>{"inputstatus"=>/^.{1}0/}}
    2024-09-11T12:31:16.435Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    9d43  Sent StatusSubscribe  {"mType":"rSMsg","type":"StatusSubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0029","n":"status","uRt":"0"},{"sCI":"S0003","n":"inputstatus","uRt":"0"}],"mId":"9d43f515-4d2b-41dc-a606-f8537edc6c5d","ntsOId":"","xNId":""}
    2024-09-11T12:31:16.436Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusSubscribe 9d43  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "9d43f515-4d2b-41dc-a606-f8537edc6c5d"
}
    2024-09-11T12:31:16.436Z  35670  AA+BBCCC=DDD         -                    -     StatusSubscribe 9d43 acknowledged, allowing repeated status values for [{"sCI"=>"S0029", "n"=>"status", "uRt"=>"0"}, {"sCI"=>"S0003", "n"=>"inputstatus", "uRt"=>"0"}]
    2024-09-11T12:31:16.439Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    6a23  Received StatusUpdate  {
    "mType": "rSMsg",
    "type": "StatusUpdate",
    "mId": "6a2342ec-2a48-4cb0-9d4e-d43b725a06fb",
    "ntsOId": "AA+BBCCC=DDDEEFFF",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "sTs": "2024-09-11T12:31:16.375Z",
    "sS": [
        {
            "sCI": "S0029",
            "n": "status",
            "q": "recent",
            "s": "0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"
        },
        {
            "sCI": "S0003",
            "n": "inputstatus",
            "q": "recent",
            "s": "0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"
        }
    ]
}
    2024-09-11T12:31:16.439Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for StatusUpdate 6a23  {"mType":"rSMsg","type":"MessageAck","oMId":"6a2342ec-2a48-4cb0-9d4e-d43b725a06fb"}
    2024-09-11T12:31:16.439Z  35670  AA+BBCCC=DDD         -                    -     Status response 6a23 collect match {"sCI"=>"S0029", "n"=>"status", "s"=>/^.{1}1/, "uRt"=>"0"}, item {"sCI"=>"S0029", "n"=>"status", "q"=>"recent", "s"=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}
    2024-09-11T12:31:16.440Z  35670  AA+BBCCC=DDD         -                    -     Status response 6a23 collect match {"sCI"=>"S0003", "n"=>"inputstatus", "s"=>/^.{1}0/, "uRt"=>"0"}, item {"sCI"=>"S0003", "n"=>"inputstatus", "q"=>"recent", "s"=>"0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}
    2024-09-11T12:31:16.440Z  35670  AA+BBCCC=DDD         -                    -     Collect 1360: Completed with {"S0029"=>{"status"=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}, "S0003"=>{"inputstatus"=>"0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}}
    2024-09-11T12:31:16.442Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    b247  Sent StatusUnsubscribe  {"mType":"rSMsg","type":"StatusUnsubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0029","n":"status"},{"sCI":"S0003","n":"inputstatus"}],"mId":"b247c373-024f-40e7-993c-40dab196c356","ntsOId":"","xNId":""}
    > Wait for input 2 to be False
    2024-09-11T12:31:16.443Z  35670  AA+BBCCC=DDD         -                    -     Collect 1374: Waiting for StatusUpdate/StatusResponse matching {"S0003"=>{"inputstatus"=>/^.{1}0/}}
    2024-09-11T12:31:16.443Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusUnsubscribe b247  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "b247c373-024f-40e7-993c-40dab196c356"
}
    2024-09-11T12:31:16.444Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    7ba2  Sent StatusSubscribe  {"mType":"rSMsg","type":"StatusSubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0003","n":"inputstatus","uRt":"0"}],"mId":"7ba2d0f4-6222-4a51-94e2-d11bf055b0d1","ntsOId":"","xNId":""}
    2024-09-11T12:31:16.445Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusSubscribe 7ba2  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "7ba2d0f4-6222-4a51-94e2-d11bf055b0d1"
}
    2024-09-11T12:31:16.445Z  35670  AA+BBCCC=DDD         -                    -     StatusSubscribe 7ba2 acknowledged, allowing repeated status values for [{"sCI"=>"S0003", "n"=>"inputstatus", "uRt"=>"0"}]
    2024-09-11T12:31:16.446Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    2cd8  Received StatusUpdate  {
    "mType": "rSMsg",
    "type": "StatusUpdate",
    "mId": "2cd89a32-57e4-4caf-ba6d-8d3c4b588f54",
    "ntsOId": "AA+BBCCC=DDDEEFFF",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "sTs": "2024-09-11T12:31:16.444Z",
    "sS": [
        {
            "sCI": "S0003",
            "n": "inputstatus",
            "q": "recent",
            "s": "0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"
        }
    ]
}
    2024-09-11T12:31:16.446Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for StatusUpdate 2cd8  {"mType":"rSMsg","type":"MessageAck","oMId":"2cd89a32-57e4-4caf-ba6d-8d3c4b588f54"}
    2024-09-11T12:31:16.447Z  35670  AA+BBCCC=DDD         -                    -     Status response 2cd8 collect match {"sCI"=>"S0003", "n"=>"inputstatus", "s"=>/^.{1}0/, "uRt"=>"0"}, item {"sCI"=>"S0003", "n"=>"inputstatus", "q"=>"recent", "s"=>"0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}
    2024-09-11T12:31:16.447Z  35670  AA+BBCCC=DDD         -                    -     Collect 1374: Completed with {"S0003"=>{"inputstatus"=>"0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}}
    2024-09-11T12:31:16.448Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    a2f6  Sent StatusUnsubscribe  {"mType":"rSMsg","type":"StatusUnsubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0003","n":"inputstatus"}],"mId":"a2f6f8ec-6a97-4447-ab61-9cacbbaba638","ntsOId":"","xNId":""}
    2024-09-11T12:31:16.448Z  35670  AA+BBCCC=DDD         -                    -     Collect 1388: Waiting for Alarm {"cId"=>"AA+BBCCC=DDDDL002", "aCId"=>"A0302", "aSp"=>/issue/i, "aS"=>/active/i}
    2024-09-11T12:31:16.448Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusUnsubscribe a2f6  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "a2f6f8ec-6a97-4447-ab61-9cacbbaba638"
}
    > Force input 2 to True
    2024-09-11T12:31:16.449Z  35670  AA+BBCCC=DDD         -                    -     Collect 139c: Waiting for CommandResponse matching {"M0019"=>{"setInput"=>{"securityCode"=>"default", "status"=>"True", "input"=>"2", "inputValue"=>"True"}}}
    2024-09-11T12:31:16.450Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    9393  Sent CommandRequest  {"mType":"rSMsg","type":"CommandRequest","cId":"AA+BBCCC=DDDEEFFF","arg":[{"cCI":"M0019","cO":"setInput","n":"securityCode","v":"default"},{"cCI":"M0019","cO":"setInput","n":"status","v":"True"},{"cCI":"M0019","cO":"setInput","n":"input","v":"2"},{"cCI":"M0019","cO":"setInput","n":"inputValue","v":"True"}],"mId":"939302d5-8869-47de-8694-e9c835e965f1","ntsOId":"","xNId":""}
    2024-09-11T12:31:16.451Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for CommandRequest 9393  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "939302d5-8869-47de-8694-e9c835e965f1"
}
    2024-09-11T12:31:16.455Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    9393  Received CommandResponse  {
    "mType": "rSMsg",
    "type": "CommandResponse",
    "mId": "939302d5-8869-47de-8694-e9c835e965f1",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "cTS": "2024-09-11T12:31:16.451Z",
    "rvs": [
        {
            "cCI": "M0019",
            "n": "input",
            "age": "recent",
            "v": "2"
        },
        {
            "cCI": "M0019",
            "n": "inputValue",
            "age": "recent",
            "v": "True"
        },
        {
            "cCI": "M0019",
            "n": "securityCode",
            "age": "recent",
            "v": "default"
        },
        {
            "cCI": "M0019",
            "n": "status",
            "age": "recent",
            "v": "True"
        }
    ]
}
    2024-09-11T12:31:16.455Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for CommandResponse 9393  {"mType":"rSMsg","type":"MessageAck","oMId":"939302d5-8869-47de-8694-e9c835e965f1"}
    2024-09-11T12:31:16.455Z  35670  AA+BBCCC=DDD         -                    -     Command response 9393 collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"securityCode", "v"=>"default"}, item {"cCI"=>"M0019", "n"=>"securityCode", "age"=>"recent", "v"=>"default"}
    2024-09-11T12:31:16.455Z  35670  AA+BBCCC=DDD         -                    -     Command response 9393 collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"status", "v"=>"True"}, item {"cCI"=>"M0019", "n"=>"status", "age"=>"recent", "v"=>"True"}
    2024-09-11T12:31:16.455Z  35670  AA+BBCCC=DDD         -                    -     Command response 9393 collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"input", "v"=>"2"}, item {"cCI"=>"M0019", "n"=>"input", "age"=>"recent", "v"=>"2"}
    2024-09-11T12:31:16.456Z  35670  AA+BBCCC=DDD         -                    -     Command response 9393 collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"inputValue", "v"=>"True"}, item {"cCI"=>"M0019", "n"=>"inputValue", "age"=>"recent", "v"=>"True"}
    2024-09-11T12:31:16.456Z  35670  AA+BBCCC=DDD         -                    -     Collect 139c: Completed with {"M0019"=>{"setInput"=>{"securityCode"=>"default", "status"=>"True", "input"=>"2", "inputValue"=>"True"}}}
    > Wait for input 2 to be forced to True
    2024-09-11T12:31:16.456Z  35670  AA+BBCCC=DDD         -                    -     Collect 13b0: Waiting for StatusUpdate/StatusResponse matching {"S0029"=>{"status"=>/^.{1}1/}, "S0003"=>{"inputstatus"=>/^.{1}1/}}
    2024-09-11T12:31:16.458Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    cd3c  Sent StatusSubscribe  {"mType":"rSMsg","type":"StatusSubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0029","n":"status","uRt":"0"},{"sCI":"S0003","n":"inputstatus","uRt":"0"}],"mId":"cd3cac57-3f69-402e-94ae-8e9a6ded622e","ntsOId":"","xNId":""}
    2024-09-11T12:31:16.459Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusSubscribe cd3c  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "cd3cac57-3f69-402e-94ae-8e9a6ded622e"
}
    2024-09-11T12:31:16.459Z  35670  AA+BBCCC=DDD         -                    -     StatusSubscribe cd3c acknowledged, allowing repeated status values for [{"sCI"=>"S0029", "n"=>"status", "uRt"=>"0"}, {"sCI"=>"S0003", "n"=>"inputstatus", "uRt"=>"0"}]
    2024-09-11T12:31:16.460Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    5422  Received StatusUpdate  {
    "mType": "rSMsg",
    "type": "StatusUpdate",
    "mId": "542289ec-6de9-4b18-b843-7fdb7644a45c",
    "ntsOId": "AA+BBCCC=DDDEEFFF",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "sTs": "2024-09-11T12:31:16.458Z",
    "sS": [
        {
            "sCI": "S0029",
            "n": "status",
            "q": "recent",
            "s": "0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"
        },
        {
            "sCI": "S0003",
            "n": "inputstatus",
            "q": "recent",
            "s": "0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"
        }
    ]
}
    2024-09-11T12:31:16.461Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for StatusUpdate 5422  {"mType":"rSMsg","type":"MessageAck","oMId":"542289ec-6de9-4b18-b843-7fdb7644a45c"}
    2024-09-11T12:31:16.461Z  35670  AA+BBCCC=DDD         -                    -     Status response 5422 collect match {"sCI"=>"S0029", "n"=>"status", "s"=>/^.{1}1/, "uRt"=>"0"}, item {"sCI"=>"S0029", "n"=>"status", "q"=>"recent", "s"=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}
    2024-09-11T12:31:16.461Z  35670  AA+BBCCC=DDD         -                    -     Status response 5422 collect mismatch {"sCI"=>"S0003", "n"=>"inputstatus", "s"=>/^.{1}1/, "uRt"=>"0"}, item {"sCI"=>"S0003", "n"=>"inputstatus", "q"=>"recent", "s"=>"0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}
    2024-09-11T12:31:16.461Z  35670  AA+BBCCC=DDD         -                    -     Collect 13b0: .. Matched 1/2 with {"S0029"=>{"status"=>{{/^.{1}1/=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}=>true}}, "S0003"=>{"inputstatus"=>{/^.{1}1/=>nil}}}
    2024-09-11T12:31:16.648Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDDL002    32ff  Received Alarm, A0302 Issue [notAcknowledged,active,notSuspended]  {
    "mType": "rSMsg",
    "type": "Alarm",
    "mId": "32fff902-684a-481a-9794-78fe749abb43",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDDL002",
    "aCId": "A0302",
    "xACId": "Control Block 2: Det Logic 2 (<DET LOGIC NAME>) has a short-circuit failure at inp.",
    "xNACId": "",
    "aSp": "Issue",
    "ack": "notAcknowledged",
    "aS": "active",
    "sS": "notSuspended",
    "aTs": "2024-09-11T12:31:16.646Z",
    "cat": "D",
    "pri": "3",
    "rvs": [
        {
            "n": "detector",
            "v": "2"
        },
        {
            "n": "errormode",
            "v": "off"
        },
        {
            "n": "logicerror",
            "v": ""
        },
        {
            "n": "manual",
            "v": "False"
        },
        {
            "n": "type",
            "v": "loop"
        }
    ]
}
    2024-09-11T12:31:16.649Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for Alarm 32ff  {"mType":"rSMsg","type":"MessageAck","oMId":"32fff902-684a-481a-9794-78fe749abb43"}
    2024-09-11T12:31:16.649Z  35670  AA+BBCCC=DDD         -                    -     Collect 1388: Done
    2024-09-11T12:31:16.656Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    3dc2  Received StatusUpdate  {
    "mType": "rSMsg",
    "type": "StatusUpdate",
    "mId": "3dc240fb-1ba0-46fa-b9a1-deaa75c6c33a",
    "ntsOId": "AA+BBCCC=DDDEEFFF",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "sTs": "2024-09-11T12:31:16.654Z",
    "sS": [
        {
            "sCI": "S0003",
            "n": "inputstatus",
            "q": "recent",
            "s": "0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"
        }
    ]
}
    2024-09-11T12:31:16.657Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for StatusUpdate 3dc2  {"mType":"rSMsg","type":"MessageAck","oMId":"3dc240fb-1ba0-46fa-b9a1-deaa75c6c33a"}
    2024-09-11T12:31:16.658Z  35670  AA+BBCCC=DDD         -                    -     Status response 3dc2 collect match {"sCI"=>"S0003", "n"=>"inputstatus", "s"=>/^.{1}1/, "uRt"=>"0"}, item {"sCI"=>"S0003", "n"=>"inputstatus", "q"=>"recent", "s"=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}
    2024-09-11T12:31:16.658Z  35670  AA+BBCCC=DDD         -                    -     Collect 13b0: Completed with {"S0029"=>{"status"=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}, "S0003"=>{"inputstatus"=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}}
    2024-09-11T12:31:16.661Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    9b88  Sent StatusUnsubscribe  {"mType":"rSMsg","type":"StatusUnsubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0029","n":"status"},{"sCI":"S0003","n":"inputstatus"}],"mId":"9b881ef9-864b-4e5d-9e93-cc9efb727f6e","ntsOId":"","xNId":""}
    > Wait for input 2 to be True
    2024-09-11T12:31:16.662Z  35670  AA+BBCCC=DDD         -                    -     Collect 13c4: Waiting for StatusUpdate/StatusResponse matching {"S0003"=>{"inputstatus"=>/^.{1}1/}}
    2024-09-11T12:31:16.664Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    5bd5  Sent StatusSubscribe  {"mType":"rSMsg","type":"StatusSubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0003","n":"inputstatus","uRt":"0"}],"mId":"5bd533b5-44ec-45db-bc47-caf1af2aadfb","ntsOId":"","xNId":""}
    2024-09-11T12:31:16.664Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusUnsubscribe 9b88  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "9b881ef9-864b-4e5d-9e93-cc9efb727f6e"
}
    2024-09-11T12:31:16.708Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusSubscribe 5bd5  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "5bd533b5-44ec-45db-bc47-caf1af2aadfb"
}
    2024-09-11T12:31:16.709Z  35670  AA+BBCCC=DDD         -                    -     StatusSubscribe 5bd5 acknowledged, allowing repeated status values for [{"sCI"=>"S0003", "n"=>"inputstatus", "uRt"=>"0"}]
    2024-09-11T12:31:16.711Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    12e6  Received StatusUpdate  {
    "mType": "rSMsg",
    "type": "StatusUpdate",
    "mId": "12e685fb-70c6-4529-920e-edd1374a3fe6",
    "ntsOId": "AA+BBCCC=DDDEEFFF",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "sTs": "2024-09-11T12:31:16.664Z",
    "sS": [
        {
            "sCI": "S0003",
            "n": "inputstatus",
            "q": "recent",
            "s": "0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"
        }
    ]
}
    2024-09-11T12:31:16.713Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for StatusUpdate 12e6  {"mType":"rSMsg","type":"MessageAck","oMId":"12e685fb-70c6-4529-920e-edd1374a3fe6"}
    2024-09-11T12:31:16.713Z  35670  AA+BBCCC=DDD         -                    -     Status response 12e6 collect match {"sCI"=>"S0003", "n"=>"inputstatus", "s"=>/^.{1}1/, "uRt"=>"0"}, item {"sCI"=>"S0003", "n"=>"inputstatus", "q"=>"recent", "s"=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}
    2024-09-11T12:31:16.714Z  35670  AA+BBCCC=DDD         -                    -     Collect 13c4: Completed with {"S0003"=>{"inputstatus"=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}}
    2024-09-11T12:31:16.716Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    ea12  Sent StatusUnsubscribe  {"mType":"rSMsg","type":"StatusUnsubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0003","n":"inputstatus"}],"mId":"ea12bfb4-453a-47fd-80b9-4b2cb0c20171","ntsOId":"","xNId":""}
    > Alarm A0302 is now Active on component AA+BBCCC=DDDDL002
    2024-09-11T12:31:16.718Z  35670  AA+BBCCC=DDD         -                    -     Collect 13d8: Waiting for Alarm {"cId"=>"AA+BBCCC=DDDDL002", "aCId"=>"A0302", "aSp"=>/Issue/i, "aS"=>/inactive/i}
    2024-09-11T12:31:16.719Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusUnsubscribe ea12  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "ea12bfb4-453a-47fd-80b9-4b2cb0c20171"
}
    > Force input 2 to False
    2024-09-11T12:31:16.719Z  35670  AA+BBCCC=DDD         -                    -     Collect 13ec: Waiting for CommandResponse matching {"M0019"=>{"setInput"=>{"securityCode"=>"default", "status"=>"True", "input"=>"2", "inputValue"=>"False"}}}
    2024-09-11T12:31:16.723Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    f055  Sent CommandRequest  {"mType":"rSMsg","type":"CommandRequest","cId":"AA+BBCCC=DDDEEFFF","arg":[{"cCI":"M0019","cO":"setInput","n":"securityCode","v":"default"},{"cCI":"M0019","cO":"setInput","n":"status","v":"True"},{"cCI":"M0019","cO":"setInput","n":"input","v":"2"},{"cCI":"M0019","cO":"setInput","n":"inputValue","v":"False"}],"mId":"f055fe57-deef-4db0-bf59-4d3be00b5570","ntsOId":"","xNId":""}
    2024-09-11T12:31:16.725Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for CommandRequest f055  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "f055fe57-deef-4db0-bf59-4d3be00b5570"
}
    2024-09-11T12:31:16.729Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    f055  Received CommandResponse  {
    "mType": "rSMsg",
    "type": "CommandResponse",
    "mId": "f055fe57-deef-4db0-bf59-4d3be00b5570",
    "ntsOId": "",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "cTS": "2024-09-11T12:31:16.724Z",
    "rvs": [
        {
            "cCI": "M0019",
            "n": "input",
            "age": "recent",
            "v": "2"
        },
        {
            "cCI": "M0019",
            "n": "inputValue",
            "age": "recent",
            "v": "False"
        },
        {
            "cCI": "M0019",
            "n": "securityCode",
            "age": "recent",
            "v": "default"
        },
        {
            "cCI": "M0019",
            "n": "status",
            "age": "recent",
            "v": "True"
        }
    ]
}
    2024-09-11T12:31:16.730Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for CommandResponse f055  {"mType":"rSMsg","type":"MessageAck","oMId":"f055fe57-deef-4db0-bf59-4d3be00b5570"}
    2024-09-11T12:31:16.730Z  35670  AA+BBCCC=DDD         -                    -     Command response f055 collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"securityCode", "v"=>"default"}, item {"cCI"=>"M0019", "n"=>"securityCode", "age"=>"recent", "v"=>"default"}
    2024-09-11T12:31:16.731Z  35670  AA+BBCCC=DDD         -                    -     Command response f055 collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"status", "v"=>"True"}, item {"cCI"=>"M0019", "n"=>"status", "age"=>"recent", "v"=>"True"}
    2024-09-11T12:31:16.731Z  35670  AA+BBCCC=DDD         -                    -     Command response f055 collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"input", "v"=>"2"}, item {"cCI"=>"M0019", "n"=>"input", "age"=>"recent", "v"=>"2"}
    2024-09-11T12:31:16.731Z  35670  AA+BBCCC=DDD         -                    -     Command response f055 collect match {"cCI"=>"M0019", "cO"=>"setInput", "n"=>"inputValue", "v"=>"False"}, item {"cCI"=>"M0019", "n"=>"inputValue", "age"=>"recent", "v"=>"False"}
    2024-09-11T12:31:16.731Z  35670  AA+BBCCC=DDD         -                    -     Collect 13ec: Completed with {"M0019"=>{"setInput"=>{"securityCode"=>"default", "status"=>"True", "input"=>"2", "inputValue"=>"False"}}}
    > Wait for input 2 to be forced to False
    2024-09-11T12:31:16.732Z  35670  AA+BBCCC=DDD         -                    -     Collect 1400: Waiting for StatusUpdate/StatusResponse matching {"S0029"=>{"status"=>/^.{1}1/}, "S0003"=>{"inputstatus"=>/^.{1}0/}}
    2024-09-11T12:31:16.739Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    edb1  Sent StatusSubscribe  {"mType":"rSMsg","type":"StatusSubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0029","n":"status","uRt":"0"},{"sCI":"S0003","n":"inputstatus","uRt":"0"}],"mId":"edb144e9-fe40-4ddc-aebb-24138a5e831d","ntsOId":"","xNId":""}
    2024-09-11T12:31:16.740Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusSubscribe edb1  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "edb144e9-fe40-4ddc-aebb-24138a5e831d"
}
    2024-09-11T12:31:16.740Z  35670  AA+BBCCC=DDD         -                    -     StatusSubscribe edb1 acknowledged, allowing repeated status values for [{"sCI"=>"S0029", "n"=>"status", "uRt"=>"0"}, {"sCI"=>"S0003", "n"=>"inputstatus", "uRt"=>"0"}]
    2024-09-11T12:31:16.744Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    4f4e  Received StatusUpdate  {
    "mType": "rSMsg",
    "type": "StatusUpdate",
    "mId": "4f4ef005-23f9-413c-a49b-b77c275ac794",
    "ntsOId": "AA+BBCCC=DDDEEFFF",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "sTs": "2024-09-11T12:31:16.739Z",
    "sS": [
        {
            "sCI": "S0029",
            "n": "status",
            "q": "recent",
            "s": "0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"
        },
        {
            "sCI": "S0003",
            "n": "inputstatus",
            "q": "recent",
            "s": "0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"
        }
    ]
}
    2024-09-11T12:31:16.746Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for StatusUpdate 4f4e  {"mType":"rSMsg","type":"MessageAck","oMId":"4f4ef005-23f9-413c-a49b-b77c275ac794"}
    2024-09-11T12:31:16.746Z  35670  AA+BBCCC=DDD         -                    -     Status response 4f4e collect match {"sCI"=>"S0029", "n"=>"status", "s"=>/^.{1}1/, "uRt"=>"0"}, item {"sCI"=>"S0029", "n"=>"status", "q"=>"recent", "s"=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}
    2024-09-11T12:31:16.746Z  35670  AA+BBCCC=DDD         -                    -     Status response 4f4e collect mismatch {"sCI"=>"S0003", "n"=>"inputstatus", "s"=>/^.{1}0/, "uRt"=>"0"}, item {"sCI"=>"S0003", "n"=>"inputstatus", "q"=>"recent", "s"=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}
    2024-09-11T12:31:16.747Z  35670  AA+BBCCC=DDD         -                    -     Collect 1400: .. Matched 1/2 with {"S0029"=>{"status"=>{{/^.{1}1/=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}=>true}}, "S0003"=>{"inputstatus"=>{/^.{1}0/=>nil}}}
    2024-09-11T12:31:16.947Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    4739  Received StatusUpdate  {
    "mType": "rSMsg",
    "type": "StatusUpdate",
    "mId": "47398c89-354f-49f9-95b5-af5c741226bb",
    "ntsOId": "AA+BBCCC=DDDEEFFF",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "sTs": "2024-09-11T12:31:16.945Z",
    "sS": [
        {
            "sCI": "S0003",
            "n": "inputstatus",
            "q": "recent",
            "s": "0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"
        }
    ]
}
    2024-09-11T12:31:16.948Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for StatusUpdate 4739  {"mType":"rSMsg","type":"MessageAck","oMId":"47398c89-354f-49f9-95b5-af5c741226bb"}
    2024-09-11T12:31:16.949Z  35670  AA+BBCCC=DDD         -                    -     Status response 4739 collect match {"sCI"=>"S0003", "n"=>"inputstatus", "s"=>/^.{1}0/, "uRt"=>"0"}, item {"sCI"=>"S0003", "n"=>"inputstatus", "q"=>"recent", "s"=>"0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}
    2024-09-11T12:31:16.949Z  35670  AA+BBCCC=DDD         -                    -     Collect 1400: Completed with {"S0029"=>{"status"=>"0100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}, "S0003"=>{"inputstatus"=>"0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}}
    2024-09-11T12:31:16.952Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    edf1  Sent StatusUnsubscribe  {"mType":"rSMsg","type":"StatusUnsubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0029","n":"status"},{"sCI":"S0003","n":"inputstatus"}],"mId":"edf1271e-e33f-4ed6-940f-a557c44334b1","ntsOId":"","xNId":""}
    > Wait for input 2 to be False
    2024-09-11T12:31:16.953Z  35670  AA+BBCCC=DDD         -                    -     Collect 1428: Waiting for StatusUpdate/StatusResponse matching {"S0003"=>{"inputstatus"=>/^.{1}0/}}
    2024-09-11T12:31:16.954Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusUnsubscribe edf1  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "edf1271e-e33f-4ed6-940f-a557c44334b1"
}
    2024-09-11T12:31:16.956Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    553e  Sent StatusSubscribe  {"mType":"rSMsg","type":"StatusSubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0003","n":"inputstatus","uRt":"0"}],"mId":"553eaa9d-432d-4c31-892e-716a01f5ff11","ntsOId":"","xNId":""}
    2024-09-11T12:31:16.957Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusSubscribe 553e  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "553eaa9d-432d-4c31-892e-716a01f5ff11"
}
    2024-09-11T12:31:16.957Z  35670  AA+BBCCC=DDD         -                    -     StatusSubscribe 553e acknowledged, allowing repeated status values for [{"sCI"=>"S0003", "n"=>"inputstatus", "uRt"=>"0"}]
    2024-09-11T12:31:16.959Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    0d34  Received StatusUpdate  {
    "mType": "rSMsg",
    "type": "StatusUpdate",
    "mId": "0d34b6a8-1023-4c99-bf6a-b60f61574095",
    "ntsOId": "AA+BBCCC=DDDEEFFF",
    "xNId": "",
    "cId": "AA+BBCCC=DDDEEFFF",
    "sTs": "2024-09-11T12:31:16.956Z",
    "sS": [
        {
            "sCI": "S0003",
            "n": "inputstatus",
            "q": "recent",
            "s": "0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"
        }
    ]
}
    2024-09-11T12:31:16.960Z  35670  AA+BBCCC=DDD         -                    -     Sent MessageAck for StatusUpdate 0d34  {"mType":"rSMsg","type":"MessageAck","oMId":"0d34b6a8-1023-4c99-bf6a-b60f61574095"}
    2024-09-11T12:31:16.960Z  35670  AA+BBCCC=DDD         -                    -     Status response 0d34 collect match {"sCI"=>"S0003", "n"=>"inputstatus", "s"=>/^.{1}0/, "uRt"=>"0"}, item {"sCI"=>"S0003", "n"=>"inputstatus", "q"=>"recent", "s"=>"0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}
    2024-09-11T12:31:16.961Z  35670  AA+BBCCC=DDD         -                    -     Collect 1428: Completed with {"S0003"=>{"inputstatus"=>"0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"}}
    2024-09-11T12:31:16.963Z  35670  AA+BBCCC=DDD         AA+BBCCC=DDDEEFFF    e3a2  Sent StatusUnsubscribe  {"mType":"rSMsg","type":"StatusUnsubscribe","cId":"AA+BBCCC=DDDEEFFF","sS":[{"sCI":"S0003","n":"inputstatus"}],"mId":"e3a2695c-796a-46a8-b51b-53ebf4a24e23","ntsOId":"","xNId":""}
    2024-09-11T12:31:16.964Z  35670  AA+BBCCC=DDD         -                    -     Received MessageAck for StatusUnsubscribe e3a2  {
    "mType": "rSMsg",
    "type": "MessageAck",
    "oMId": "e3a2695c-796a-46a8-b51b-53ebf4a24e23"
}
    2024-09-11T12:31:20.943Z  35670  AA+BBCCC=DDD         -                    -     Connection closed
    2024-09-11T12:31:20.943Z  35670  AA+BBCCC=DDD         -                    -     Closing connection
    2024-09-11T12:31:20.944Z  -      -                    -                    -     Connection to 127.0.0.1:35670 closed
  Failure/Error: collector.collect!
  
  RSMP::TimeoutError:
    0 of 1 messages collected

  # ./vendor/bundle/ruby/3.2.0/gems/rsmp-0.32.5/lib/rsmp/collect/collector.rb:100:in `ok!'
  # ./vendor/bundle/ruby/3.2.0/gems/rsmp-0.32.5/lib/rsmp/collect/collector.rb:118:in `collect!'
  # ./spec/support/command_helpers.rb:397:in `block in with_alarm_activated'
  # ./vendor/bundle/ruby/3.2.0/gems/async-2.17.0/lib/async/task.rb:197:in `block in run'
  # ./vendor/bundle/ruby/3.2.0/gems/async-2.17.0/lib/async/task.rb:422:in `block in schedule'


Failures:

  1) Site::Traffic Light Controller Alarm Alarm A0302 is raised when input is activated
     Failure/Error: collector.collect!
     
     RSMP::TimeoutError:
       0 of 1 messages collected
     # ./vendor/bundle/ruby/3.2.0/gems/rsmp-0.32.5/lib/rsmp/collect/collector.rb:100:in `ok!'
     # ./vendor/bundle/ruby/3.2.0/gems/rsmp-0.32.5/lib/rsmp/collect/collector.rb:118:in `collect!'
     # ./spec/support/command_helpers.rb:397:in `block in with_alarm_activated'
     # ./vendor/bundle/ruby/3.2.0/gems/async-2.17.0/lib/async/task.rb:197:in `block in run'
     # ./vendor/bundle/ruby/3.2.0/gems/async-2.17.0/lib/async/task.rb:422:in `block in schedule'

Finished in 15.87 seconds (files took 0.4473 seconds to load)
1 example, 1 failure

Failed examples:

rspec ./spec/site/tlc/alarm_spec.rb:29 # Site::Traffic Light Controller Alarm Alarm A0302 is raised when input is activated

make: *** [makefile:25: run_tlc_spec] Error 1
sveitech commented 2 months ago

I just confirmed this to be the case. If I remove this line:

      message.validate(get_schemas) if should_validate_ingoing_message?(message)

from the file vendor/bundle/ruby/3.2.0/gems/rsmp-0.32.5/lib/rsmp/proxy.rb

The alarm tests pass.

emiltin commented 2 months ago

I'm not sure why the message would not show up.

BTW, I noticed that you're specifing sxl 1.0.13: Run options: exclude {:sxl=>[unless relevant for 1.0.13], :core=>[unless relevant for 3.1.2]}

But the site is actually connecting using 1.0.15: 2024-09-11T12:31:16.378Z 35670 AA+BBCCC=DDD - - Connection to site AA+BBCCC=DDD established, using core 3.1.2, tlc 1.0.15

Since the site is using 1.0.15 (and assuming this is what you want), you should set restrict_testing/sxl_version to 1.0.15, otherwise an incorrect set of tests might be run.

I'm considering adding a check on this when the validator starts, and abort if there's a mismatch.