#1 2015-01-27 06:35:39

ludydoo
Member
Registered: 2015-01-27
Posts: 17

Error on regression tests

Hi,

I have this error when I try to run the regression tests (See 2.8)

   Synopse mORMot Framework Automated tests
  ------------------------------------------


1. Synopse libraries

 1.1. Low level common:
  - System copy record: 22 assertions passed  545us
  - TRawUTF8List: 110,007 assertions passed  44.07ms
  - TDynArray: 1,027,709 assertions passed  120.64ms
  - TDynArrayHashed: 1,200,629 assertions passed  86.30ms
  - TObjectListHashed: 999,871 assertions passed  334.07ms
  - TObjectDynArrayWrapper: 167,501 assertions passed  14.31ms
  - Fast string compare: 7 assertions passed  293us
  - IdemPropName: 30 assertions passed  157us
  - Url encoding: 132 assertions passed  1.14ms
  - GUID: 9,007 assertions passed  3.67ms
  - IsMatch: 599 assertions passed  304us
  - Soundex: 35 assertions passed  262us
  - Numerical conversions: 1,115,346 assertions passed  233.29ms
  - crc32c: 30,030 assertions passed  68.70ms
      pas 25.24ms 236.3 MB/s fast 2.91ms 2.0 GB/s sse42 1.29ms 511.3 MB/s
  - Curr 64: 20,053 assertions passed  957us
  - CamelCase: 11 assertions passed  136us
  - Bits: 4,774 assertions passed  157us
  - Ini files: 7,004 assertions passed  13.93ms
  - UTF8: 81,128 assertions passed  948.53ms
  - Iso 8601 date and time: 36,015 assertions passed  4.17ms
  - Url decoding: 1,100 assertions passed  615us
  - Mime types: 23 assertions passed  605us
  - TSynTable: 875 assertions passed  3.29ms
  - TSynCache: 404 assertions passed  389us
  - TSynFilter: 1,005 assertions passed  2.58ms
  - TSynValidate: 677 assertions passed  1.00ms
  - TSynLogFile: 42 assertions passed  1.04ms
  Total failed: 0 / 4,814,036  - Low level common PASSED  1.89s

 1.2. Low level types:
  - RTTI: 58 assertions passed  749us
  - Url encoding: 200 assertions passed  1.03ms
  - Encode decode JSON: 302,513 assertions passed  103.14ms
  - Variants: 5 assertions passed  487us
  - Mustache renderer: 142 assertions passed  1.64ms
  - TDocVariant: 71,670 assertions passed  97.02ms
  - BSON: 245,048 assertions passed  2.60ms
  - TSynTableStatement: 205 assertions passed  421us
  Total failed: 0 / 619,841  - Low level types PASSED  212.80ms

 1.3. Big table:
  - TSynBigTable: 19,177 assertions passed  47.53ms
  - TSynBigTableString: 16,072 assertions passed  18.63ms
  - TSynBigTableMetaData: 475,563 assertions passed  1.14s
  - TSynBigTableRecord: 375,563 assertions passed  2.68s
  Total failed: 0 / 886,375  - Big table PASSED  3.89s

 1.4. Synopse PDF:
  - TPdfDocument: 4 assertions passed  4.66ms
  - TPdfDocumentGDI: 8 assertions passed  446.45ms
  Total failed: 0 / 12  - Synopse PDF PASSED  453.91ms

 1.5. Cryptographic routines:
  - Adler32: 1 assertion passed  728us
  - MD5: 1 assertion passed  573us
  - SHA1: 5 assertions passed  601us
  - SHA256: 5 assertions passed  571us
  - AES256: 16,815 assertions passed  355.82ms
  - RC4: 1 assertion passed  288us
  - Base64: 11,994 assertions passed  120.03ms
  - CompressShaAes: 1,683 assertions passed  2.02ms
  Total failed: 0 / 30,505  - Cryptographic routines PASSED  486.45ms

 1.6. Compression:
  - In memory compression: 12 assertions passed  300.38ms
  - GZIP format: 19 assertions passed  570.64ms
  - ZIP format: 54 assertions passed  1.71s
  - SynLZO: 3,006 assertions passed  85.28ms
  - SynLZ: 30,219 assertions passed  535.07ms
  Total failed: 0 / 33,310  - Compression PASSED  3.20s


2. mORMot

 2.1. File based:
  - Database direct access: 10,138 assertions passed  155.50ms
  - Virtual table direct access: 12 assertions passed  1.05ms
  - TSQLTableJSON: 111,074 assertions passed  81.88ms
  - TSQLRestClientDB: 615,200 assertions passed  10.45s
  - Regexp function: 6,016 assertions passed  36.60ms
  Total failed: 0 / 742,440  - File based PASSED  10.73s

 2.2. File based memory map:
  - Database direct access: 10,136 assertions passed  156.94ms
  - Virtual table direct access: 12 assertions passed  899us
  - TSQLTableJSON: 111,074 assertions passed  80.31ms
  - TSQLRestClientDB: 615,199 assertions passed  10.74s
  - Regexp function: 6,016 assertions passed  41.75ms
  Total failed: 0 / 742,437  - File based memory map PASSED  11.02s

 2.3. File based WAL:
  - Database direct access: 10,138 assertions passed  173.81ms
  - Virtual table direct access: 12 assertions passed  928us
  - TSQLTableJSON: 111,074 assertions passed  79.03ms
  - TSQLRestClientDB: 615,200 assertions passed  10.56s
  - Regexp function: 6,016 assertions passed  27.46ms
  Total failed: 0 / 742,440  - File based WAL PASSED  10.84s

 2.4. Memory based:
  - Database direct access: 10,136 assertions passed  150.38ms
  - Virtual table direct access: 12 assertions passed  624us
  - TSQLTableJSON: 111,074 assertions passed  80.41ms
  - TSQLRestClientDB: 683,507 assertions passed  9.02s
  - Regexp function: 6,016 assertions passed  28.91ms
  - RTree: 140,000 assertions passed  671.64ms
  Total failed: 0 / 950,745  - Memory based PASSED  9.96s

 2.5. Basic classes:
  - TSQLRecord: 80 assertions passed  521us
  - TSQLRecordSigned: 200 assertions passed  2.97ms
  - TSQLModel: 3 assertions passed  291us
  - TSQLRestServerFullMemory: 782,290 assertions passed  963.21ms
  Total failed: 0 / 782,573  - Basic classes PASSED  968.95ms

 2.6. Client server access:
  - TSQLHttpServer: 2 assertions passed  3.47ms
     using HTTP API 2.0
  - TSQLHttpClient: 3 assertions passed  17.08ms
     using TSQLHttpClientWinHTTP
  - HTTP client keep alive: 3,087 assertions passed  342.79ms
     4818 B, first 2.62ms, done 326.06ms i.e. 3066/s, aver. 326us, 14.3 MB/s
  - HTTP client multi connect: 3,087 assertions passed  303.33ms
     4818 B, first 477us, done 284.96ms i.e. 3509/s, aver. 284us, 16.4 MB/s
  - HTTP client encrypted: 3,087 assertions passed  332.61ms
     4818 B, first 356us, done 318.30ms i.e. 3141/s, aver. 318us, 14.6 MB/s
  - Named pipe access: 3,089 assertions passed  723.90ms
     4818 B, first 271.97ms, done 243.43ms i.e. 4107/s, aver. 243us, 19.2 MB/s
  - Local window messages: 3,088 assertions passed  32.31ms
     4818 B, first 69us, done 28.17ms i.e. 35492/s, aver. 28us, 165.9 MB/s
  - Direct in process access: 3,056 assertions passed  29.43ms
     4818 B, first 28us, done 22.98ms i.e. 43506/s, aver. 22us, 203.4 MB/s
  - HTTP several DB servers: 9,604 assertions passed  1.38s
     4818 B, first 533us, done 284.53ms i.e. 3514/s, aver. 284us, 16.4 MB/s
     4818 B, first 608us, done 445.60ms i.e. 2244/s, aver. 445us, 10.4 MB/s
     4818 B, first 621us, done 458.62ms i.e. 2180/s, aver. 458us, 10.1 MB/s
  Total failed: 0 / 28,103  - Client server access PASSED  3.18s

 2.7. Service oriented architecture:
  - Weak interfaces: 56 assertions passed  1.30ms
  - Service initialization: 243 assertions passed  4.75ms
  - Direct call: 589,701 assertions passed  43.89ms
  - Server side: 589,720 assertions passed  23.65ms
  - Client side REST: 589,725 assertions passed  386.71ms
  - Client side REST result as object: 589,719 assertions passed  381.94ms
  - Client side REST locked: 589,722 assertions passed  387.39ms
  - Client side REST synchronized: 589,722 assertions passed  6.51s
  - Client side REST background thread: 589,722 assertions passed  3.26s
  - Client side REST weak authentication: 589,719 assertions passed  390.45ms
  - Client side http basic authentication: 589,719 assertions passed  498.01ms
  - Client side REST custom record layout: 589,719 assertions passed  397.41ms
  - Client side JSONRPC: 589,719 assertions passed  433.01ms
  - Test over HTTP: 10,130 assertions passed  832.02ms
  - Security: 135 assertions passed  1.14ms
  - Mocks and stubs: 30,031 assertions passed  38.04ms
  Total failed: 0 / 6,527,502  - Service oriented architecture PASSED  13.61s

 2.8. External database:
  - TQuery: 2,003 assertions passed  5.18ms
  - SynDBRemote: 30,095 assertions passed  299.58ms
  - External records: 2 assertions passed  486us
  - Auto adapt SQL: 543 assertions passed  30.76ms
  - Crypted database: 253,275 assertions passed  138.16ms
[ins]
!  - External via REST: 21,893 / 170,353 FAILED  1.05s
!  - External via virtual table: 21,893 / 170,353 FAILED  1.51s
!  - External via REST with change tracking: 22,904 / 180,453 FAILED  2.23s
  - JET database: 7,007 assertions passed  798.29ms
  Total failed: 66,690 / 814,084  - External database FAILED  6.08s
[/ins]

 2.9. Multi thread process:
  - Create thread pool: 1 assertion passed  5.63ms
  - TSQLRestServerDB: 4,822 assertions passed  88.42ms
     1=18272/s  2=41814/s  5=36559/s  10=42996/s  30=25054/s  50=35984/s
  - TSQLRestClientDB: 4,822 assertions passed  134.98ms
     1=46077/s  2=39757/s  5=39024/s  10=39169/s  30=13662/s  50=6858/s
  - TSQLRestClientURINamedPipe: 2,412 assertions passed  1.63s
     1=1105/s  2=1200/s  5=544/s
  - TSQLRestClientURIMessage: 3,222 assertions passed  338.54ms
     1=4027/s  2=6994/s  5=6397/s  10=3645/s
  - TSQLHttpClientWinHTTP_HTTPAPI: 4,820 assertions passed  432.18ms
     1=2713/s  2=6608/s  5=5561/s  10=9225/s  30=8410/s  50=8942/s
  - TSQLHttpClientWinSock_WinSock: 4,822 assertions passed  334.27ms
     1=12542/s  2=11113/s  5=6520/s  10=8075/s  30=5537/s  50=5559/s
  - Locked: 4,822 assertions passed  105.70ms
     1=46339/s  2=39706/s  5=40596/s  10=38077/s  30=13645/s  50=13538/s
  - Unlocked: 4,821 assertions passed  98.36ms
     1=45714/s  2=21572/s  5=20623/s  10=34231/s  30=34671/s  50=20134/s
  - Background thread: 4,821 assertions passed  204.73ms
     1=21349/s  2=17585/s  5=10390/s  10=10316/s  30=16384/s  50=7480/s
  - Main thread: 4,818 assertions passed  171.14ms
     1=39404/s  2=22253/s  5=8532/s  10=10049/s  30=19415/s  50=15063/s
  Total failed: 0 / 44,203  - Multi thread process PASSED  3.56s


Using mORMot 1.18.752 FTS3
Running on wSeven_64 with code page 1252
TSQLite3LibraryStatic running 3.8.8.1 with internal MM
Generated with: Delphi XE5 compiler

Time elapsed for all tests: 80.17s
Tests performed at 2015-01-27 01:16:54

Total assertions failed for all test suits:  66,690 / 17,758,606
! Some tests FAILED: please correct the code.

Done - Press ENTER to Exit

Offline

#2 2015-01-27 07:46:35

ab
Administrator
From: France
Registered: 2010-06-21
Posts: 14,182
Website

Re: Error on regression tests

On our side, every tests do pass with XE4 and XE7.

What is the error line?
The stack trace?
The exact test involved?
The data on disk?

Offline

#3 2015-01-30 18:50:50

ludydoo
Member
Registered: 2015-01-27
Posts: 17

Re: Error on regression tests

I run windows on a MAC using bootcamp. Maybe that changes something with the internal clock ?

Error lines :
Check(RExt.CreatedAt<=Updated);(SynSelfTests.pas #9231)
Check(RExt.CreatedAt<=Updated); (SynSelfTests.pas #9254)

Fails for tests

!  - External via REST: 21,893 / 170,353 FAILED  1.05s
!  - External via virtual table: 21,893 / 170,353 FAILED  1.51s
!  - External via REST with change tracking: 22,904 / 180,453 FAILED  2.23s

I can't really copy the stack trace, I don't have a tool for that...

What do you mean by data on disk ?

Offline

#4 2015-01-30 19:05:21

ludydoo
Member
Registered: 2015-01-27
Posts: 17

Re: Error on regression tests

Concerning the clock, I've previously set HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\TimeZoneInformation\RealTimeIsUniversal = 1 to fix some clock synchronization problem between Osx and Windows.

Offline

#5 2015-01-30 22:07:32

ab
Administrator
From: France
Registered: 2010-06-21
Posts: 14,182
Website

Re: Error on regression tests

So Now/NowUTC functions did return a value < another value returned at a previous call?
Pretty weird...
But I guess this is not a mORMot problem...

At which time did it occur?
It may be a TDateTime <-> TTimeLog conversion issue.

Offline

#6 2015-02-01 14:25:35

ludydoo
Member
Registered: 2015-01-27
Posts: 17

Re: Error on regression tests

I'm not sure it is with synopse. I formatted my HDD and reinstalled Windows 8.1. Reinstalled RAD Studio XE7. Now, I have the same errors on regression tests + TPdfDocument (Test 1.4). Could it be because I'm running on a MacBook with Bootcamp ?

Offline

#7 2015-02-01 14:30:54

ludydoo
Member
Registered: 2015-01-27
Posts: 17

Re: Error on regression tests

PDF error occurs at SynSelfTests.pas 7387 : Check(Hash32(MS.Memory,MS.Position)=Hash[embed]);

Value of CreatedAt : 135228614414
Value of Updated : 135228593934

Offline

#8 2015-02-01 17:35:34

ab
Administrator
From: France
Registered: 2010-06-21
Posts: 14,182
Website

Re: Error on regression tests

OK.
The values you are transmitting were the following:

CreateAt: 2015-02-01T14:28:14
Updated: 2015-02-01T09:28:14

So there is exactly a 5 hours switch between the two.
I guess this is your time zone with GMT/UTC, right?
Sounds like if Updated := aExternalClient.ServerTimeStamp retrieved the local time, not the GMT time.
It is weird, because TSQLRest.GetServerTimeStamp uses NowUTC on both client and server side.

Offline

#9 2015-02-01 18:09:03

ab
Administrator
From: France
Registered: 2010-06-21
Posts: 14,182
Website

Re: Error on regression tests

For the PDF I suspect this is because your code page is not 1252 any more.

I think I found the root cause of the TTimeLog wrong values.
In fact, TSQLRestStorageExternal.Create do change the server time stamp from the one retrieved from the DB:

  // try to connect to the remote DB, and synchronize local Rest time
  if Owner<>nil then
    try
      Owner.ServerTimeStamp := fProperties.ThreadSafeConnection.ServerTimeStamp;
    except
      on E: Exception do ; // ignore any error here
    end;

This was a totally wrong idea.
It worked in our case (i.e. France is UTC+01), but not if the time zone is BEFORE UTC, as in your case is UTC-05!

So I get rid of the whole block.
See http://synopse.info/fossil/info/9355b61606
The reference clock will be the ORM server clock, not the DB clock.
It would be much consistent.

Sorry for the issue!

Offline

#10 2015-02-02 14:14:37

warleyalex
Member
From: Sete Lagoas-MG, Brasil
Registered: 2013-01-20
Posts: 250

Re: Error on regression tests

Timezone settings is really an issue. If I set to Europe/Paris, everything is finally green!
Tested at Win/Linux

Using mORMot 1.18.772 PRTL FTS3
Running on Linux 3.13.0-44-generic #73-Ubuntu SMP Tue Dec 16 00:23:46 UTC 2014
TSQLite3LibraryDynamic running 3.8.8.2 with internal MM
Generated with: Kylix 3 compiler
Tests performed at 02-02-2015 15:09:05

Total assertions failed for all test suits:  0 / 15,074,289
! All tests passed successfully.

2.8. External database:
  - TQuery: 2,003 assertions passed  29.93ms
  - SynDBRemote: 20,063 assertions passed  5.45s
  - External records: 2 assertions passed  401us
  - Auto adapt SQL: 543 assertions passed  170.40ms
  - Crypted database: 176,192 assertions passed  583.67ms
  - External via REST: 170,353 assertions passed  63.96s
  - External via virtual table: 170,353 assertions passed  70.09s
  - External via REST with change tracking: 180,453 assertions passed  71.64s
  Total failed: 0 / 719,962  - External database PASSED  211.95s

I don't understand why the tests External DB performed at linux environment, take so long time.

Last edited by warleyalex (2015-02-02 14:19:43)

Offline

#11 2015-02-02 20:18:55

ab
Administrator
From: France
Registered: 2010-06-21
Posts: 14,182
Website

Re: Error on regression tests

I suspect this is some #pragma about off/exclusive mode was not activated for the test...
I did not have time to investigate yet.

Offline

#12 2015-02-03 18:25:15

ludydoo
Member
Registered: 2015-01-27
Posts: 17

Re: Error on regression tests

Hi, Thanks for replying so quickly. And yes indeed, timezones are such a pain! I will run regression tests and will inform you of the results.

Offline

Board footer

Powered by FluxBB