View Issue Details

IDProjectCategoryView StatusLast Update
0004570JEDI VCL00 JVCL Componentspublic2009-03-26 20:56
ReporterZENsanAssigned Tojfudickar 
PrioritynormalSeveritymajorReproducibilityalways
Status resolvedResolutionfixed 
Product VersionDaily / GIT 
Target VersionFixed in Version 
Summary0004570: JvSimpleXML or JclSimpleXML
DescriptionJvAppXMLStorage.Flush now works 100 times slower then one month before...
After I have installed latest daily packages my application after closing was hanging in processes with full cpu usage. After I debugged I found that it is working somewhere in JvSimpleXML.SaveToFile..->SaveToStream...
TagsNo tags attached.

Activities

ZENsan

2008-11-06 05:45

reporter   ~0014971

It works and all is ok. but this problem was not before. My AppXMLStorage xml file is sized aproximetly 1-2MB (differs from workstation to workstation)

jfudickar

2008-11-06 15:49

developer   ~0014973

I have the same problem, but i'm not able to figure it out.

I've tried to analyze with aqtime, but i was not so successfull.

I've attached some screenshots of aqtime statistics.

Any help is welcome :-)

Greetings
Jens

obones

2008-11-07 00:11

administrator   ~0014975

Can you guys try to find which revision in the JCL introduced this?

ZENsan

2008-11-07 04:46

reporter   ~0014979

JclSimpleXML: http://jcl.svn.sourceforge.net/viewvc/jcl/branches/JCL_1.103/jcl/source/common/JclSimpleXml.pas?view=log#rev2462

Revision 2462 (Broken - works 100x slower)
Modified Tue Sep 9 19:32:52 2008 UTC (8 weeks, 2 days ago) by outchy
support for Delphi 2009 and C++Builder 2009 with native Unicode support:
 - native Unicode support;
 - update to Unicode Character Database 5.1.0;
 - introduction of string streams with automatic conversions.

Revision 2460 (This works fine like old good..)
Modified Tue Sep 9 11:12:36 2008 UTC (8 weeks, 3 days ago) by outchy
preparation of the preview for Delphi 2009 and C++Builder 2009.

outchy

2008-11-07 05:37

administrator   ~0014980

Starting of this revision, JclSimpleXml is able to load XML files with various encoding (UTF8, UTF16, ANSI), the conversion functions are taking a lot of time there.
Maybe they could be fine tuned...

jfudickar

2008-11-07 08:28

developer   ~0014983

Hi Olivier,

it's not only the reading, the writing is realy slowly.

It can take more then a minute to write a file with 500k.

Greetings
Jens

USchuster

2008-11-07 11:28

manager   ~0014985

For the situation Delphi 2007 + Ansi Encoding TJclStringStream.PeekChar and TJclStringStream.ReadChar consume almost all of the time. I compared the reading speed of the current revision (2514) with revision 2293 and it is 3 times slower. With a very simple version of PeekChar and ReadChar (just read a byte + Chr) it was faster then revision 2293.

2008-11-07 13:57

 

flush_editor.png (291,447 bytes)

2008-11-07 13:58

 

loadbuffer_editor.png (156,139 bytes)
loadbuffer_editor.png (156,139 bytes)

2008-11-07 14:00

 

callgraph.png (147,674 bytes)
callgraph.png (147,674 bytes)

jfudickar

2008-11-07 14:00

developer   ~0014986

I've added now some of the screenshots from AQTime.

ZENsan

2008-11-07 23:43

reporter   ~0014987

Only 2462 revision started to work slowly. 2460 works perfect.

jfudickar

2008-11-10 14:10

developer   ~0014993

An other interesting point is: reading is much faster then writing.

AHUser

2008-11-10 14:35

developer   ~0014994

The main problem is that the JclStringStream is more busy converting byte sequences to UCS4 and back than reading/writing the actual data.

jfudickar

2008-12-03 16:13

developer   ~0015076

Does anyone has a chance to look into this ?

USchuster

2008-12-04 07:26

manager   ~0015083

I had a look at the writing issue and the problem is that TJclBufferedStream is not suitable for writing, because it always tries to load the buffer although there is nothing to load for a new file. Furthermore setting the BufferSize to 1 does not help, because the buffer starts at the last write position and TJclBufferedStream is trying to load a byte at the new position into the buffer, that fails and doesn't make sense, because the byte will be overwritten afterwards.

For the following example the speed with TJclBufferedStream is three times lower than using the TFileStream directly

var
  FS: TFileStream;
  BS: TJclBufferedStream;
  B: Byte;
  I: Integer;
begin
  FS := TFileStream.Create('Testfile', fmCreate);
  try
    BS := TJclBufferedStream.Create(FS, False);
    try
      B := 0;
      for I := 0 to 1048575 do
        BS.Write(B, 1);
    finally
      BS.Free;
    end;
  finally
    FS.Free;
  end;
end;

USchuster

2008-12-21 13:13

manager   ~0015123

The following change brings the write speed back, but I am not yet sure if this change is correct.

change

    if not BufferHit then
      LoadBuffer;

in TJclBufferedStream.Write in JclStreams.pas into

    if not BufferHit then
    begin
      if (FBufferStart <= FPosition) and (FPosition < (FBufferStart + FBufferSize)) then
      begin
        if Length(FBuffer) <> FBufferSize then
          SetLength(FBuffer, FBufferSize);
      end
      else
        LoadBuffer;
    end;

USchuster

2008-12-22 12:47

manager   ~0015175

I've committed the suggested JclStreams change from 0004570:0015123 as revision 2575.

Does this fix the write speed issue?

jfudickar

2009-01-10 05:24

developer   ~0015234

For me it looks much better now.

Thanks Uwe.

Issue History

Date Modified Username Field Change
2008-11-06 05:42 ZENsan New Issue
2008-11-06 05:45 ZENsan Note Added: 0014971
2008-11-06 15:49 jfudickar Note Added: 0014973
2008-11-07 00:11 obones Note Added: 0014975
2008-11-07 00:11 obones Status new => feedback
2008-11-07 04:46 ZENsan Note Added: 0014979
2008-11-07 05:37 outchy Note Added: 0014980
2008-11-07 08:28 jfudickar Note Added: 0014983
2008-11-07 11:28 USchuster Note Added: 0014985
2008-11-07 13:57 jfudickar File Added: flush_editor.png
2008-11-07 13:58 jfudickar File Added: loadbuffer_editor.png
2008-11-07 14:00 jfudickar File Added: callgraph.png
2008-11-07 14:00 jfudickar Note Added: 0014986
2008-11-07 23:43 ZENsan Note Added: 0014987
2008-11-10 14:10 jfudickar Note Added: 0014993
2008-11-10 14:35 AHUser Note Added: 0014994
2008-12-03 16:13 jfudickar Note Added: 0015076
2008-12-03 16:13 jfudickar Status feedback => acknowledged
2008-12-04 07:26 USchuster Note Added: 0015083
2008-12-21 13:13 USchuster Note Added: 0015123
2008-12-22 12:47 USchuster Note Added: 0015175
2008-12-22 12:47 USchuster Status acknowledged => feedback
2009-01-10 05:24 jfudickar Note Added: 0015234
2009-03-26 20:56 jfudickar Status feedback => resolved
2009-03-26 20:56 jfudickar Resolution open => fixed
2009-03-26 20:56 jfudickar Assigned To => jfudickar