Shannon's JD Edwards CNC Blog: Awesome problem… UBE ending early on AS/400 not completing all records in main select

The benefits of ODBC trace are still there when debugging UBEs especially.

So this was the problem. There was a main section with a SQL statement that was based on a VIEW (this is important) and should have processed 20000 rows. The SQL was good and tidy, but the batch job would stop after 10 rows on the 400 and 271 on the client. Yep, that is weird. The problem was kind of intermittent, but consistent… (Even that is a bad description).

The developers were saying the server was rubbish and fix it. This is a tough situation, as CNC is generally at the bottom of these types of problems that are in the nether regions of peoples responsibilities.

So we ran it with logging, nothing really.

Mar 21 13:31:36.701864 dbdrvsql.c1362 - 1087/139 MAIN_THREAD                          >>>Start - FetchSQLRow QxdaProcessExtDynEDRS
Mar 21 13:31:36.805392 dbdrvsql.c1373 - 1087/139 MAIN_THREAD                          >>>End - FetchSQLRow QxdaProcessExtDynEDRS
Mar 21 13:31:36.805432 dbdrvag.c1143   - 1087/139 MAIN_THREAD                          Exiting PerformRequest, result=-1
Mar 21 13:31:36.805448 jdb_exef.c4618 - 1087/139 MAIN_THREAD                          No More Data found
--UBE--[2]-- End of Records for the section with Return Code (-2147483648) after fetching 0 records.

The above message is a funny one, as this is 2^31 negative. I think this is the return of an unsigned int if it gets a negative.

Good info, but not helpful enough.

Next level of logging was tracing the job on the 400 and ODBC trace.

ODBC trace turn out to solve the problem quickly. The ODBC trace has great information about warnings and things that JDE logs ignore. The ODBC trace shows you accurate handle associates and cursors etc.

What actually was occurring was that there was an update to a parent table in the parent child relationship that the view was based upon.

So the main loop had a cursor open and that value had been updated with a separate table i/o to the parent record.

This eventually caught up with the code and the report crapped out. The ODBC trace shows the handles that the errors are reported on. The different colours show the continuity of the handles.

activConsole 13cc-1e0 EXIT SQLPrepareW with return code 0 (SQL_SUCCESS)

HSTMT 03AC92F0

WCHAR * 0x1BD95F80 [ 766] "SELECT T0.AFEDBT, T0.AFEDTN, T0.AFEDLN, T0.AFEDSP, T0.AF57PRID, T0.AF57PRDESC, T0.AFITM, T0.AF57STCD, T0.AFLITM, T0.AF57STDESC, T0.AFAN8, T0.AFALKY, T0.AFTRDJ, T0.AF57ACD, T0.AF57ACOOP, T0.AFAID, T0.AFAID2, T0.AFAID3, T0.AFAID4, T0.AFUSER, T0.AFPID, T0.AFJOBN, T0.AFUPMJ, T0.AFUPMT, T1.BHEDBT, T1.BH57INTF, T1.BHEDCT, T1.BH57SEQ, T1.BH57BSTS, T1.BH57RECC, T1.BH57TOT1, T1.BH57TOT2, T1.BH57TOT3, T1.BH57TOT4, T1.BH57SUM1, T1.BH57SUM2, T1.BH57FDAT, T1.BH57FTIM, T1.BH57TDAT, T1.BH57TTIM, T1.BH57CDAT, T1.BH57CTIM, T1.BH57MDAT, T1.BHUSER, T1.BHPID, T1.BHJOBN, T1.BHUPMJ, T1.BHUPMT, T1.BH57MTIM, T1.BH57EDBT FROM UADTA/F570911F T0,UADTA/F570001 T1 WHERE ( ( T1.BH57INTF = ? AND T1.BH57BSTS = ? ) ) AND ( T0.AFEDBT=T1.BHEDBT ) ORDER BY T0.AFEDBT ASC,T0.AF57PRID ASC"

SDWORD 766

activConsole 13cc-1e0 ENTER SQLExecute

HSTMT 03AC92F0

activConsole 13cc-1e0 EXIT SQLExecute with return code 0 (SQL_SUCCESS)

HSTMT 03AC92F0

activConsole 13cc-1e0 ENTER SQLFetch

HSTMT 03AC92F0

activConsole 13cc-1e0 ENTER SQLPrepareW

HSTMT 03ACAC40

WCHAR * 0x2665CF90 [ 59] "UPDATE UADTA/F570001 SET BH57BSTS=? WHERE ( BHEDBT = ? ) "

SDWORD 59

activConsole 13cc-1e0 EXIT SQLPrepareW with return code 0 (SQL_SUCCESS)

HSTMT 03ACAC40

WCHAR * 0x2665CF90 [ 59] "UPDATE UADTA/F570001 SET BH57BSTS=? WHERE ( BHEDBT = ? ) "

SDWORD 59

activConsole 13cc-1e0 ENTER SQLExecute

HSTMT 03ACAC40

activConsole 13cc-1e0 EXIT SQLExecute with return code 0 (SQL_SUCCESS)

HSTMT 03ACAC40

...

activConsole 13cc-1e0 EXIT SQLFetch with return code 100 (SQL_NO_DATA_FOUND)

HSTMT 03AC92F0