Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

isc_segstr_eof not set in first call to isc_get_segment() [CORE6184] #6429

Open
firebird-automations opened this issue Nov 9, 2019 · 7 comments

Comments

@firebird-automations
Copy link
Collaborator

Submitted by: Cris Doorn (cris)

When you read a blob and all data is returned in the first call to isc_get_segment(), both the returned status and the status_vector[1] remain 0.

Since most people will keep reading the blob-data while the status equals 0 or the vector equals isc_segment, like this:

while (blob_stat == 0 || status_vector[1] == isc_segment) {
isc_get_segment()
}

a second call to isc_get_segment() is made. This second time it does indeed return isc_segstr_eof in status_vector[1].

Although this might seem totally harmless, it really isn't because it affects the performance very badly.
The second call to isc_get_segment(), returning no data at all, thus only returning isc_segstr_eof, is far more slower than the first call to isc_get_segment().

By using the actual blob size retrieved with isc_blob_info(), the read loop can be modified so that it stops reading when all data is retrieved.
This prevents the extra, very slow, call to isc_get_segment()

To give an impression of the impact, we'll fetch 1000 rows with each 2 small blobs subtype 1.

The original code with 2 calls to isc_get_segment() for each blob, took 7575 ms
After removing the second call to isc_get_segment(), it only took 448 ms.

Without the extra call, the code runs about 17 times faster!

Returning the isc_segstr_eof directly in the first call when all data is returned seems like the fastest solution to me.
This also prevents a second round trip over the network.
Fixing the reason why the second call is so much slower might also be great.

@firebird-automations
Copy link
Collaborator Author

Commented by: @aafemt

You are suggesting to break every application that use code like

repeat

until not (isc_get_segment() in [0, isc_segment]));

That's not good.

@firebird-automations
Copy link
Collaborator Author

Commented by: Cris Doorn (cris)

No I don't, when all data is read, and isc_segstr_eof is returned it exits your repeat-until loop after the first call to isc_get_segment().
When all data is retrieved you are done reading. There is no point in a second call to isc_get_segment() which only returns sc_segstr_eof.

@firebird-automations
Copy link
Collaborator Author

Modified by: Sean Leyne (seanleyne)

description: When you read a blob and all data is returned in the first call to isc_get_segment(), both the returned status and the status_vector[1] remain 0.

Since most people will keep reading the blob-data while the status equals 0 or the vector equals isc_segment, like this:

while (blob_stat == 0 || status_vector[1] == isc_segment) {
isc_get_segment()
}

a second call to isc_get_segment() is made. This second time it does indeed return isc_segstr_eof in status_vector[1].

Although this might seem totally harmless, it really isn't because it affects the performance very badly.
The second call to isc_get_segment(), returning no data at all, thus only returning isc_segstr_eof, is far more slower than the first call to isc_get_segment().

By using the actual blob size retrieved with isc_blob_info(), the read loop can be modified so that it stops reading when all data is retrieved.
This prevents the extra, very slow, call to isc_get_segment()

To give an impression of the impact, we'll fetch 1000 rows with each 2 small blobs subtype 1.

The original code with 2 calls to isc_get_segment() for each blob, took 7575 ms
After removing the second call to isc_get_segment(), it only took 448 ms.

Without the extra call, the code runs about 17 times faster!

Returning the isc_segstr_eof directly in the first call when all data is returned seems like the fastest solution to me.
This also prevents a second round trip over the network.
Fixing the reason why the second call is so much slower might also be great.

Kind regards,
Cris

=>

When you read a blob and all data is returned in the first call to isc_get_segment(), both the returned status and the status_vector[1] remain 0.

Since most people will keep reading the blob-data while the status equals 0 or the vector equals isc_segment, like this:

while (blob_stat == 0 || status_vector[1] == isc_segment) {
isc_get_segment()
}

a second call to isc_get_segment() is made. This second time it does indeed return isc_segstr_eof in status_vector[1].

Although this might seem totally harmless, it really isn't because it affects the performance very badly.
The second call to isc_get_segment(), returning no data at all, thus only returning isc_segstr_eof, is far more slower than the first call to isc_get_segment().

By using the actual blob size retrieved with isc_blob_info(), the read loop can be modified so that it stops reading when all data is retrieved.
This prevents the extra, very slow, call to isc_get_segment()

To give an impression of the impact, we'll fetch 1000 rows with each 2 small blobs subtype 1.

The original code with 2 calls to isc_get_segment() for each blob, took 7575 ms
After removing the second call to isc_get_segment(), it only took 448 ms.

Without the extra call, the code runs about 17 times faster!

Returning the isc_segstr_eof directly in the first call when all data is returned seems like the fastest solution to me.
This also prevents a second round trip over the network.
Fixing the reason why the second call is so much slower might also be great.

@firebird-automations
Copy link
Collaborator Author

Commented by: @hvlad

Let read IB6 ApiGuide for isc_get_segment() description:

p.360

When isc_get_segment() reads the last segment of the Blob, the function returns the code isc_segstr_eof.

p.361

Return Value
isc_get_segment() returns the second element of the status vector. Zero indicates success.
isc_segment indicates the buffer is not large enough to hold the entire current segment; the next call to
isc_get_segment() gets the next chunk of the oversized segment rather than getting the next segment.
isc_segstr_eof indicates that the last segment of the Blob has been read.

So, it seems Cris is correct here and we could improve things a bit.

What is not clear for me is:
---
To give an impression of the impact, we'll fetch 1000 rows with each 2 small blobs subtype 1.

The original code with 2 calls to isc_get_segment() for each blob, took 7575 ms
After removing the second call to isc_get_segment(), it only took 448 ms.
---

Cris, could you provide your test case for investigation ?

@firebird-automations
Copy link
Collaborator Author

Commented by: Cris Doorn (cris)

Sure I want to help. I think it should be easy to reproduce however.

I found this bug while investigating the great difference in fetch time when using UTF8 encoding or no encoding in FireDac (Delphi).
https://quality.embarcadero.com/browse/RSP-26607

I found out that a small bug in FireDac caused a second call to isc_get_segment() for each blob to be fetched.
Below is the original code, enabling/disabling UTF8 makes 'National' either true or false.
When true, the number of bytes to be read (ABuffLen) is doubled, causing a second call to isc_get_segment().

if National and (ABuffLen > 0) then begin
ABuffLen := ABuffLen * SizeOf(WideChar);
ABuff := FDatabase.Buffer.Check(ABuffLen);
end;

while ABuffLen > 0 do begin
if ABuffLen > High(Word) then
iSeg := High(Word)
else
iSeg := Word(ABuffLen);

iStatus := Lib\.Fisc\_get\_segment\(@Error\.FStatusVector, @FBLHandle, iRead, iSeg, PISC\_SCHAR\(ABuff\)\);
if \(iStatus <\> 0\) and \(Error\.FStatusVector\[1\] <\> isc\_segment\) and \(Error\.FStatusVector\[1\] <\> isc\_segstr\_eof\) then
  Check\(iStatus\);
ABuffLen := ABuffLen \- iRead;
ABuff := ABuff \+ iRead;
Result := Result \+ iRead;
if Error\.FStatusVector\[1\] = isc\_segstr\_eof then
  Break;

end;

To prove that the second call to Lib.Fisc_get_segment() was causing the delay, I've added a high resolution timer around it:

sw := TStopwatch\.StartNew;
iStatus := Lib\.Fisc\_get\_segment\(@Error\.FStatusVector, @FBLHandle, iRead, iSeg, PISC\_SCHAR\(ABuff\)\);
sw\.Stop;
CodeSite\.SendFmtMsg\('BlobHandle: %d, Iteration: %d, ticks: %d, Bytes read: %d', \[DWORD\(FBLHandle\), i, sw\.ElapsedTicks, iRead\]\);
Inc\(i\);

The log output shows:

BlobHandle: 1, Iteration: 0, ticks: 206, Bytes read: 18
BlobHandle: 1, Iteration: 1, ticks: 1611, Bytes read: 0
BlobHandle: 2, Iteration: 0, ticks: 194, Bytes read: 12
BlobHandle: 2, Iteration: 1, ticks: 19488, Bytes read: 0
BlobHandle: 3, Iteration: 0, ticks: 193, Bytes read: 18
BlobHandle: 3, Iteration: 1, ticks: 17325, Bytes read: 0
BlobHandle: 5, Iteration: 0, ticks: 208, Bytes read: 18
BlobHandle: 5, Iteration: 1, ticks: 16666, Bytes read: 0
BlobHandle: 7, Iteration: 0, ticks: 383, Bytes read: 18
BlobHandle: 7, Iteration: 1, ticks: 17198, Bytes read: 0
BlobHandle: 9, Iteration: 0, ticks: 192, Bytes read: 18
BlobHandle: 9, Iteration: 1, ticks: 13918, Bytes read: 0

As you can see, reading nothing is very expensive.

If you need more information, let me know!

Cris

@firebird-automations
Copy link
Collaborator Author

Commented by: @hvlad

I modified isql to print stats about blob segments it reads and I can't confirm delay when reading last (zero-length) segment

I skipped actual blob data below:

Firebird3

SQL> select first 5 RDB$PROCEDURE_SOURCE from RDB$PROCEDURES;
...
N = 1, ts = 233 ticks, len = 511, ret = 2
N = 2, ts = 5 ticks, len = 511, ret = 2
N = 3, ts = 3 ticks, len = 511, ret = 2
N = 4, ts = 4 ticks, len = 395, ret = 0
N = 5, ts = 3 ticks, len = 0, ret = 1

N = 1, ts = 144 ticks, len = 177, ret = 0
N = 2, ts = 3 ticks, len = 0, ret = 1

N = 1, ts = 144 ticks, len = 252, ret = 0
N = 2, ts = 4 ticks, len = 0, ret = 1

N = 1, ts = 158 ticks, len = 511, ret = 2
N = 2, ts = 5 ticks, len = 171, ret = 0
N = 3, ts = 4 ticks, len = 0, ret = 1

N = 1, ts = 168 ticks, len = 511, ret = 2
N = 2, ts = 4 ticks, len = 314, ret = 0
N = 3, ts = 3 ticks, len = 0, ret = 1

Firebird 2.5:

N = 1, ts = 295 ticks, len = 15, ret = 0
N = 2, ts = 3 ticks, len = 0, ret = 335544367

N = 1, ts = 182 ticks, len = 19, ret = 0
N = 2, ts = 4 ticks, len = 0, ret = 335544367

N = 1, ts = 239 ticks, len = 31, ret = 0
N = 2, ts = 4 ticks, len = 0, ret = 335544367

N = 1, ts = 207 ticks, len = 36, ret = 0
N = 2, ts = 5 ticks, len = 0, ret = 335544367

N = 1, ts = 209 ticks, len = 39, ret = 0
N = 2, ts = 7 ticks, len = 0, ret = 335544367

@firebird-automations
Copy link
Collaborator Author

Commented by: Cris Doorn (cris)

Thanks for looking into this Vlad.
I guess the plot thickens... The only thing I can come up with right now is a difference in bitness.
I am using a 32bit fbclient.dll against a 64bit service (version 3.0.2).
I'll retest using a 64bit client .dll and test application. I will also test to see if there is any difference between reading from a system table compared to reading from an user defined table.
I currently run Firebird as SuperServer, maybe other modes behave differently, so I'll test those too.
I'll let you know my findings.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

1 participant