Friday, May 23, 2025

Oracle ORA-00600 [pfrsfm: stack mismatch] and [pfrsfm: stack mismatch] Reproducing

This Blog will demonstrate how to generate Oracle ORA-00600 [pfrsfm: stack mismatch] and [pfrsfm: stack mismatch].

Note: Tested on Oracle 19c


1. ORA-00600: internal error code, arguments: [pfrsfm: stack mismatch]


Open one Sqlplus window, start 400 Jobs to test (see Section 3. Test Code):

  SQL > exec start_test(400, 1e4, 1e6, 0, 5);
During and after test (it takes about 15 minutes), check DB alert.log and incident files if they contain error text like:

  ORA-00600: internal error code, arguments: [pfrsfm: stack mismatch]
If with 400 Jobs, it is not reproduced, increase it and re-run the test.

Here the incident file:

ORA-00600: internal error code, arguments: [pfrsfm: stack mismatch], [0x7F1F08BB3BF8], [0xFFFFFFFFFFFFFFFF], [0x7F1F08506000], [0x7F1F08BB33F0], 
                                                                     [0xFFFFFFFFFFFFFFFF], [0xFFFFFFFFFFFFFFFF], [], [], [], [], []
ORA-27403: scheduler stop job event
ORA-27403: scheduler stop job event

========= Dump for incident 14217 (ORA 600 [pfrsfm: stack mismatch]) ========

----- Current SQL Statement for this session (sql_id=f44xkpcgqsatb) -----
SELECT * FROM TABLE(PIPELINE_TAB(:B1 , :B2 )) WHERE ROWNUM <= :B1 -5

----- Parser State -----
Parser state1: len1=0 len2=0 pos1=0 pos2=0
Parser state2: flg=0x0 xflg=0x0 xxflg=0x400
Parser state3: tty=0 tlen=0
Parser string: prx=0x7f1f0e8a9d60 base=(nil) cur=(nil)

----- PL/SQL Call Stack -----
  object      line  object
  handle    number  name
0x9def1680         5  procedure K.TEST_JOB_PROC
0x7e82e800         1  anonymous block

[TOC00006]
----- Call Stack Trace -----
calling              call     entry                argument values in hex      
location             type     point                (? means dubious value)     
-------------------- -------- -------------------- ----------------------------
dbgexProcessError()  call     dbgexPhaseII()       7F1F0E83B6D8 7F1F0E7ED1F0
+1872                                              7FFD1ED4C800 7FFD1ED450C8 ?
                                                   000000000 ? 000000000 ?
dbgePostErrorKGE()+  call     dbgexProcessError()  7F1F0E83B6D8 7F1F0E7ED1F0
1853                                               000000001 000000000
                                                   000000000 ? 000000000 ?
dbkePostKGE_kgsf()+  call     dbgePostErrorKGE()   7F1F0E87B9C0 7F1F08BB0050
71                                                 000000258 000000000 ?
                                                   000000000 ? 000000000 ?
kgeadse()+448        call     dbkePostKGE_kgsf()   7F1F0E87B9C0 7F1F08BB0050
                                                   000000258 000000000 ?
                                                   000000000 ? 000000000 ?
kgerinv_internal()+  call     kgeadse()            7F1F0E87B9C0 ? 7F1F08BB0050
44                                                 000000258 ? 016036C24
                                                   000000000 000000006
kgerinv()+40         call     kgerinv_internal()   7F1F0E87B9C0 ? 7F1F08BB0050 ?
                                                   000000258 ? 016036C24 ?
                                                   000000000 ? 000000006 ?
kgeasnmierr()+146    call     kgerinv()            7F1F0E87B9C0 ? 7F1F08BB0050 ?
                                                   000000258 ? 016036C24 ?
                                                   000000000 ? 000000006 ?
pfrsfm()+1233        call     kgeasnmierr()        7F1F0E87B9C0 ? 7F1F08BB0050 ?
                                                   000000258 ? 016036C24 ?
                                                   000000002 7F1F08BB3BF8
pfrspopstks()+103    call     pfrsfm()             7F1F0E87B9C0 ? 7F1F08BB0050 ?
                                                   000000258 ? 016036C24 ?
                                                   000000002 ? 7F1F08BB3BF8 ?
kksumc()+526         call     pfrspopstks()        7F1F0E87B9C0 ? 7F1F08507910
                                                   000000258 ? 016036C24 ?
                                                   000000002 ? 7F1F08BB3BF8 ?
opiodr()+4705        call     kksumc()             7F1F0864F5C8 000000005


2. ORA-00600: internal error code, arguments: [pfrsfm: Stack disordered]


Open one Sqlplus window, start test by:

SQL>  exec test_job_proc(1, 1e4, 1e6, 0, 5);
Get its session SPID (1055599) and its (sid, serial#) = (915.49648).

In UNIX Terminal, run kill command:

  kill -URG 1055599
or In another Sqlplus window, run cancel statement:

  alter system cancel sql '915,49648';
(see Blog:
   How to CANCEL a query running in another session? (https://tanelpoder.com/2010/02/17/how-to-cancel-a-query-running-in-another-session/)
   DBMS_SCHEDULER Job Not Running and Used Slaves (https://ksun-oracle.blogspot.com/2021/01/dbmsscheduler-job-not-running-and-used.html)
)

You will see either:

SQL>  exec test_job_proc(1, 1e4, 1e6, 0, 5);
BEGIN test_job_proc(1, 1e4, 1e6, 0, 5); END;

*
ERROR at line 1:
ORA-01013: user requested cancel of current operation
or

SQL>  exec test_job_proc(1, 1e4, 1e6, 0, 5);
BEGIN test_job_proc(1, 1e4, 1e6, 0, 5); END;

*
ERROR at line 1:
ORA-00603: ORACLE server session terminated by fatal error
ORA-24557: error 600 encountered while handling error 1013; exiting server
process
ORA-00600: internal error code, arguments: [pfrsfm: Stack disordered],
[0x7F0FE0BA14F8], [0x7F0FE0BA22F0], [0x7F0FE0BA1850], [0x7F0FE0BA34F8], [], [],
[], [], [], [], []
ORA-01013: user requested cancel of current operation
Process ID: 1055599
Session ID: 915 Serial number: 49648
If it is the first case, in the same Oracle session (ORA-01013 does not terminate session), re-run:

   exec test_job_proc(1, 1e4, 1e6, 0, 5); 
re-run UNIX kill command or SQL cancel statement.

Repeat above steps till the session hit "ORA-00600: [pfrsfm: Stack disordered]".

Then the session incident file shows:

ORA-00600: internal error code, arguments: [pfrsfm: Stack disordered], [0x7F0FE0BA14F8], [0x7F0FE0BA22F0], [0x7F0FE0BA1850], [0x7F0FE0BA34F8], 
                                                                       [], [], [], [], [], [], []
ORA-01013: user requested cancel of current operation

========= Dump for incident 11485 (ORA 600 [pfrsfm: Stack disordered]) ========

*** 2025-05-20T09:54:22.541566+02:00
dbkedDefDump(): Starting incident default dumps (flags=0x2, level=3, mask=0x0)
[TOC00003]
----- Current SQL Statement for this session (sql_id=b7vzj4s3qw97g) -----
SELECT * FROM TABLE(GET_TAB_PTF(:B1 , :B2 )) WHERE ROWNUM <= :B1 -5
[TOC00004]
----- Parser State -----
Parser state1: len1=0 len2=36 pos1=0 pos2=5
Parser state2: flg=0x0 xflg=0x4300000 xxflg=0x400
Parser state3: tty=0 tlen=5
Parser string: prx=0x7f0fe6887d60 base=(nil) cur=0x7ffce65bdbed

----- PL/SQL Call Stack -----
  object      line  object
  handle    number  name
0xa0fb7940         5  procedure K.TEST_ORA_600_DISCONNET
0x95391e58         1  anonymous block

----- Call Stack Trace -----
calling              call     entry                argument values in hex      
location             type     point                (? means dubious value)     
-------------------- -------- -------------------- ----------------------------
dbgexProcessError()  call     dbgexPhaseII()       7F0FE68196D8 7F0FE67CB1F0
+1872                                              7FFCE65B7000 7FFCE65AF908 ?
                                                   000000000 ? 000000000 ?
dbgePostErrorKGE()+  call     dbgexProcessError()  7F0FE68196D8 7F0FE67CB1F0
1853                                               000000001 000000000
                                                   000000000 ? 000000000 ?
dbkePostKGE_kgsf()+  call     dbgePostErrorKGE()   7F0FE68599C0 7F0FE0B90050
71                                                 000000258 000000000 ?
                                                   000000000 ? 000000000 ?
kgeadse()+448        call     dbkePostKGE_kgsf()   7F0FE68599C0 7F0FE0B90050
                                                   000000258 000000000 ?
                                                   000000000 ? 000000000 ?
kgerinv_internal()+  call     kgeadse()            7F0FE68599C0 ? 7F0FE0B90050
44                                                 000000258 ? 016036BEC
                                                   000000000 000000004
kgerinv()+40         call     kgerinv_internal()   7F0FE68599C0 ? 7F0FE0B90050 ?
                                                   000000258 ? 016036BEC ?
                                                   000000000 ? 000000004 ?
kgeasnmierr()+146    call     kgerinv()            7F0FE68599C0 ? 7F0FE0B90050 ?
                                                   000000258 ? 016036BEC ?
                                                   000000000 ? 000000004 ?
pfrsfm()+1055        call     kgeasnmierr()        7F0FE68599C0 ? 7F0FE0B90050 ?
                                                   000000258 ? 016036BEC ?
                                                   000000002 7F0FE0BA14F8
pfrspopstks()+103    call     pfrsfm()             7F0FE68599C0 ? 7F0FE0B90050 ?
                                                   000000258 ? 016036BEC ?
                                                   000000002 ? 7F0FE0BA14F8 ?
kksumc()+526         call     pfrspopstks()        7F0FE68599C0 ? 7F0FE0BA22F0
                                                   000000258 ? 016036BEC ?
                                                   000000002 ? 7F0FE0BA14F8 ?
opiodr()+4705        call     kksumc()             7F0FE0298488 000000005
                                                   000000258 ? 7F0FE68599C0
                                                   000000002 ? 7F0FE0BA14F8 ?
If we compare incident file of [pfrsfm: stack mismatch] and [pfrsfm: Stack disordered], we can see that they hit ORA-00600 at different pfrsfm locations:

pfrsfm()+1233

pfrsfm()+1055


3. Test Code



create or replace procedure clearup_test as
begin
  for c in (select * from dba_scheduler_jobs where job_name like '%TEST_JOB%') loop
    begin
      --set DBA_SCHEDULER_JOBS.enabled=FALSE
	    dbms_scheduler.disable (c.job_name, force => true, commit_semantics =>'ABSORB_ERRORS');
	    --set DBA_SCHEDULER_JOBS.enabled=TRUE, so that it can be scheduled to run (state='RUNNING')
	    --  dbms_scheduler.enable (c.job_name, commit_semantics =>'ABSORB_ERRORS');
	  exception when others then null;
	  end;
	end loop;
	
  for c in (select * from dba_scheduler_running_jobs where job_name like '%TEST_JOB%') loop
    begin
      --If force=FALSE, gracefully stop the job, slave process can update the status of the job in the job queue.
      --If force= TRUE, the Scheduler immediately terminates the job slave.
      --For repeating job with attribute "start_date => systimestamp" and enabled=TRUE, 
      --re-start immediate (state changed from 'SCHEDULED' to 'RUNNING'), DBA_SCHEDULER_JOBS.run_count increases 1.
	    dbms_scheduler.stop_job (c.job_name, force => true, commit_semantics =>'ABSORB_ERRORS');
	  exception when others then null;
	  end;
	end loop;
	
  for c in (select * from dba_scheduler_jobs where job_name like '%TEST_JOB%') loop
    begin
      --If force=TRUE, the Scheduler first attempts to stop the running job instances 
      --(by issuing the STOP_JOB call with the force flag set to false), and then drops the jobs.
	    dbms_scheduler.drop_job (c.job_name, force => true, commit_semantics =>'ABSORB_ERRORS');
	  exception when others then null;
	  end;
	end loop;
end;
/

drop type t_tab;
drop type t_row;

create type t_row as object (id number, name varchar2(50));
/

create type t_tab is table of t_row;
/

create or replace function pipeline_tab (p_rows in number, p_seconds number) return t_tab pipelined as
begin
  for i in 1 .. p_rows loop
    dbms_output.put_line('row: ' || i);
    pipe row(t_row(i, 'Name_' || i));
    if p_seconds > 0 then 
      dbms_session.sleep(p_seconds);
    end if;
  end loop;
  return;
end;
/

-- not needed
drop table test_tab;
create table test_tab(id number, label varchar2(10));
insert into test_tab(id, label) values(1, 'label');
commit;

create or replace procedure test_pipeline_proc_recur(p_rows number, p_seconds number, p_depth number) as
begin
  if p_depth = 0 then
    for c in (select * from table(pipeline_tab(p_rows, p_seconds)) where  rownum <= p_rows-5) 
    loop
      dbms_output.put_line('id = '||c.id);
    end loop;
  else 
    test_pipeline_proc_recur(p_rows, p_seconds, p_depth - 1);
  end if;
  exception when others then 
    dbms_output.put_line('p_depth = '||p_depth||', ERROR: ' || sqlerrm);
end;
/

create or replace procedure test_job_proc(p_job_id number, p_loop_count number, p_rows number, p_seconds number, p_depth number) as
begin
  update test_tab set id = id+1;
  for i in 1..p_loop_count loop
    execute immediate 'begin test_pipeline_proc_recur('||p_rows||', '||p_seconds||', '||p_depth||'); end; ';
  end loop;
  commit;
end;
/

create or replace procedure start_jobs(p_job_count number, p_loop_count number, p_rows number, p_seconds number, p_depth number) as
begin
  for i in 1..p_job_count loop
    dbms_scheduler.create_job (
      job_name        => 'TEST_JOB_CRASHED_1'||i,
      job_type        => 'PLSQL_BLOCK',
      job_action      => 'begin test_job_proc('||i||', '||p_loop_count||', '||p_rows||', '||p_seconds||', '||p_depth||'); end;',    
      start_date      => systimestamp,
      --repeat_interval => 'systimestamp',
      auto_drop       => true,
      enabled         => true);
  end loop;
end;
/

create or replace procedure start_test(p_job_count number, p_loop_count number, p_rows number, p_seconds number, p_depth number) as
  l_cnt number := 0;
begin
  dbms_output.put_line('Start '||p_job_count||' Jobs at '||sysdate);
  start_jobs(p_job_count, p_loop_count, p_rows, p_seconds, p_depth);
  
  -- wait for all jobs running
  dbms_output.put_line('Wait all Jobs running at '||sysdate);
  loop
    dbms_session.sleep(1);
    select count(*) into l_cnt from dba_scheduler_running_jobs where job_name like 'TEST_JOB_CRASHED%';
    exit when l_cnt >= p_job_count;
  end loop;
  
  dbms_output.put_line('Start clearup at '||sysdate);
  clearup_test;
 
  -- wait for all jobs stopped
  dbms_output.put_line('Wait clearup at '||sysdate);
  loop
    dbms_session.sleep(1);
    select count(*) into l_cnt from dba_scheduler_running_jobs where job_name like 'TEST_JOB_CRASHED%';
    exit when l_cnt = 0;
  end loop;
  dbms_output.put_line('Test End at '||sysdate);
end;
/

-- exec start_jobs(1e2, 1e4, 1e6, 0, 5);
-- exec clearup_test;
-- exec test_job_proc(1, 1e4, 1e6, 0, 5);

--================== Test Run ==================--
--  exec start_test(400, 1e4, 1e6, 0, 5);