Skip to content

Buffer race condition fix #102

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Open
wants to merge 2 commits into
base: master
Choose a base branch
from
Open

Buffer race condition fix #102

wants to merge 2 commits into from

Conversation

SergeyGulik
Copy link
Contributor

@SergeyGulik SergeyGulik commented Jun 6, 2025 •
edited
Loading

By splitting observation removal lock and further adding lock, there was broken atomicity of the update.

As a result, a simultaneously running current query could not return any value for removed observation. And this observation, once restored, was not returned as sample. After all it was an update of existing observation.
To mitigate the problem made update atomic.

Please see the log for illustration:
Despite the fact that sequence 58 was not known when we started the scan for Current values, 58 was returned as the LastSequence from GetCurrentObservations.

2025-06-06T12:49:47.2753930|Trace: [MTConnect.Servers.Http.MTConnectHttpServer] CurrentRequest: deviceKey=(null), deviceType=(null), path=(null), at=(null), interval=-1, heartbeat=10000, version=2.4, documentFormat=XML, validationLevel=0, indentOutput=True, outputComments=False, acceptEncodings=
2025-06-06T12:49:47.2753943|Information: [MTConnect.Servers.Http.MTConnectHttpServer] Handling current request as a single response (interval <= -1).
2025-06-06T12:49:47.2753968|Information: [MTConnect.Servers.Http.MTConnectHttpServer] Handling current request as a single response without deviceKey.
2025-06-06T12:49:47.2753999|Trace: [MTConnect.Agents.MTConnectAgentBroker] Streams request received
2025-06-06T12:49:47.2754433|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.AddCurrentObservation: Removed Existing Observation for BufferKey 20041 with Sequence 41 and Timestamp 17492069872588588, Removed: True
2025-06-06T12:49:47.2754484|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 10001 with Sequence 1 and Timestamp 17492069872491916
2025-06-06T12:49:47.2754511|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 10002 with Sequence 2 and Timestamp 17492069872497963
2025-06-06T12:49:47.2754521|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 10003 with Sequence 3 and Timestamp 17492069872498734
2025-06-06T12:49:47.2754530|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 10004 with Sequence 4 and Timestamp 17492069872499506
2025-06-06T12:49:47.2754539|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 10005 with Sequence 5 and Timestamp 17492069872499750
2025-06-06T12:49:47.2754551|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 10006 with Sequence 6 and Timestamp 17492069872507792
2025-06-06T12:49:47.2754560|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 10007 with Sequence 7 and Timestamp 17492069872507792
2025-06-06T12:49:47.2754570|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 10008 with Sequence 8 and Timestamp 17492069872507792
2025-06-06T12:49:47.2754579|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 10009 with Sequence 9 and Timestamp 17492069872507792
2025-06-06T12:49:47.2754593|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 10010 with Sequence 10 and Timestamp 17492069872507792
2025-06-06T12:49:47.2754605|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 10011 with Sequence 11 and Timestamp 17492069872507792
2025-06-06T12:49:47.2754622|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20012 with Sequence 12 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754643|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20013 with Sequence 13 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754654|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20014 with Sequence 14 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754666|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20015 with Sequence 15 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754677|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20016 with Sequence 16 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754687|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20017 with Sequence 17 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754700|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20018 with Sequence 18 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754710|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20019 with Sequence 19 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754721|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20020 with Sequence 20 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754730|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20021 with Sequence 21 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754739|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20022 with Sequence 22 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754747|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20023 with Sequence 23 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754756|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20024 with Sequence 24 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754769|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20025 with Sequence 25 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754796|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20026 with Sequence 26 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754805|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20027 with Sequence 27 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754833|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20031 with Sequence 31 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754842|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20032 with Sequence 32 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754850|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20033 with Sequence 33 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754865|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20034 with Sequence 34 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754873|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20035 with Sequence 35 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754882|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20036 with Sequence 36 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754890|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20037 with Sequence 37 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754899|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20038 with Sequence 38 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754908|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20039 with Sequence 39 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754920|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20040 with Sequence 40 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754929|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20042 with Sequence 42 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754938|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20043 with Sequence 43 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754946|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20044 with Sequence 44 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754956|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20045 with Sequence 45 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754966|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20046 with Sequence 46 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754975|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20047 with Sequence 47 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754985|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20048 with Sequence 48 and Timestamp 17492069872588588
2025-06-06T12:49:47.2754999|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20049 with Sequence 49 and Timestamp 17492069872588588
2025-06-06T12:49:47.2755008|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20050 with Sequence 50 and Timestamp 17492069872588588
2025-06-06T12:49:47.2755020|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20053 with Sequence 53 and Timestamp 17492069872588588
2025-06-06T12:49:47.2755029|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20054 with Sequence 54 and Timestamp 17492069872588588
2025-06-06T12:49:47.2755037|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20055 with Sequence 55 and Timestamp 17492069872588588
2025-06-06T12:49:47.2755046|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20056 with Sequence 56 and Timestamp 17492069872588588
2025-06-06T12:49:47.2755055|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found Current Observation for BufferKey 20057 with Sequence 57 and Timestamp 17492069872588588
2025-06-06T12:49:47.2755203|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.AddCurrentObservation: Added Current Observation for BufferKey 20041 with Sequence 58 and Timestamp 17492069872753157
2025-06-06T12:49:47.2755290|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectObservationBuffer.GetCurrentObservations[1]: Found 56 Current Observations for BufferKeys 10001, 10002, 10003, 10004, 10005, 10006, 10007, 10008, 10009, 10010, 10011, 20012, 20013, 20014, 20015, 20016, 20017, 20018, 20019, 20020, 20021, 20022, 20023, 20024, 20025, 20026, 20027, 20028, 20029, 20030, 20031, 20032, 20033, 20034, 20035, 20036, 20037, 20038, 20039, 20040, 20041, 20042, 20043, 20044, 20045, 20046, 20047, 20048, 20049, 20050, 20051, 20052, 20053, 20054, 20055, 20056, 20057 with FirstSequence 1, LastSequence 58, NextSequence 59, FirstObservationSequence 1, LastObservationSequence 57.
2025-06-06T12:49:47.2755473|Trace: [MTConnect.Agents.MTConnectAgentBroker] Observation added: bc14c002-4e99-446d-b8a4-7f3174f34dbb PartCountAct Result:12
2025-06-06T12:49:47.2755568|Trace: [MTConnect.Agents.MTConnectAgentBroker] MTConnectAgent:12.49.47.275549 Data item added async in agent PartCountAct:Result/12 with success.
2025-06-06T12:49:47.2755635|Trace: [MTConnect.Agents.MTConnectAgentBroker] [MTConnectAgent, 2011] 12.49.47.275562 Added data item PartCountAct to buffer with True.
2025-06-06T12:49:47.2755939|Trace: [MTConnect.Agents.MTConnectAgentBroker] Streams response sent

2025-06-06T12:49:47.2762561|Trace: [MTConnect.Servers.Http.MTConnectHttpServer] Response sent: 200 application/xml <?xml version="1.0" encoding="utf-8"?>
<MTConnectStreams xmlns="urn:mtconnect.org:MTConnectStreams:2.4" xmlns:m="urn:mtconnect.org:MTConnectStreams:2.4" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="">
  <Header instanceId="1749206987" version="6.5.0.0" sender="ADSKPF3FBP2T" bufferSize="150000" firstSequence="1" lastSequence="58" nextSequence="59" deviceModelChangeTime="2025-06-06T10:49:47.2587027Z" creationTime="2025-06-06T10:49:47.2755907Z" />
  <Streams>
    <DeviceStream name="agent" uuid="29029e4c-2feb-4ce3-8747-128c68044cab">
      <ComponentStream component="Agent" componentId="agent_8482033913" name="agent" uuid="29029e4c-2feb-4ce3-8747-128c68044cab">
        <Events>
          <Availability dataItemId="agent_8482033913_availability" name="availability" sequence="1" timestamp="2025-06-06T10:49:47.2491916Z">AVAILABLE</Availability>
          <Application dataItemId="agent_8482033913_application_MANUFACTURER" name="application" subType="MANUFACTURER" sequence="2" timestamp="2025-06-06T10:49:47.2497963Z">Microsoft Corporation</Application>
          <Application dataItemId="agent_8482033913_application_VERSION" name="application" subType="VERSION" sequence="3" timestamp="2025-06-06T10:49:47.2498734Z">6.5.0.0</Application>
          <OperatingSystem dataItemId="agent_8482033913_operatingSystem_MANUFACTURER" name="operatingSystem" subType="MANUFACTURER" sequence="4" timestamp="2025-06-06T10:49:47.2499506Z">WINDOWS</OperatingSystem>
          <OperatingSystem dataItemId="agent_8482033913_operatingSystem_VERSION" name="operatingSystem" subType="VERSION" sequence="5" timestamp="2025-06-06T10:49:47.2499750Z">Microsoft Windows NT 10.0.26100.0</OperatingSystem>
          <DeviceAdded dataItemId="agent_8482033913_deviceAdded" name="deviceAdded" sequence="6" timestamp="2025-06-06T10:49:47.2507792Z">UNAVAILABLE</DeviceAdded>
          <DeviceRemoved dataItemId="agent_8482033913_deviceRemoved" name="deviceRemoved" sequence="7" timestamp="2025-06-06T10:49:47.2507792Z">UNAVAILABLE</DeviceRemoved>
          <DeviceChanged dataItemId="agent_8482033913_deviceChanged" name="deviceChanged" sequence="8" timestamp="2025-06-06T10:49:47.2507792Z">UNAVAILABLE</DeviceChanged>
          <AssetChanged dataItemId="agent_8482033913_assetChanged" name="assetChanged" sequence="9" timestamp="2025-06-06T10:49:47.2507792Z">UNAVAILABLE</AssetChanged>
          <AssetRemoved dataItemId="agent_8482033913_assetRemoved" name="assetRemoved" sequence="10" timestamp="2025-06-06T10:49:47.2507792Z">UNAVAILABLE</AssetRemoved>
          <AssetCount dataItemId="agent_8482033913_assetCount" name="assetCount" sequence="11" timestamp="2025-06-06T10:49:47.2507792Z">UNAVAILABLE</AssetCount>
        </Events>
      </ComponentStream>
    </DeviceStream>
    <DeviceStream name="Machine5010" uuid="bc14c002-4e99-446d-b8a4-7f3174f34dbb">
      <ComponentStream component="Device" componentId="d1" name="Machine5010" uuid="bc14c002-4e99-446d-b8a4-7f3174f34dbb">
        <Events>
          <Availability dataItemId="avail" sequence="12" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</Availability>
          <FunctionalMode dataItemId="functionalmode" sequence="13" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</FunctionalMode>
          <EquipmentMode dataItemId="emloaded" subType="LOADED" sequence="14" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</EquipmentMode>
          <EquipmentMode dataItemId="emworking" subType="WORKING" sequence="15" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</EquipmentMode>
          <EquipmentMode dataItemId="emoperating" subType="OPERATING" sequence="16" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</EquipmentMode>
          <EquipmentMode dataItemId="empowered" subType="POWERED" sequence="17" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</EquipmentMode>
          <EquipmentMode dataItemId="emdelay" subType="DELAY" sequence="18" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</EquipmentMode>
          <OperatingSystem dataItemId="operatingsystem" sequence="19" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</OperatingSystem>
          <OperatingSystem dataItemId="osmfg" subType="MANUFACTURER" sequence="20" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</OperatingSystem>
          <OperatingSystem dataItemId="osversion" subType="VERSION" sequence="21" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</OperatingSystem>
          <Application dataItemId="gui" sequence="22" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</Application>
          <Application dataItemId="guimfg" subType="MANUFACTURER" sequence="23" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</Application>
          <Application dataItemId="guiversion" subType="VERSION" sequence="24" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</Application>
          <AssetChanged dataItemId="d1_asset_chg" sequence="25" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</AssetChanged>
          <AssetRemoved dataItemId="d1_asset_rem" sequence="26" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</AssetRemoved>
          <AssetCount dataItemId="d1_assetCount" name="assetCount" sequence="27" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</AssetCount>
        </Events>
      </ComponentStream>
      <ComponentStream component="Controller" componentId="cont" name="controller">
        <Events>
          <EmergencyStop dataItemId="estop" sequence="31" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</EmergencyStop>
          <PalletId dataItemId="pallet_num" sequence="32" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</PalletId>
        </Events>
        <Condition>
          <Unavailable dataItemId="comms_cond" type="COMMUNICATIONS" sequence="28" timestamp="2025-06-06T10:49:47.2588588Z" />
          <Unavailable dataItemId="logic_cond" type="LOGIC_PROGRAM" sequence="29" timestamp="2025-06-06T10:49:47.2588588Z" />
          <Unavailable dataItemId="system_cond" type="SYSTEM" sequence="30" timestamp="2025-06-06T10:49:47.2588588Z" />
        </Condition>
      </ComponentStream>
      <ComponentStream component="Path" componentId="path1" name="path">
        <Samples>
          <PathFeedrate dataItemId="Fact" subType="ACTUAL" sequence="42" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</PathFeedrate>
        </Samples>
        <Events>
          <ProgramEdit dataItemId="peditmode" sequence="33" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ProgramEdit>
          <ProgramEditName dataItemId="peditname" sequence="34" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ProgramEditName>
          <ChuckState dataItemId="hd1chuckstate" sequence="35" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ChuckState>
          <PathFeedrateOverride dataItemId="Frapidovr" subType="RAPID" sequence="36" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</PathFeedrateOverride>
          <PathFeedrateOverride dataItemId="Fovr" subType="PROGRAMMED" sequence="37" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</PathFeedrateOverride>
          <RotaryVelocityOverride dataItemId="Sovr" sequence="38" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</RotaryVelocityOverride>
          <Program dataItemId="program" subType="MAIN" sequence="39" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</Program>
          <Program dataItemId="activeprog" subType="ACTIVE" sequence="40" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</Program>
          <ToolNumber dataItemId="Tool_number" sequence="43" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ToolNumber>
          <ToolAssetId dataItemId="Tool_asset_id" sequence="44" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ToolAssetId>
          <ToolGroup dataItemId="Tool_group" sequence="45" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ToolGroup>
          <Execution dataItemId="execution" sequence="46" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</Execution>
          <WaitState dataItemId="waitstate" sequence="47" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</WaitState>
          <ControllerMode dataItemId="mode" sequence="48" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ControllerMode>
          <ProgramComment dataItemId="program_cmt" subType="MAIN" sequence="49" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ProgramComment>
          <ProgramComment dataItemId="activeprogram_cmt" subType="ACTIVE" sequence="50" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ProgramComment>
          <ControllerModeOverride dataItemId="cmomachineaxislock" subType="MACHINE_AXIS_LOCK" sequence="53" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ControllerModeOverride>
          <ControllerModeOverride dataItemId="cmosingleblock" subType="SINGLE_BLOCK" sequence="54" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ControllerModeOverride>
          <ControllerModeOverride dataItemId="cmodryrun" subType="DRY_RUN" sequence="55" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</ControllerModeOverride>
          <LineLabel dataItemId="linelabel" sequence="56" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</LineLabel>
          <LineNumber dataItemId="linenumber" subType="INCREMENTAL" sequence="57" timestamp="2025-06-06T10:49:47.2588588Z">UNAVAILABLE</LineNumber>
        </Events>
        <Condition>
          <Unavailable dataItemId="motion_cond" type="MOTION_PROGRAM" sequence="51" timestamp="2025-06-06T10:49:47.2588588Z" />
          <Unavailable dataItemId="path_system" type="SYSTEM" sequence="52" timestamp="2025-06-06T10:49:47.2588588Z" />
        </Condition>
      </ComponentStream>
    </DeviceStream>
  </Streams>
</MTConnectStreams>

@SergeyGulik
By splitting observation removal lock and further adding lock, there …
9df5c22 
…was broken atomicity of the update.

As a result, a simultaneously running current query could not return any value for removed observation.
And this observation, once restored, was not returned as sample. After all it was an update of existing observation.
To mitigate the problem made update atomic.
@SergeyGulik
Copy link
Contributor Author

SergeyGulik commented Jun 6, 2025 •
edited
Loading

Hi Patrick, I can see that the current fix is not enough.
I was surprised by the fact that the lastSequence from GetCurrentObservations was containing new item added in parallel.
The reason is obvious:
image
So,

  1. We start AddObservation, lock state changes, increment the sequence, unlock the state changes.
  2. We start GetCurrentObservations(IEnumerable bufferKeys), lock state and enumerate observations, also reading already incremented sequence, unlock the state changes.
  3. We lock the state changes and finish adding observations, unlock the state changes.
    I proved it is true with logging.

To avoid such bugs I used to lock state only once per public method. All private/protected methods work inside that lock.
Yes, it reduces performance in theory, especially if we do some heavy-lifting inside private/protected methods.
What do you think?

@SergeyGulik
Applied my locking rule of thumb: apply lock only in public methods
b52e282 
The only exception of this rule are private/protected methods running in a separate thread, which is not the case here.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers
No reviews
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
1 participant
@SergeyGulik