Oplossing voor chaotische bug: volg orde.
Een goede software engineer is een probleemoplosser. Om problemen in software op te lossen, moet u een analyse van het probleem uitvoeren om de oorzaak te vinden. Veel programmeurs merken het moment dat de fout optreedt op, kijken eens naar de broncode, doen een gok naar de oorzaak en beginnen “in de code te hakken” om het te repareren. Hoewel ze vaak geluk hebben, zijn er enkele situaties waarin je echt, echt moet begrijpen wat er aan de hand is.
Vele jaren geleden werkte ik aan een applicatie die eerst een inlogvenster zou weergeven met een selectie voor welke server u mee wilt verbinden. De lijst met servers werd niet geladen vanuit een configuratiebestand of hard gecodeerd in de clienttoepassing. In plaats daarvan opende de applicatie een internet “socket” om te luisteren naar “broadcast” berichten die van de servers werden verzonden. Echter, af en toe zou de toepassing beginnen en onmiddellijk een foutmelding tonen en afsluiten, waarna de gebruiker de clienttoepassing opnieuw zou moeten starten voor een nieuwe poging. Dit is nu misschien geen groot probleem. Het zou de gebruiker slechts een paar seconden extra kosten om de foutmelding te sluiten en opnieuw te proberen. Omdat dit probleem zich slechts sporadisch voordeed, zou het meestal werken aan de tweede poging na het krijgen van deze fout.
Maar het probleem hiermee is.. Het is een symptoom van een dieper probleem. En dat maakt gebruikers nerveus. Voor een klant lijkt het erop dat de ontwikkelaars niet volledig de controle hebben over het product. Het is een fout die optreedt nadat de gebruiker de toepassing heeft gestart. Dus als je tijdens een demosessie wat pech hebt, is het eerste wat de potentiële klant zal zien een foutmelding en een crashtoepassing. Geen goede manier om een demo te beginnen. Voeg daar een paar databasefouten aan toe en een aantal andere (schijnbaar willekeurig voorkomende) kwaliteitsproblemen en sommige potentiële klanten kunnen gewoon een alternatief product van een concurrent kiezen.
Omdat ik in mijn werk vaak de clientapplicatie moest starten om de functionaliteit te testen die ik had toegevoegd of veranderd, kreeg ik een paar keer per week te maken met deze inlogfout, soms twee of drie keer per dag. Je kunt je voorstellen dat na enkele maanden op deze manier te hebben gewerkt, dit me echt begon te storen ;). Ik heb er een aantal collega’s naar gevraagd. Het bleek dat verschillende mensen er al naar hadden gekeken, maar niemand had het in enkele jaren kunnen oplossen. In hun verdediging is een fout die misschien maar twee of drie keer per dag gebeurt, erg moeilijk te analyseren, omdat de gemakkelijkste manier om de oorzaak van bugs te vinden is om ze te reproduceren en vervolgens onder de motorkap te kijken om te zien wat er in de broncode is gebeurd. Dit kan een aanwijzing geven over de oorzaak van de bug.
Deze specifieke bug, als het al gebeurde, hielp het nog niet veel om onder de motorkap te kijken naar de staat van de toepassing. Ten eerste zou iemand die het analyseert verschillende niveaus in functiecalls omhoog moeten gaan om erachter te komen dat het gebeurde omdat de applicatie probeerde een wijziging aan te brengen in het inlogvenster, terwijl het inlogvenster nog niet was gemaakt. Maar ok, toen ik dat eindelijk ontdekte, wist ik dat de fout op zijn minst legitiem was: de computer kan inderdaad geen verandering aanbrengen in een venster dat nog niet bestaat. Maar waarom bestaat het inlogvenster niet? Het moet op dat moment altijd bestaan. De willekeur ervan was erg vreemd.. Of het venster zou op dat moment nooit moeten bestaan (wat betekende dat het gewoon nog niet is gemaakt), of het zou altijd moeten bestaan. Dingen gebeuren niet zomaar in willekeurige volgorde in de uitvoering van een computerprogramma, tenzij je het expliciet programmeert om dat te doen. Deze willekeur moet dus een reden hebben.
Dit soort willekeur is wat wij ontwikkelaars een race-condition noemen. Twee processen “racen” om eerst een punt te bereiken. Afhankelijk van de situatie kan een dergelijke race-condition volledig onvoorspelbaar gedrag geven, of, zoals in mijn geval, slechts zeer zelden gebeuren.
Ik besloot om door de code te stappen waar het inlogvenster is gemaakt en wat te graven. De broncode van een programma is gestructureerd. We groeperen een aantal regels code die samen een zekere functionaliteit implementeren in wat we een functie noemen. En de ene functie kan een andere functie aanroepen. Op deze manier kunnen we een zeer ingewikkeld gedrag abstraheren achter een eenvoudige naam zoals “CreateLoginWindow”. Wanneer u een lopende toepassing pauzeert en onder de motorkap naar de status ervan kijkt, kunt u kijken naar welke functie de computer werd uitgevoerd toen de uitvoering werd onderbroken. U kunt ook zien welke functie de functie wordt genoemd die werd uitgevoerd en dus vele niveaus van functieaanroepen omhoog gaan. Dus plaatste ik een “scheidingspunt” op de functie die het daadwerkelijk maken van het inlogvenster deed en de applicatie uitgevoerd. Het breekpunt is een functie van de debugger (een tool die wij programmeurs gebruiken om een uitvoerende toepassing te analyseren) die het proces automatisch onderbreekt wanneer het wordt bereikt. Dus mijn debugger pauzeerde de applicatie op het moment dat het de daadwerkelijke aanmaak van het inlogvenster deed. Ik ging naar de “stapel”, die lijkt op een geschiedenis van alle functies die betrokken waren bij het bereiken van de huidige staat, en keek naar de code die leidde tot het maken van het inlogvenster. En toen zag ik iets als dit:
CreateUDPListenSocket();
CreateLoginWindow();
De eerste regel roept een functie aan die de creatie en setup van een zogenaamde “UDP listen socket” afhandelt, wat een soort “oor” op internet is dat “luistert” naar UDP (User Datagram Protocol) berichten (laten we zeggen berichten die verzonden kunnen worden zonder eerst een verbinding te maken). Deze functie “CreateUDPListenSocket” instrueerde de computer ook wat er moest gebeuren om zo’n bericht te verwerken wanneer het werd ontvangen. Nu is er op het eerste gezicht niets mis mee. Hoewel sommige ontwikkelaars die dit lezen het misschien al begrepen hebben. De eerste functie creëert de UDP socket en instrueert de computer wat er moet gebeuren wanneer een bericht wordt ontvangen en de tweede functie creëert het login venster. Deze twee functie calls stonden vlak naast elkaar. Hoe kan er nog iets anders gebeuren tussenin? De computer doet toch niet zomaar andere dingen tussendoor? Nou.. Ja, dat is normaal gesproken het geval.. Maar hier niet…
Laten we wat dieper duiken. De eerste functie instrueerde de computer gewoon wat te doen wanneer een bericht van de server werd ontvangen. Dus wat zou er gebeuren als zo’n UDP-bericht van de server werd ontvangen direct nadat het klaar was met de eerste functie, maar voordat de tweede functie werd uitgevoerd? Ja, als je dacht dat het zou proberen de naam en het adres van de server toe te voegen aan het inlogvenster, dan zou je gelijk hebben.. Maar wacht, als het dat doet voordat de tweede functie klaar is met het maken van het inlogvenster, veroorzaakt dat dan niet ons probleem? Ja, dat zou het inderdaad doen!
Oké, maar dat verklaart nog steeds niet waarom het dat doet tussen deze twee functieaanroepen, toch? Nou, er zijn zelfs meerdere manieren waarop er iets tussendoor kan worden gedaan. Eén manier is via iets dat een “interrupt service routine” wordt genoemd. De andere is omdat een applicatie uit meer dan één proces kan bestaan. Dergelijke processen die deel uitmaken van dezelfde applicatie en parallel worden uitgevoerd, worden “threads” genoemd. Wat er in dit geval zou gebeuren, is dat de applicatie een library (wat een set functies is die door meerdere applicaties gebruikt kunnen worden) gebruikte die een andere thread gebruikte om internetberichten te verwerken.
Op dit punt zouden sommige slimme lezers kunnen protesteren en zeggen dat er slechts nanoseconden zitten tussen de eerste functie en de tweede, zodat de kans dat dat serverbericht precies tussen die twee functieaanroepen wordt ontvangen, vrijwel nul is. Het zou niet verklaren hoe deze fout zo vaak kan optreden.
Ja, dat doet het wel! Het verklaart het wel. Al moet ik bekennen dat ik het eigenlijk wel eens ben met de sceptici. Maar die mensen die zeggen dat de tijd tussen het einde van de eerste functie en het begin van de tweede functie extreem kort is, hebben geen ongelijk. In ieder geval zou de tijd tussen het uitvoeren van deze twee functies GEWOONLIJK erg kort zijn, een miljoen keer sneller dan een oogwenk. Er bestaat echter zoiets in een computer als een “timeslice”. Computers zijn niet zo goed in het doen van meerdere dingen tegelijk. Dus doen ze alsof. Door heel snel te schakelen tussen het uitvoeren van twee processen, lijkt het alsof die processen tegelijkertijd worden uitgevoerd. Elk proces krijgt een klein beetje verwerkingstijd, een “timeslice” genoemd. Aan het einde van de timeslice pauzeert de computer het proces, slaat de informatie over de status op, laadt de informatie over de status van een ander proces en voert dat andere proces een tijdje uit. Als de timeslice direct na de eerste functieaanroep zou eindigen, maar vóór de tweede, dan zouden er zelfs meerdere milliseconden kunnen zijn waarin een serverbericht kan worden ontvangen en verwerkt.
Het is zelfs mogelijk dat de creatie van het loginvenster iets activeerde om gebeurtenissen te verwerken die op de achtergrond plaatsvonden voordat het venster daadwerkelijk werd gemaakt. Dat zou de actieve thread dan kunnen dwingen om te pauzeren, zodat andere achtergrondgebeurtenissen eerst konden worden verwerkt. En terwijl achtergrondgebeurtenissen werden verwerkt, zou dat UDP-bericht van de server kunnen worden ontvangen en verwerkt voordat het terugkeerde naar de thread die het loginvenster maakte.
Er zijn misschien nog een paar andere verklaringen die je zou kunnen bedenken die het waarschijnlijker maken dat het UDP-bericht van de server werd ontvangen en verwerkt tussen deze twee functieaanroepen. Hoe dan ook.. Ik heb de twee regels omgedraaid zodat het inlogvenster eerst werd gemaakt voordat de UDP-listensocket werd gemaakt. En daarna heb ik nooit meer van deze fout gehoord.
Er zit wel een kleine les in. Het kostte de oorspronkelijke auteur van deze code waarschijnlijk minder dan tien seconden om die twee regels te schrijven. Maar het op die manier schrijven, in die volgorde, kostte meerdere mensen meerdere jaren van omgaan met een bug die ze niet op konden lossen. En hoewel ik niet van elke ontwikkelaar verwacht perfecte broncode te produceren (we zijn tenslotte maar mensen), lijkt er hier sprake te zijn van enige onzorgvuldigheid. Zie je, de functie die de berichten van de servers verwerkt, is inherent afhankelijk van het inlogvenster. Daarom toont het maken van de UDP-listensocket en het vertellen aan de computer wat er moet gebeuren wanneer een server-broadcastbericht wordt ontvangen VOORDAT het inlogvenster wordt gemaakt, een gebrek aan nadenken over afhankelijkheden. Zulke afhankelijkheden zijn essentieel om te overwegen in softwareontwikkeling. Deze bug had gemakkelijk voorkomen kunnen worden door rekening te houden met de relatie die er tussen de twee bestaat. Dat ze oorspronkelijk in deze volgorde zijn gezet, suggereert dat de auteur de relatie niet begreep of er niets om gaf. Misschien realiseerde de auteur zich niet dat het proces onderbroken kon worden door een ontvangen bericht, maar zelfs dan nog.. Of het nu onderbroken kan worden of niet, het is nooit een goed idee om A te creëren vóór B als A afhankelijk is van B. Je moet altijd dingen in de juiste volgorde doen, want anders krijg je een chaos.