February 25, 2010
A couple of days ago I received an email from a friend who manages a database (10.2.0.4) that is used by the same ERP platform as is used where I work. The email was quite friendly until I saw the attached file, which included a rather unfriendly ORA-07445 error message and stack trace:
ksedmp: internal or fatal error ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [_intel_fast_memcpy.A+18] [PC:0x33CFC0E] [ADDR:0x39D10000] [UNABLE_TO_READ]  Current SQL statement for this session: update my_table set costed_date = SYSDATE where type = 'W' and base_id = :1 and lot_id = :2 and split_id = :3 and sub_id = '0' ----- Call Stack Trace ----- calling call entry argument values in hex location type point (? means dubious value) -------------------- -------- -------------------- ---------------------------- _intel_fast_memcpy. 0000000000000000 000000000 000000000 000000000 A+18 000000000 0000000000000001 CALL??? _intel_fast_memcpy. 110F0E2E0 00118F111 0F7714C60 A+18 1160CE740 0000000110F0E2E0 CALL??? 0000000000000001 00118F111 0F7714C60 1160CE740 000000004 updgrh+3747 CALL??? 0000000110F0E2E0 0F7714C60 1160CE740 000000004 000000000 __PGOSF480_upduaw+1 CALL??? updgrh+3747 11DEAD460 00001E768 000000000 58 ACD6D33AF808 kdusru+540 CALL??? __PGOSF480_upduaw+1 00001E658 000000002 00001F2E0 58 00001F430 kauupd+521 CALL??? kdusru+540 110F0DBC0 023037F78 000000000 000000000 updrow+2086 CALL??? kauupd+521 039CDBA10 110F0DA48 039D0E000 100000000 __PGOSF536_qerupRow CALL??? updrow+2086 110E03438 000007FFF 002E4644C Procedure+93 00001F430 qerupFetch+748 CALL??? __PGOSF536_qerupRow 0EB37C530 000000000 000000000 Procedure+93 100000000 ...
No wonder it crashed with an ORA-07445 Access Violation error – look at the first argument of the __PGOSF480_upduaw+158 calling location – it must be that fatal errors appear in Oracle whenever the hexadecimal number DEAD appears in the middle of an argument. :-) (Watch out for false correlation when troubleshooting.) In case you are wondering, Metalink Doc ID 175982.1 “ORA-600 Lookup Error Categories” does not describe the updgrh function that eventually lead to the crash in the _intel_fast_memcpy.A+18 calling location, but there are a couple of articles on Metalink that describe updgrh as a function that is involved in updates to migrated rows.
As an experiment, a logon trigger like the following was created (caution, this logon trigger changes a “hidden” Oracle parameter to disable bind variable peeking – exercise caution, and check with Oracle support, before changing any hidden parameters):
CREATE OR REPLACE TRIGGER "SYS"."NO_PEEK_BIND" AFTER LOGON ON DATABASE DECLARE SHOULD_EXECUTE INTEGER; BEGIN SELECT DECODE(SUBSTR(UPPER(PROGRAM),1,8),'AAAAAAAA',1,0)+DECODE(INSTR(PROGRAM,'\',-1),0,0,DECODE(SUBSTR(UPPER(SUBSTR(PROGRAM,INSTR(PROGRAM,'\',-1)+1)),1,8),'AAAAAAAA',1,0)) INTO SHOULD_EXECUTE FROM V$SESSION WHERE SID=(SELECT SID FROM V$MYSTAT WHERE ROWNUM=1); IF SHOULD_EXECUTE > 0 THEN EXECUTE IMMEDIATE 'ALTER SESSION SET "_optim_peek_user_binds"=FALSE'; END IF; END; /
The above logon trigger disables bind variable peeking for any program with AAAAAAAA at the start of its filename, even if a portion of the program’s file path (assuming that the path directories are separated by backslashes) is included in the PROGRAM column of V$SESSION. Once in place, this logon trigger changes the parsing environment for the session such that any previously hard parsed SQL statements that were used by the program in the past would need to be re-hard parsed when executed by the program. Looking through the remainder of the trace file I noticed that a lot of the bind variables were not set to a value (No bind buffers allocated appeared in the trace file) during the first parse call by the session, so peeking at the bind variables could potentially cause problems if that special case is not handled correctly by Oracle Database 10.2.0.4. (The stack trace did not suggest that bind variable peeking was the cause of the problem.)
Once the trigger was in place, and new sessions have connected, were are able to confirm that the session-level parameter modification happened with the following SQL statement:
SELECT S.SID, SUBSTR(S.PROGRAM,1,8) PROGRAM, SOE.NAME, SOE.VALUE, SOE.ISDEFAULT FROM V$SESSION S, V$SES_OPTIMIZER_ENV SOE WHERE SUBSTR(UPPER(S.PROGRAM),1,8) IN ('AAAAAAAA','BBBBBBBB') AND S.SID=SOE.SID ORDER BY NAME, PROGRAM; SID PROGRAM NAME VALUE ISD ---- -------- ------------------------------------ ------------------------- --- 303 AAAAAAAA _optim_peek_user_binds false NO 303 AAAAAAAA _optimizer_adaptive_cursor_sharing false NO 335 BBBBBBBB _optimizer_adaptive_cursor_sharing false NO 303 AAAAAAAA active_instance_count 1 YES 335 BBBBBBBB active_instance_count 1 YES 303 AAAAAAAA bitmap_merge_area_size 1048576 YES 335 BBBBBBBB bitmap_merge_area_size 1048576 YES 303 AAAAAAAA cell_offload_compaction ADAPTIVE YES 335 BBBBBBBB cell_offload_compaction ADAPTIVE YES 303 AAAAAAAA cell_offload_plan_display AUTO YES 335 BBBBBBBB cell_offload_plan_display AUTO YES 303 AAAAAAAA cell_offload_processing true YES 335 BBBBBBBB cell_offload_processing true YES 303 AAAAAAAA cpu_count 2 YES 335 BBBBBBBB cpu_count 2 YES 303 AAAAAAAA cursor_sharing exact YES 335 BBBBBBBB cursor_sharing exact YES 303 AAAAAAAA db_file_multiblock_read_count 32 YES 335 BBBBBBBB db_file_multiblock_read_count 32 YES 303 AAAAAAAA hash_area_size 131072 YES 335 BBBBBBBB hash_area_size 131072 YES 303 AAAAAAAA is_recur_flags 0 YES 335 BBBBBBBB is_recur_flags 0 YES 303 AAAAAAAA optimizer_capture_sql_plan_baselines false YES 335 BBBBBBBB optimizer_capture_sql_plan_baselines false YES 303 AAAAAAAA optimizer_dynamic_sampling 2 YES 335 BBBBBBBB optimizer_dynamic_sampling 2 YES 303 AAAAAAAA optimizer_features_enable 220.127.116.11 YES 335 BBBBBBBB optimizer_features_enable 18.104.22.168 YES 303 AAAAAAAA optimizer_index_caching 0 YES 335 BBBBBBBB optimizer_index_caching 0 YES 303 AAAAAAAA optimizer_index_cost_adj 100 YES 335 BBBBBBBB optimizer_index_cost_adj 100 YES 303 AAAAAAAA optimizer_mode all_rows YES 335 BBBBBBBB optimizer_mode all_rows YES 303 AAAAAAAA optimizer_secure_view_merging true YES 335 BBBBBBBB optimizer_secure_view_merging true YES 303 AAAAAAAA optimizer_use_invisible_indexes false YES 335 BBBBBBBB optimizer_use_invisible_indexes false YES 303 AAAAAAAA optimizer_use_pending_statistics false YES 335 BBBBBBBB optimizer_use_pending_statistics false YES 303 AAAAAAAA optimizer_use_sql_plan_baselines true YES 335 BBBBBBBB optimizer_use_sql_plan_baselines true YES 303 AAAAAAAA parallel_ddl_mode enabled YES 335 BBBBBBBB parallel_ddl_mode enabled YES 303 AAAAAAAA parallel_degree 0 YES 335 BBBBBBBB parallel_degree 0 YES 303 AAAAAAAA parallel_dml_mode disabled YES 335 BBBBBBBB parallel_dml_mode disabled YES 303 AAAAAAAA parallel_execution_enabled false YES 335 BBBBBBBB parallel_execution_enabled false YES 303 AAAAAAAA parallel_query_default_dop 0 YES 335 BBBBBBBB parallel_query_default_dop 0 YES 303 AAAAAAAA parallel_query_mode enabled YES 335 BBBBBBBB parallel_query_mode enabled YES 303 AAAAAAAA parallel_threads_per_cpu 2 YES 335 BBBBBBBB parallel_threads_per_cpu 2 YES 303 AAAAAAAA pga_aggregate_target 143360 KB YES 335 BBBBBBBB pga_aggregate_target 143360 KB YES 303 AAAAAAAA query_rewrite_enabled true YES 335 BBBBBBBB query_rewrite_enabled true YES 303 AAAAAAAA query_rewrite_integrity enforced YES 335 BBBBBBBB query_rewrite_integrity enforced YES 303 AAAAAAAA result_cache_mode MANUAL YES 335 BBBBBBBB result_cache_mode MANUAL YES 303 AAAAAAAA skip_unusable_indexes true YES 335 BBBBBBBB skip_unusable_indexes true YES 303 AAAAAAAA sort_area_retained_size 0 YES 335 BBBBBBBB sort_area_retained_size 0 YES 303 AAAAAAAA sort_area_size 65536 YES 335 BBBBBBBB sort_area_size 65536 YES 303 AAAAAAAA star_transformation_enabled false YES 335 BBBBBBBB star_transformation_enabled false YES 303 AAAAAAAA statistics_level typical YES 335 BBBBBBBB statistics_level typical YES 303 AAAAAAAA transaction_isolation_level read_commited YES 335 BBBBBBBB transaction_isolation_level read_commited YES 303 AAAAAAAA workarea_size_policy auto YES 335 BBBBBBBB workarea_size_policy auto YES
The above output is obviously not from the 10.2.0.4 database. As can be determined by the above, the _OPTIM_PEEK_USER_BINDS parameter is set to FALSE only for the program AAAAAAAA. If you look closely at the output, you will also notice that the _OPTIMIZER_ADAPTIVE_CURSOR_SHARING parameter is set to the non-default value of FALSE for both sessions (this change was made in the spfile), and it would be a logical next step to determine why that hidden parameter was changed from the default.
Did changing the behavior of bind variable peeking solve the ORA-07445 Access Violation error? Well, that question is off topic for this blog article – the ORA-07445 is just one reason why it might be necessary to explore the parameters that were modified at the session-level. V$SES_OPTIMIZER_ENV shows the parameters that were modified from the Oracle defaults (check the ISDEFAULT column) at the session-level, and those values may be compared with the system-wide defaults found in the V$SYS_OPTIMIZER_ENV view. A previous blog article described the V$SQL_OPTIMIZER_ENV view, which shows the parameters that were in effect when a specific child cursor was initially hard parsed.