Oracle 12.2.0.1 keeps throwing ORA-01406

[aehimself]

An other day, an other interesting error. I connected my application to an Oracle server with the client version number in the subject. When I'm trying to select data from a table, an ORA-01406 exception is thrown every second or so. My code is like the following:

Procedure TForm1.ExecuteButtonClick(Sender: TObject);
Begin
Try
SQLQuery.SQL.Text := 'SELECT Note FROM MYTABLE';
SQLQuery.Open;
Except
On E:Exception Do ShowMessage(E.Message);
End;
End;

If I change the ClientCodePage from UTF-8 to nothing, the error is not thrown (but characters are displayed incorrectly ofc). I managed to find the record where the problem appeared (increasing "WHERE ROWNUM < x") but when I'm selecting only that one record, it shows up without errors.
The field is a status-like field and I can see other records having the exact same status displaying correctly.

The exception is thrown in CheckOracleError procedure, ZDbcOracleUtils.pas at line 1158.

SQLMonitor shows:

[2019.09.02 18:11:58.402] SQL trace: 2019-09-02 18:11:58 cat: Prepare, proto: oracle-9i, msg: Statement 3 : select note from mytable
[2019.09.02 18:11:58.452] SQL trace: 2019-09-02 18:11:58 cat: Execute prepared, proto: oracle-9i, msg: Statement 3
[2019.09.02 18:11:58.459] SQL trace: 2019-09-02 18:11:58 cat: Prepare, proto: oracle-9i, msg: Statement 4 : SELECT OWNER, TABLE_NAME, COLUMN_NAME, DATA_TYPE, DATA_LENGTH, DATA_PRECISION, DATA_SCALE, NULLABLE, DATA_DEFAULT, COLUMN_ID FROM SYS.ALL_TAB_COLUMNS Where TABLE_NAME like 'MYTABLE' order by COLUMN_ID
[2019.09.02 18:11:58.474] SQL trace: 2019-09-02 18:11:58 cat: Execute prepared, proto: oracle-9i, msg: Statement 4
[2019.09.02 18:12:02.400] SQL trace: 2019-09-02 18:12:02 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:04.616] SQL trace: 2019-09-02 18:12:04 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:08.933] Tab 0, TESTORACLE: EZSQLException was raised with the message: SQL Error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:09.098] SQL trace: 2019-09-02 18:12:09 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:22.732] SQL trace: 2019-09-02 18:12:22 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:24.601] SQL trace: 2019-09-02 18:12:24 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:27.174] SQL trace: 2019-09-02 18:12:27 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:30.706] SQL trace: 2019-09-02 18:12:30 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:31.929] SQL trace: 2019-09-02 18:12:31 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:34.298] SQL trace: 2019-09-02 18:12:34 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:35.396] SQL trace: 2019-09-02 18:12:35 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:38.098] SQL trace: 2019-09-02 18:12:38 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:39.220] SQL trace: 2019-09-02 18:12:39 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:42.221] SQL trace: 2019-09-02 18:12:42 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:44.119] SQL trace: 2019-09-02 18:12:44 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:47.928] SQL trace: 2019-09-02 18:12:47 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:52.839] SQL trace: 2019-09-02 18:12:52 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:12:59.194] SQL trace: 2019-09-02 18:12:59 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:01.148] SQL trace: 2019-09-02 18:13:01 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:05.535] SQL trace: 2019-09-02 18:13:05 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:06.477] SQL trace: 2019-09-02 18:13:06 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:09.151] SQL trace: 2019-09-02 18:13:09 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:10.761] SQL trace: 2019-09-02 18:13:10 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:14.181] SQL trace: 2019-09-02 18:13:14 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:19.951] SQL trace: 2019-09-02 18:13:19 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:22.850] SQL trace: 2019-09-02 18:13:22 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:23.836] SQL trace: 2019-09-02 18:13:23 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:24.722] SQL trace: 2019-09-02 18:13:24 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:26.557] SQL trace: 2019-09-02 18:13:26 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.02 18:13:30.316] SQL trace: 2019-09-02 18:13:30 cat: Other, proto: oracle-9i, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[...]

There are multiple anomalies here:
- There are no cycles in the code, so why the error keeps popping back up? See with bold, my application actually caught the exception once. Is it possible that the error buffer is not cleared out properly?
- Since the record seems to be causing the issue can be selected individually, it must not be an encoding issue. However it works with no codepage selected... can it be a buffer overflow?
- It also worths to mention that if I add "ORDER BY ID" to my command to fetch different rows (Oracle processes WHERE first and then ORDER BY) the magic number is the same (609), which means it only could download 608 records correctly, not depending on the contents.
- Connecting a different Oracle test database the same query executes flawlessly. This can be because of different server versions or different data though.

Unfortunately I will not be able to send an extract from the database as it contains commercial, probably sensitive information and I'd get in trouble for sharing it but I'm happy to do some debugging if someone could point me to a direction.

I'm using Delphi 10.2.3 but since the error is raised in the driver I don't think it's relevant.

Thank you for everyone, who is willing to help finding the culprit

Edit: I forgot, using Zeos 7.2.4 (r5698), reporting as 7.2.5-rc
Edit-edit: Adding SQLQuery.Close; to the exception handler stops the messages from keep popping up. Having data-aware components assigned to the ZQuery component seems to make no difference.

[EgonHugeist]

Hi,

lorbs that shouldn't happen. Since 7.2 i introduced a block cusor mode. Means OCI fetches n-Rows into the Zeos buffers on the first "true" execute is done (see ZDbcOracleResultset.pas -> TZOracleResultSet.Next if RowNo = zero) or if a StmtFetch2 is called (same method).

So it seems the buffers are to small.
Well the buffer-size alignment happen in TZOracleResultSet.Open. See:

Code: Select all

    FPlainDriver.AttrGet(CurrentVar^.Handle, OCI_DTYPE_PARAM,
      @CurrentVar^.oDataSize, nil, OCI_ATTR_DATA_SIZE, FErrorHandle);
    FPlainDriver.AttrGet(CurrentVar^.Handle, OCI_DTYPE_PARAM,
      @CurrentVar^.oDataType, nil, OCI_ATTR_DATA_TYPE, FErrorHandle);

I've no clue why you get this Exception. Which Oracle are you using? What's the field definition?

Btw. does it happen on 7.3 too?

[aehimself]

Hello,

Server is Oracle 11.2.0 and client library is 12.2.0. As for 7.3 I'm not sure, did not try it yet; to be honest I was waiting for the stable version before upgrading
I'm not aware in how Zeos exactly does it magic in the background, but "FPlainDriver.AttrGet" suggests that the buffer size is provided by the connection library, right? Since I already had sleepless nights because of Oracle's software (see http://zeoslib.sourceforge.net/viewtopi ... 40&t=88185) I guess I'll try to acquire a more recent library before upgrading Zeos.
The strange thing though that with PL/SQL the same query can be executed on the same machine with no issues. Although they use the same Client library I'm aware that the implementation is different, so...

Just as an addition, it seems out test servers are all on the same version, so we can rule out server version mismatch as the source. Dang, that was one of my initial suspect

I'll let you know what I can find.

[aehimself]

Hello,

Since updating the Oracle client to 19.3.0 (wow, mine was seriously outdated...) did not fix the issue I installed Zeos 7.3 r5898 but the issue remains:

[2019.09.05 10:59:33.967] Tab 0, TESTORACLE: Successfully connected to testoracle.internal in 966 millisecond(s). oracle 11.2.0, client version: 19.3.0, database component version:7.3.0-alpha
[2019.09.05 10:59:44.430] SQL trace: 2019-09-05 10:59:44 cat: Prepare, proto: oracle, msg: Statement 3 : SELECT * FROM MYTABLE
[2019.09.05 10:59:44.452] SQL trace: 2019-09-05 10:59:44 cat: Execute prepared, proto: oracle, msg: Statement 3
[2019.09.05 10:59:44.463] SQL trace: 2019-09-05 10:59:44 cat: Prepare, proto: oracle, msg: Statement 4 : SELECT OWNER, TABLE_NAME, COLUMN_NAME, DATA_TYPE, DATA_LENGTH, DATA_PRECISION, DATA_SCALE, NULLABLE, DATA_DEFAULT, COLUMN_ID FROM SYS.ALL_TAB_COLUMNS Where TABLE_NAME like 'MYTABLE' order by COLUMN_ID
[2019.09.05 10:59:44.479] SQL trace: 2019-09-05 10:59:44 cat: Execute prepared, proto: oracle, msg: Statement 4
[2019.09.05 10:59:47.429] SQL trace: 2019-09-05 10:59:47 cat: Other, proto: oracle, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: fetched column value was truncated
[2019.09.05 10:59:53.369] Tab 0, TESTORACLE: EZSQLException was raised with the message: SQL Error: OCI_ERROR: ORA-01406: fetched column value was truncated
Code: 1406 SQL: FETCH ROW

The exception message changed though

[aehimself]

So, managed to find something. Either it will be an Oracle bug or I don't understand Zeos's ClientCodePage well enough. Not only one test systems were affected, and those affected SELECT USERENV ('language') FROM DUAL returned "AMERICAN_AMERICA.EE8MSWIN1250".
If in the connection I set ClientCodePage to UTF8 the error appears, if I set EE8MSWIN1250 data is downloaded without malformation, if I leave it empty it downloads but is malformed.

I don't want to turn this topic to a rage about encodings (read way too many of those when I was educating myself about them lol), but...
According to my knowledge translation between code pages are done by the DB engine so if I request data in UTF8, it should do the conversion. As in UTF8 characters can be more bytes, I suppose we should have had enough buffer size.
So the question is:
- Does "ClientCodePage" mean that Zeos is asking the DB server to convert it's data to this specific encoding?
- Why only specific tables (now I'm not sure there was only one) showed the error / malformed data when the ClientCodePage is set to UTF8?

I'll keep looking but I think if I keep changing the ClientCodePage of all test systems to what they return to the above query everything should be fine...

[marsupilami]

Hello aehimself,

currently things should work like this: ClientCodePage is the codepage, that you request the database to send. So if you set it to UTF8 then it should be UTF8. With Oracle, UTF8 should be aliased to AL32UTF8 in Zeos. Because the Oracle UTF8 in reality is CESU-8... I left a comment about this in ZPlainOracleDriver.pas:

Code: Select all

  //2018-09-28 UTF8 removed by marsupilami79. UTF8 is CESU-8 in reality which cannot
  //be converted by Zeos correctly. For more information see:
  //https://en.wikipedia.org/wiki/CESU-8
  //https://community.oracle.com/thread/351482
  //UTF8 is aliased to AL32UTF8 to mitigate those rare problems.
  //AddCodePage('UTF8', 871, ceUTF8, zCP_UTF8);
  AddCodePage('UTF8', 871, ceUTF8, zCP_UTF8, 'AL32UTF8', 4);

So if you choose EE8MSWIN1250 Oracle will most probably deliver the data in WIN1250 and Zeos will transparently convert that to UTF16 on Unicode Delphis and the current system codepage on most ANSI Delphis.

What strikes me here: UTF8 can use up to 4 bytes per character and WIN1250 is a character set that only uses one byte per character.

[marsupilami]

Note: The following page says we (Zeos) don't provide enough biffer space: https://docs.oracle.com/cd/B10501_01/server.920/a96525/e900.htm:

ORA-01406 fetched column value was truncated

Cause: In a host language program, a FETCH operation was forced to truncate a character string. The program buffer area for this column was not large enough to contain the entire string. The cursor return code from the fetch was +3.

Action: Increase the column buffer area to hold the largest column value or perform other appropriate processing.

@Egonhugeist: I know it is a stupid question, but are we sure that we calculate the buffer size correctly?

[aehimself]

With Oracle, UTF8 should be aliased to AL32UTF8 in Zeos. Because the Oracle UTF8 in reality is CESU-8...
[...]
What strikes me here: UTF8 can use up to 4 bytes per character and WIN1250 is a character set that only uses one byte per character.

I did not know about this but this makes sense. What is really strange in this case is that I receive the exact same message when the ClientCodePage is set to AL32UTF8 (AL32UTF16 crashes with TNS protocol error, AL32UTF32 )

[2019.09.06 13:20:00.306] SQL trace: 2019-09-06 13:20:00 cat: Prepare, proto: oracle, msg: Statement 30 : SELECT * FROM MYTABLE
[2019.09.06 13:20:00.321] SQL trace: 2019-09-06 13:20:00 cat: Execute prepared, proto: oracle, msg: Statement 30
[2019.09.06 13:20:00.321] SQL trace: 2019-09-06 13:20:00 cat: Prepare, proto: oracle, msg: Statement 31 : SELECT OWNER, TABLE_NAME, COLUMN_NAME, DATA_TYPE, DATA_LENGTH, DATA_PRECISION, DATA_SCALE, NULLABLE, DATA_DEFAULT, COLUMN_ID FROM SYS.ALL_TAB_COLUMNS Where TABLE_NAME like 'MYTABLE' order by COLUMN_ID
[2019.09.06 13:20:00.321] SQL trace: 2019-09-06 13:20:00 cat: Execute prepared, proto: oracle, msg: Statement 31
[2019.09.06 13:22:06.709] SQL trace: 2019-09-06 13:22:06 cat: Other, proto: oracle, msg: FETCH ROW, errcode: 1406, error: OCI_ERROR: ORA-01406: a lehívott oszlop értéke csonkolva lett
[2019.09.06 13:22:06.709] Tab 0, TESTORACLE: EZSQLException was raised with the message: SQL Error: OCI_ERROR: ORA-01406: a lehívott oszlop értéke csonkolva lett
Code: 1406 SQL: FETCH ROW

Even the error message got translated (what an idiotic idea from Oracle's side though...) and shows the special characters correctly but it still throws the error when executing the query.

P.s.: since this topic has nothing to do with Zeos 7.2 after the upgrade, it might be a good idea to move it to the Oracle forum?

[aehimself]

@Egonhugeist: I know it is a stupid question, but are we sure that we calculate the buffer size correctly?

Did we manage to get a reply on this one? I'm keeping the ClientCodePage on EE8MSWIN1250 for the time being but I'd feel a lot better just to set it to UTF8 and forget about this.

[marsupilami]

@Egonhugeist: I know it is a stupid question, but are we sure that we calculate the buffer size correctly?

Did we manage to get a reply on this one?

Unfortunately I am not sure.

I'm keeping the ClientCodePage on EE8MSWIN1250 for the time being but I'd feel a lot better just to set it to UTF8 and forget about this.

A side note: On Zeos 7.2 you would have to choose AL32UTF8. We only aliased UTF8 to AL32UTF8 on Zeos 7.3 to keep the impact on existing systems low.

Is there any chance for you to create a set of example data that we can use to produce the error? This would help a lot in tracking down the problem.

[aehimself]

Nice, even if I'm subscribed to a topic I'm not receiving notifications
By UTF8 I meant AL32UTF8; because of your previous comment I already even forgot that the base UTF8 exists.

As for a test case I'll try to create a similar table with similar data... as I mentioned it's a commercial database with real-ish information inside it. Worst case scenario I'll sit together with the legal team to see what I can extract.

[marsupilami]

Nice, even if I'm subscribed to a topic I'm not receiving notifications

Yes - SourceForge doesn't allow sending e-mails from PHP anymore. We have to move the forums to an outside server if we want working e-mail again.

By UTF8 I meant AL32UTF8; because of your previous comment I already even forgot that the base UTF8 exists.

Ok - I just wanted to make sure.

As for a test case I'll try to create a similar table with similar data...

That would be great help.

as I mentioned it's a commercial database with real-ish information inside it. Worst case scenario I'll sit together with the legal team to see what I can extract.

I don't want to get you into trouble.

[aehimself]

So I did an extract with PL/SQL to create the table / upload some sample data. When trimming the excess from the export file I realized that PL/SQL simply, silently trims ALL the special characters from the strings. Doublechecked it with a SELECT query, with the same result.
No wonder it works.

I'll have to write a small app to extract the raw data and upload it in request in the very same format.

So far no anomaly on the table structure... column is DATA_TYPE 19, VARCHAR2, size is 200, BUFFER_LENGTH is 402, CHAR_OCTET_LENGTH is 400 according to TZMetaData.

I'll let you know when I managed to create the application with the raw dump.

[marsupilami]

Could you please check if the latest version of Zeos fixes your problem? Egonhugeist checked in a possible fix in Rev. 5979.

[aehimself]

...aaaaaand you see, this is why I always recommend this package when it comes to database connections (we just changed an old, internal app's ADO to Zeos).

Yes, indeed it seems that the problem is completely solved.

r5973, AL32UTF8:

Code: Select all

[2019.10.04 21:09:06.733] Tab 0, TESTCONNECTION: Successfully connected to  in 320 millisecond(s). oracle 11.2.0, client version: 19.3.0, database component version:7.3.0-alpha
[2019.10.04 21:09:36.546] SQL trace: '2019-10-04 21:10:36' cat: Prepare, proto: oracle, msg: Statement 3 : SELECT MYFIELD FROM MYTABLE WHERE MYFIELD IS NOT NULL
[2019.10.04 21:09:36.546] SQL trace: '2019-10-04 21:10:36' cat: Execute prepared, proto: oracle, msg: Statement 3
[2019.10.04 21:09:40.932] Tab 0, TESTCONNECTION: EZSQLException was raised with the message: SQL Error: OCI_ERROR: ORA-01406: a lehívott oszlop értéke csonkolva lett
 Code: 1406 SQL: FETCH ROW

r5985, AL32UTF8:

Code: Select all

[2019.10.04 21:06:31.011] Tab 0, TESTCONNECTION: Successfully connected to  in 675 millisecond(s). oracle 11.2.0, client version: 19.3.0, database component version:7.3.0-alpha
[2019.10.04 21:07:16.786] SQL trace: '2019-10-04 21:10:16' cat: Prepare, proto: oracle, msg: Statement 5 : SELECT MYFIELD FROM MYTABLE WHERE MYFIELD IS NOT NULL
[2019.10.04 21:07:17.411] SQL trace: '2019-10-04 21:10:17' cat: Execute prepared, proto: oracle, msg: Statement 5
[2019.10.04 21:07:41.854] Tab 0, TESTCONNECTION: Loading grid...
[2019.10.04 21:07:41.870] Tab 0, TESTCONNECTION: Formatting grid...
[2019.10.04 21:07:42.042] Tab 0, TESTCONNECTION: Query returned 2 191 record(s) in 25,26 second(s)

And I actually smiled on that commit message

Thank you very much for the Zeos team, you guys are simply awesome!


Edit:
"The datasize of the attachment charset is the naive DB-Size value + 1(+1 if NCHAR) so we've to calculate the buffer sizes manually using the code page informations we have"
How do you guys manage to figure these things out?!