Results 1 to 13 of 13

Thread: Het versnellen van logging met TFilestream of TMemorystream

  1. #1
    John Kuiper
    Join Date
    Apr 2007
    Location
    Almere
    Posts
    8,747

    Het versnellen van logging met TFilestream of TMemorystream

    Ik maak nu gebruik van deze procedure om een logbestand weg te schrijven:
    Delphi Code:
    1. procedure TMyLog.Log(const Loglevel : byte; Msg : String);
    2. var StreamMessage : string;
    3.     FStream       : TFileStream;
    4.     LBuffer       : TBytes;
    5.     LByteOrderMark: TBytes;
    6.     LOffset       : Integer;
    7.     LEncoding, DestEncoding: TEncoding;
    8. begin
    9.   LEncoding:= TEncoding.unicode;
    10.   if LogLevel <= FMaxLogLevel then
    11.   begin
    12.     StreamMessage := format('%s [%s] %s',[Datumlog,FPrintnr,Msg]) + #13#10;
    13.     DestEncoding := TEncoding.UTF8;
    14.     SetLength(LBuffer, length(StreamMessage) * sizeof(char));
    15.     if StreamMessage <> '' then Move(StreamMessage[1], lbuffer[0], Length(lbuffer));
    16.     LOffset := TEncoding.GetBufferEncoding(LBuffer, LEncoding);
    17.     LBuffer := LEncoding.Convert(LEncoding, DestEncoding, LBuffer,
    18.                                    LOffset, Length(LBuffer) - LOffset);
    19.     if FileExists(FLogFile) then
    20.     begin
    21.       FStream := TFileStream.Create(FLogFile, fmOpenReadWrite or fmShareDenyNone);
    22.       FStream.Position := FStream.Size;
    23.     end
    24.     else
    25.       begin
    26.         FStream := TFileStream.Create(FLogFile, fmCreate or fmShareDenyNone);
    27.         LByteOrderMark := DestEncoding.GetPreamble;
    28.         // Write an encoding byte order mark and buffer to output file
    29.         FStream.Write(LByteOrderMark[0], Length(LByteOrderMark));
    30.       end;
    31.     try
    32.       FStream.Write(LBuffer[0], Length(LBuffer));
    33.     finally
    34.       FStream.Free;
    35.     end;
    36.   end;
    37. end;
    Werkt prima, maar erg vertragend. Telkens wordt er een bestand geopend, regel weggeschreven en weer afgesloten.
    Ik wil dit graag gaan versnellen, want gebruikers hebben een hekel aan wachten. Kan ik dit ombouwen naar een tmemorystream en periodiek / aan het einde van de log deze opslaan? Of kan ik de TFilestream op een of andere manier openlaten en regels wegschrijven, zodat aan het einde van de log deze wordt afgesloten?
    Delphi is great. Lazarus is more powerfull

  2. #2
    Woops. Daar doe je nogal wat met allerlei encodings.

    Was het niet makkelijker om TStreamWriter te gebruiken? Die heeft dat volgens mij allemaal intern in zich zitten.

    http://docs.embarcadero.com/products...eamWriter.html

    Tevens zit daar wat buffering in. Maar dan moet je natuurlijk niet elke keer openen en sluiten. Is het niet makkelijker die stream open te houden en alleen op sluiten of crash te sluiten?

  3. #3
    Ik denk dat het een stuk sneller gaat als je de filestream gewoon open houd en na het schrijven eventueel een flush geeft om te voorkomen dat je bij een crash logging mist
    FlushFileBuffers(fs.Handle);

  4. #4
    John Kuiper
    Join Date
    Apr 2007
    Location
    Almere
    Posts
    8,747
    Dat is ook de bedoeling. Deze constructie heb ik lang geleden gemaakt zodat er er geen regel verloren gaat.
    Is het dan niet handiger om gebruik te maken van tstrings en deze periodiek weg te laten schrijven. Nadeel hiervan is dat ik met een crash o.i.d. niet de volledige log heb,
    Delphi is great. Lazarus is more powerfull

  5. #5
    Quote Originally Posted by jkuiper View Post
    Is het dan niet handiger om gebruik te maken van tstrings en deze periodiek weg te laten schrijven. Nadeel hiervan is dat ik met een crash o.i.d. niet de volledige log heb,
    Juist omdat je bij een crash wel de log regels wilt hebben is dat natuurlijk niet handig

    Een TStringList moet je ook weer in geheugen houden. Bij een "klein" logbestand is dat misschien niet zo'n probleem. (zorg dan wel dat je die ook bij je exception-handler weg schrijft)

    Maar volgens mij werkt die TStreamWriter dan beter en dan hou je gewoon de file open (met af en toe een TStreamWriter.Flush ertussen).

  6. #6
    John Kuiper
    Join Date
    Apr 2007
    Location
    Almere
    Posts
    8,747
    Ik ga er naar kijken
    Delphi is great. Lazarus is more powerfull

  7. #7
    Fornicatorus Formicidae VideoRipper's Avatar
    Join Date
    Mar 2005
    Location
    Vicus Saltus Orientalem
    Posts
    5,708
    Ik log eigenlijk alleen om te kunnen debuggen ("Normale" logregels gaan gewoon naar een database)
    en daarvoor gebruik ik het good ol' TextFile; nooit snelheidsproblemen mee (maar nooit tot vele
    megabytes getest, dus wellicht geeft dat wel problemen).

    Delphi Code:
    1. const
    2.   FLogFile: string = 'MijnLog.log'; // of verzin een leuke (pad en) naam
    3.  
    4. procedure Log(AMsg: string);
    5. var
    6.   F: TextFile;
    7. begin
    8.   AssignFile(F, FLogFile);
    9.   try
    10.     if FileExists(FLogFile) then
    11.       Append(F)
    12.     else
    13.       Rewrite(F);
    14.  
    15.     WriteLn(F, AMsg);
    16.   finally
    17.     CloseFile(F);
    18.   end;
    19. end;

    Uiteindelijk doet een TFileStream ook soortgelijke disk I/O (maar dan over een heleboel extra lagen).
    TMemoryLeak.Create(Nil);

  8. #8
    John Kuiper
    Join Date
    Apr 2007
    Location
    Almere
    Posts
    8,747
    Ik merk dat met de "good old fashion way" een vertraging optreedt als je telkens opent / sluit. Dat zal ook wel de bottleneck zijn.
    Als debugging uitstaat is hetzelfde proces 3 keer sneller dan als deze aanstaat.
    Maar als je in memory werkt, zal dat proces versneld moeten worden.
    Delphi is great. Lazarus is more powerfull

  9. #9
    Die bottleneck krijg je, neem ik aan, toch met name als je heel veel logt, of logt naar een netwerk share ofzo. Bij 'normaal' gebruik zou je er toch niet zoveel van moeten merken?

    Overigens, kijk eens naar TFile (in System.IOUtils). Bestaat ook al een paar versies, maar maakt het schrijven naar files wel erg makkelijk. Bijvoorbeeld:

    Delphi Code:
    1. //Voegt de tekst in Text toe aan het eind van het bestand FileName.
    2. TFile.AppendAllText(FileName, Text);

    Delphi Code:
    1. //Geeft een streamwriter terug om mee te schrijven zoals rvk voorstelde.
    2. Writer := TFile.AppendText(FileName);

    Als het echt zo'n bottleneck is, dan zou ik m'n heil toch ergens anders zoeken. Het open laten staan van de file kan iets helpen. Meer winst haal je misschien door een aparte thread de log te laten schrijven, of zelfs door het uit te besteden aan een externe tool, zoals CodeSite, of EstLogger, of zelfs een cloud-oplossing als Splunk.
    Last edited by GolezTrol; 18-Apr-18 at 00:39.
    1+1=b

  10. #10
    Fornicatorus Formicidae VideoRipper's Avatar
    Join Date
    Mar 2005
    Location
    Vicus Saltus Orientalem
    Posts
    5,708
    Het probleem met logging is dat je moet kiezen tussen twee kwaden.

    Ofwel je logt met een hoge snelheid, met een verhoogd risico dat je logregels kwijtraakt
    wanneer een applicatie crashed, of je logt 99.9% betrouwbaar alle regels, maar daavoor
    moet je genoegen nemen met een lagere performance.

    Gelukkig hoef je niet altijd alles te loggen.
    Doorgaans wil je alleen tijdens ontwikkeling, testen en debuggen alles zoveel mogelijk
    loggen ("Trace", "Debug" of "Info") en dan is het snelheidsverlies geen issue en zet je
    tijdens "Normaal" gebruik het logniveau op een lager pitje ("Warn", "Error" of "Fatal").

    Je zou, als je echt snelheid wilt tijdens normaal gebruik, kunnen kijken of je het loggen
    via asynchrone weg naar een externe service oid zou kunnen doen.
    Deze service zorgt dan als buffer waar je alleen een bericht naar stuurt (dus zonder te
    wachten) waarna de service er vervolgens voor zorgt dat de logregel uiteindelijk op de
    juiste plaats terecht komt (bestand, database, ...).

    Er zullen vast mensen zijn die op dit onderwerp afgestudeerd zijn en er zijn waarschijnlijk
    ook al kant en klare oplossingen bedacht, maar ik heb tot op heden altijd genoeg gehad
    aan eenvoudige tekst-logging of loggen mbv tools als SmartInspect.
    TMemoryLeak.Create(Nil);

  11. #11
    John Kuiper
    Join Date
    Apr 2007
    Location
    Almere
    Posts
    8,747
    Dat is ook de reden dat in niveau's gebruik voor mij logs. Niveau 0 is uit en 3 is heavy.
    En dat is ook makkelijk in te stellen via een tabel.
    Maar de vertraging zit toch in het continue wegschrijven naar een bestand. Hoop dat op een iets snellere manier uit te voeren dan met mijn huidige logsysteem.
    Delphi is great. Lazarus is more powerfull

  12. #12
    Kan ook nog te maken hebben met de snelheid van je schijf, de lookup-tijd, en wat je applicatie verder aan het doen is. Als je hoofdproces bijvoorbeeld ook naar een bestand aan het schrijven is, en je logging schrijft naar een ander bestand, dan moet je schijf constant heen en weer springen om op een bepaalde plaats wat te schrijven. Dat springen kost relatief veel tijd, zeker als je een bewegend kopje hebt. Dat is ook de reden dat defragmentatie op een gegeven moment nodig is om de boel snel te laten werken.
    1+1=b

  13. #13
    mov rax,marcov; push rax marcov's Avatar
    Join Date
    Apr 2004
    Location
    Ehv, Nl
    Posts
    10,357
    Ik cache log regels (tot 1MB), maar flush elke paar seconden indien er wat is. En daarnaast ook extra als ik bepaalde code in en uitga.

    De blokken logregels worden verder dan naar een thread gestuurd die het eigenlijke schrijven doet. Deze simpele principes gaan erg goed, en de code is niet eens zo heel groot.

    De log() procedure zelf is daarnaast gespecificeerd als ansistring, scheelt weer in conversies.

Thread Information

Users Browsing this Thread

There are currently 1 users browsing this thread. (0 members and 1 guests)

Bookmarks

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •