[C#] Concurrency probleem

[Brains]

Hallo,

In een applicatie loop ik tegen een vreemd probleem aan. De applicatie heeft een loop (timer) waarin elke 30 seconden de huidige instellingen worden gecontroleerd en indien nodig worden bijgesteld. Echter na verloop van tijd, tot nu toe altijd pas na één of meer dagen, ontstaat er een “knipperende” instellingswaarde.
Na het afsluiten en opnieuw opstarten van de applicatie loop alles weer zoals gewenst.

In de code heb ik een singleton controller met daarin de huidige instellingen en een timer. De klasse met instellingen heeft een int? als Id, deze is volgens de documentatie _niet_ thread safe.

C#:

class Settings
{
    public int? Id {get; set;}
...
}

public class Controller
{
        private static volatile Controller mInstance;
        private static object mSync = new Object();
        private System.Timers.Timer mTimer;

        private Controller()
        {
            mTimer = new Timer…
        }

        public static Controller Instance
        {
            get
            {
                lock (mSync)
                {
                    if (mInstance == null)
                    {
                        mInstance = new Controller ();
                    }
                }
                return mInstance;
            }
        }

        public Settings CurrentSettings {get; set;}
...

        void mTimer_Elapsed(object sender, ElapsedEventArgs e)
        {
                int lValue = 0;
                if (CurrentSettings != null)
                {
                    if (CurrentSettings.Id.HasValue)
                    {
                        lValue = CurrentSettings.Id.Value;
                    }
                }
               // write lValue
        }
}

Na verloop van tijd zie ik helaas “geknipper” bij het schrijven van de instellingen: elke 30 sec zie ik de waarde wisselen (om en om) tussen 0 en X, waarbij X de ingestelde waarde is. De instelling zelf is niet veranderd en dat vind ik dus het vreemde.

Nu heb ik zelf de 0 hard als default value staan, maar in elapsed event zouden de CurrentSettings en CurrentSettings.Id gezet moeten zijn. Dat zijn nu nog de enige twee punten waar ik geen log-traces heb staan, die komen in de eerst volgende versie, dus ik weet niet welke van de twee vergelijkingen onwaar oplevert.

Er is geen tweede instantie van de singleton die op de achtergrond ligt de irriteren. Dit heb ik gecontroleerd door een log-entry te maken bij het instantieren van de controller.
Wat ik wel zie is dat de elapsed event van de timer(soms) 2x wordt getriggerd, zo’n 500ms achter elkaar. Maar dat is maar heel sporadisch.

De CurrentSettings worden eenmalig gezet en inhoudelijk niet veranderd. Wel kunnen er andere settings worden geselecteerd, mogelijk met Id=null (default settings).


Nu ben ik het spoor bijster en weet niet waar het probleem vandaan kan komen. Het vreemde vind ik het geknipper, zonder iets te doen wisselt de instellingswaarde. Maar als in de vergelijking de waarde hard op 0 zet (laat staan), door het niet kunnen opvragen de Id, is het de volgende event weer goed.

Heeft iemand een handvat of een verwijzing waar ik de oorzaak van dit probleem kan achterhalen?

[SaphuA]

.

[ Voor 99% gewijzigd door SaphuA op 31-01-2022 15:52 ]

[Nibble]

Ik ben javaan en geen c#er, maar kan het misschien zo zijn dat je waarde bij //write 0 is omdat current setting ergens null wordt gemaakt? Of omdat dit ergens met een thread op de achtergrond gebeurt?
Kun je een breakpoint zetten op lijn 41 en de variabelen inspecteren op het moment dat het gebeurt?

[Brains]

@SaphuA
Met een backgroundworker zou het ook mogelijk zijn, alleen daar zou ik dan de rustperiodes zelf moeten bepalen mbv sleep-commando's.

@Nibble
Het stukje code in de topic-start is een voorbeeldje dat overeenkomt de code waar het fout in gaat. Helaas kan ik het probleem niet reproduceren en treedt het niet direct op maar pas naar een dag/dagen.
Daarnaast schakelt het niet om naar fouttieve waarden, maar toggelt het tussen "leeg" (fout) en geselecteerde instellingen.
Op mijn werkstation schrijf ik tot nu toe nog altijd de gewenste waarden.

[Nibble]

Ik zou proberen te achterhalen waar dat dat allemaal kan gebeuren dat of CurrentSetting op op null gezet kan worden, of CurrentSettings.Id.Value gewijzigd wordt in 0, of CurrentSettings.Id.HasValue false kan worden en proberen terug te redeneren. (ik weet het, het blijven open deuren, maar het kan niet anders zo lijkt het). Of misschien een logger gebruiken die statussen wegschrijft van objecten als dat gebeurt (zeker als het incidentieel is en je geen breakpoints kunt gebruiken om te debuggen).

[pedorus]

Geen idee wat hier aan de hand is, omdat ik vrees dat de relevante code ontbreekt.

Ik zou in ieder geval hier kijken hoe je een Singleton implementeert. Tussen regel 39 en 40 kan settings op null worden gezet, wat met bijv. een hulpvariabele kan worden voorkomen, zelfde met Id tussen 41 en 43, hiervoor zou ik gewoon .GetValueOrDefault() gebruiken.

Id bestaat intern uit een bool en een int, GetValueOrDefault() vraagt de value op zonder de bool te checken, en bij hasValue=false staat deze op 0 voor een int. Als je strikt gezien de documentatie volgt, dan zou je hier waarschijnlijk wel een lock moeten gebruiken omdat ik het niet terug kan vinden in de documentatie. Als je een andere default dan 0 wil hebben, dan is een lock zeker nodig, omdat je 0 kan terugkrijgen ipv de vorige value.

[Zoijar]

oh het is alleen na een paar dagen

[ Voor 79% gewijzigd door Zoijar op 06-12-2011 14:16 ]

[Grijze Vos]

Je singleton implementatie klopt niet. Hierdoor kun je 2 instanties van je class tegelijkertijd hebben lopen. Ik kan me best voorstellen dat het verschil tussen die 2 instanties in tijd na enkele dagen zichtbaar verschil oplevert.

[Brains]

@Nibble
Ik heb alle "setters" al afgelopen. CurrentSettings wordt op twee plaatsen gezet (bij initialisatie en bij een confirm van de gebruiker). De Id wordt alleen gezet bij ophalen van de instellingen uit de database.
Ik hoop op de goude schop die mij het zetje geeft.
Alle schrijfacties worden op dit moment gelogt, wijzigingen niet. Ik heb nu twee log-entries toegevoegd op de null- en hasvalue-check. Verder heb ik een VM aangezet met dezelfde software en remote-debugging-tools. Nu hopen op hetzelde probleem.

@pedorus
Ik krijg geen excepties op de regels 39-42, maar het kwaad is daarvoor al geschied.

@pedorus & @Grijze vos
Mijn singleton implementatie lijkt sterk op de Multithreaded Singleton uit link van pedorus, alleen wordt er vaker een lock gebruikt op runtime.
Maar de creatie van de singleton zie ik maar één keer terug in mijn de logs.

@Zoijar
Gister heb ik het probleem voor een tweede keer opgemerkt. Nu wat check die ik van buitenaf kan doen heb ik de applicatie opnieuw opstart en deze draait tot nu weer zonder zijeffect.

Let op: de klasse controller is niet static gedefineerd. Dit heb ik nu aangepast in de topicstart.

[ Voor 14% gewijzigd door Brains op 06-12-2011 14:47 ]

[pedorus]

Grijze Vos schreef op dinsdag 06 december 2011 @ 14:18:
Je singleton implementatie klopt niet. Hierdoor kun je 2 instanties van je class tegelijkertijd hebben lopen. Ik kan me best voorstellen dat het verschil tussen die 2 instanties in tijd na enkele dagen zichtbaar verschil oplevert.

Lijkt me sterk, hoe dan? Hij klopt wel, het is alleen een beetje jammer om niet gewoon de standaard-methode te gebruiken (dus methode 2 uit het gelinkte artikel).

Brains schreef op dinsdag 06 december 2011 @ 14:32:
@pedorus
Ik krijg geen excepties op de regels 39-42, maar het kwaad is daarvoor al geschied.

De kans is ook erg klein dat het daar fout gaat (hoewel er dus wel een theoretisch probleem zit).

Wat het probleem is kunnen we zo niet echt zien. Wat bijvoorbeeld zou kunnen is dat je ene timer nog niet afgelopen is, voordat de andere begint, en je daar geen rekening mee houdt.

quote: http://msdn.microsoft.com.../system.timers.timer.aspx

If the SynchronizingObject property is Nothing, the Elapsed event is raised on a ThreadPool thread. If processing of the Elapsed event lasts longer than Interval, the event might be raised again on another ThreadPool thread. In this situation, the event handler should be reentrant.

[Cobalt]

Waarom implementeer je niet het Observable pattern? Je instellingen geven dan een notify wanneer er iets veranderd is.

[ Voor 13% gewijzigd door Cobalt op 06-12-2011 15:27 ]

[Brains]

We maakte eerst gebruik van de eerste methode en toen werden er wel eens twee instanties gemaakt. Vandaar dat we nu gebruik maken van optie 3 (uit het artikel, Multithreaded Singleton).

Heb nu als test een volgend stukje geimplementeerd:

C#:

            int lSync = Interlocked.CompareExchange(ref mSyncPoint, 1, 0);
            if (lSync == 0)
            {
                Thread.CurrentThread.Name = string.Format("Timer, started at {0}", DateTime.Now);
                ...
                mSyncPoint= 0;
            }
            else
            {
                Log.Info("Skipped elapsed event.");
            }

Zodat er maar één schrijfactie tegelijk uitgevoerd kan worden, echter kunnen wel clycli worden gemist.

[Brains]

@Cobalt
De instellingen komen uit een database en worden aan een "overzicht" ge-bind. Dan worden de velden met bindings aan de properties gebonden.
In de loop worden de instellingen van dat moment naar de serielepoort gestuurd. Wat er weggeschreven wordt is afhankelijk van wat er ingelezen is.
Daarnaast zit er aan de andere kant een "dom" apparaat en dat willen ze nog wel eens resetten. Vandaar dat we besloten hebben om geforceerd en cyclisch de data te sturen. Als we aan de pc-kant geen wijzigingen hebben dan wordt er niets weggeschreven, alleen een loze slag.

[pedorus]

Brains schreef op dinsdag 06 december 2011 @ 15:26:
We maakte eerst gebruik van de eerste methode en toen werden er wel eens twee instanties gemaakt. Vandaar dat we nu gebruik maken van optie 3 (uit het artikel, Multithreaded Singleton).

Maar in jouw situatie wordt optie 2 juist aanbevolen

Heb nu als test een volgend stukje geimplementeerd:

Let op dat je hier waarschijnlijk een threadpool-thread hernoemd; deze thread wordt steeds gerecycled. Het lijkt me ook niet netjes om iets eraan te veranderen.

[Brains]

Dan is dat toentertijd niet helemaal goed overkomen en is voor de variant gekozen waar de naam het meeste raakvlak had.

De naam van de thread heb ik hernoemd zodat deze door log4net wordt weergeven als mensvriendelijke naam

[Verwijderd]

Waarom moet je elke X seconden checken of een waarde veranderd is?

Ik ken de context van het probleem niet, maar als ik op de hoogte gehouden wil worden van veranderingen, gebruik ik meestal events.

schrijf je setter zo, dat als de nieuwe waarde anders is als de huidige, dat deze een (async) event triggered.

Kunnen de settings extern van je programma aangepast worden (bijv. in een bestand), dan zou je ook een FileSystemWatcher kunnen gebruiken.

[Brains]

Een kleine update...

Na een tweetal dagen dagen testen is het probleem niet voorkomen. Na wat te spelen met de applicatie trad het probleem in eens op. Ik heb nu een iets beter handvat om verder te kijken, echter het lijkt in de ThreadPool thread van de timer te zitten: race condidion.

... a race condition can appear much more rarely and be intermittent once a minute, once an hour, or appear three days later. The race is probably the programmer's worst nightmare because of its infrequency and because it can be very very hard to reproduce.

De timer wordt inderdaad op basis van de uitgelezen waarden gestart of gestopt. Ik heb één keer kunnen reproduceren, maar nu lukt het niet meer. Ik ga verder zoeken naar het race probleem.

@Skafa
Op het apparaatje zitten ook wat knopjes waarmee de instellingen te veranderen zijn.

Even if SynchronizingObject is not null, Elapsed events can occur after the Dispose or Stop method has been called or after the Enabled property has been set to false, because the signal to raise the Elapsed event is always queued for execution on a thread pool thread. One way to resolve this race condition is to set a flag that tells the event handler for the Elapsed event to ignore subsequent events.

Bij een start/stop kan ik dus een bool hoog/laag zetten en met een if constructie in elapsed event kijken of de code uitgevoerd mag worden of niet.

Update:
Het blijkt inderdaad in de timer te zitten en niet in de singleton. Ik het een stukje code geschrijven wat excessief de timer-loop (extern) laat starten en stoppen. Nu zie ik mijn ingestelde waarde "knipperen" qua schrijfacties. Wat ook opvalt is dat er elapsed-events gestart worden zowaar gelijktijdig als met secondes ertussen, wat volgens het interval 30sec zou moeten zijn. Het duidt dus op een "race condition" ism de timer.

De software heb ik nu zo aangepast dat: er maar één thread de kritieke sectie in mag, anders wordt de actie overgeslagen (Interlocked.CompareExchange). Daarnaast wordt er een vlag bijgehouden of de timer actief is of niet, zo ja dan mag er de kritieke sectie in worden geggaan.

[ Voor 45% gewijzigd door Brains op 08-12-2011 13:36 ]