correct, you must tell sqlplus to dump the output.

try it.  login to sqlplus (without having set serveroutput on) and try to get dbms_output to work.  It won't. (make sure you don't have set serveroutput on in your login.sql file)

ops$tkyte@ORA817DEV.US.ORACLE.COM> exec dbms_output.enable(10000);

PL/SQL procedure successfully completed.

ops$tkyte@ORA817DEV.US.ORACLE.COM> exec dbms_output.put_line( 'x' );

PL/SQL procedure successfully completed.

ops$tkyte@ORA817DEV.US.ORACLE.COM> set serveroutput on
ops$tkyte@ORA817DEV.US.ORACLE.COM> exec dbms_output.put_line( 'x' );
x
x

PL/SQL procedure successfully completed.

See the second one did 2 x's -- the first and second, since plus didn't DUMP the output the first time. 

(you know, i always wonder how people rate questions, how they come up with 1..5 stars. here, we have accurate - detailed information that tells you exactly how to use something, yet because they don't LIKE the answer, its only worth 1. I guess people rate by what they WANTED to hear, not what is said. Oh well)....

DBMS_OUTPUT is a package to allow you to buffer "lines of text" that a client might retrieve and do something with.

In this package there are a couple of procedures/functions. One of which is ENABLE.

A client (any client) can call enable. If you call enable all this does is lets the package BUFFER output. If enable is not called or you call disable -- buffering of this output is disabled, does not happen.

Now, any client -- your C program, your java application, your WHATEVER, can call dbms_output.enable to get this buffering to take place. they can later call dbms_output.get_line/get_lines to get this buffered data and do SOMETHING (whatever they want) with it.

Now, sqlplus sees this functionality and says "hey, would not it be nice for me to dump this buffer to screen for the user?". So, they added the SQLPlus command "set serveroutput on" which does two things

1) it tells SQLPLUS you would like it to execute dbms_output.get_lines after each and every statement. You would like it to do this network rounding after each call. You would like this extra overhead to take place (think of an install script with hundreds/thousands of statements to be executed -- perhaps, just perhaps you don't want this extra call after every call)

2) SQLPLUS automatically calls the dbms_output API "enable" to turn on the buffering that happens in the package.


Since SQLPlus has NO WAY to know if you called dbms_output.enable (it could be buried in a stored procedure call, in a trigger, where ever) -- it would have to call dbms_output.get_lines after each ever call -- adding unnecessary overhead.

I guess the implementors of sqlplus looked at this problem and said "set serveroutput on" isn't any harder then exec dbms_output.enable -- in fact it would be easier so we'll do it that way. In this fashion, sqlplus won't make this extra call after each call -- unless the user asks us to.

Given that you can have a login.sql with

set serveroutput on size 1000000

to have this setup for you transparently, its just not really a big deal at all.

did you:

set serveroutput on size 1000000

??

(if yes, I can show you methods to get around this limit as well, all is not lost, search for my_dbms_output on this site for some ideas)

It is because prior to 9i -- a stored procedure call would goto the database, run the procedure from start to finish and then return to the client.  The client has no ability to get results from the stored procedure until its totally done. It is one message over, one message back.  The stored procedure runs in the server, not on the client so the stored procedure cannot really do any I/O on the client screen (and think of all of the interfaces - gui's, command line, etc -- there would be no way for the stored proc to do I/O to the screen)

Now, in 9i, we can actually get interactive results from a stored procedure using pipe lining (a cool feature that wasn't really designed to do exactly what I'm about to do -- rather this is a nice side effect).  Consider this small example:

ops$tkyte@ORA9I.WORLD> create or replace type messageTabType
  2  as table of varchar2(4000)
  3  /

Type created.

ops$tkyte@ORA9I.WORLD> 
ops$tkyte@ORA9I.WORLD> create or replace function my_stored_proc( p_inputs in varchar2 )
  2  return messageTabType
  3  PIPELINED
  4  as
  5  begin
  6      for i in 1 .. 10
  7      loop
  8          pipe row( 'processing iteration      ' ||
  9                      i || ' ' || systimestamp );
 10          dbms_lock.sleep(1);
 11          pipe row( 'done processing iteration ' ||
 12                      i || ' ' || systimestamp );
 13      end loop;
 14      pipe row( 'All done, success' );
 15  
 16      return;
 17  end;
 18  /

Function created.

ops$tkyte@ORA9I.WORLD> 
ops$tkyte@ORA9I.WORLD> set arraysize 1
ops$tkyte@ORA9I.WORLD> select * from table( my_stored_proc( 'foobar' ) );

COLUMN_VALUE
--------------------------------------------------------------------------------
processing iteration      1 16-NOV-01 08.14.38.335479000 AM -05:00
done processing iteration 1 16-NOV-01 08.14.39.360806000 AM -05:00
processing iteration      2 16-NOV-01 08.14.39.361372000 AM -05:00
done processing iteration 2 16-NOV-01 08.14.40.390780000 AM -05:00
processing iteration      3 16-NOV-01 08.14.40.391328000 AM -05:00
done processing iteration 3 16-NOV-01 08.14.41.420795000 AM -05:00
processing iteration      4 16-NOV-01 08.14.41.421341000 AM -05:00
done processing iteration 4 16-NOV-01 08.14.42.450819000 AM -05:00
processing iteration      5 16-NOV-01 08.14.42.451383000 AM -05:00
done processing iteration 5 16-NOV-01 08.14.43.480794000 AM -05:00
processing iteration      6 16-NOV-01 08.14.43.481343000 AM -05:00
done processing iteration 6 16-NOV-01 08.14.44.511147000 AM -05:00
processing iteration      7 16-NOV-01 08.14.44.511987000 AM -05:00
done processing iteration 7 16-NOV-01 08.14.45.540863000 AM -05:00
processing iteration      8 16-NOV-01 08.14.45.541468000 AM -05:00
done processing iteration 8 16-NOV-01 08.14.46.571104000 AM -05:00
processing iteration      9 16-NOV-01 08.14.46.571923000 AM -05:00
done processing iteration 9 16-NOV-01 08.14.47.600860000 AM -05:00
processing iteration      10 16-NOV-01 08.14.47.601463000 AM -05:00
done processing iteration 10 16-NOV-01 08.14.48.630873000 AM -05:00
All done, success

21 rows selected.

It is not obvious here but -- each pair of outputs from the procedure appeared in sqlplus -- in real time -- every second (setting the arraysize was important here, else plus would have waited for 15 rows to be generated).  

So, in 9i, if you want "real time" output from the procedure, you would simply use PIPE ROW instead of dbms_output and you would "select * from your_procedure" instead of execute your_procedure.

If your procedure modifies the database, you would have to code it as an autonomous transaction:

ops$tkyte@ORA9I.WORLD> create or replace function my_stored_proc( p_inputs in varchar2 )
  2  return messageTabType
  3  PIPELINED
  4  as<b>
  5          pragma autonomous_transaction;</b>
  6  begin
  7      for i in 1 .. 10
  8      loop
  9          pipe row( 'processing iteration      ' ||
 10                      i || ' ' || systimestamp );
 11          dbms_lock.sleep(1);<b>
 12          insert into t values ( i );</b>
 13          pipe row( 'done processing iteration ' ||
 14                      i || ' ' || systimestamp );
 15      end loop;
 16      pipe row( 'All done, success' );<b>
 17      commit;</b>
 18      return;
 19  end;
 20  /

Function created.

to avoid:

ORA-14551: cannot perform a DML operation inside a query
ORA-06512: at "OPS$TKYTE.MY_STORED_PROC", line 11
ORA-06512: at line 1

but otherwise it will work just fine. 

As I said in the other followup:

I can show you methods to get around this limit as well, all is not
lost, search for my_dbms_output on this site for some ideas

(or if you have my book, look at the dbms_output section. There i explain in gory detail how dbms_output works, how it packs data, why the 1,000,000 limit is there and how to get around it when you need)

The limit on dbms_output is hard and fast. We will have to use something else. MY_DBMS_OUTPUT is a method of doing this, search for it and the code is all there.

yes, we can see this 100% with SQL_TRACE:

C:\Documents and Settings\Thomas Kyte\Desktop>sqlplus tkyte/tkyte
SQL*Plus: Release 8.1.6.0.0 - Production on Wed Nov 21 15:45:48 2001
(c) Copyright 1999 Oracle Corporation. All rights reserved.

Connected to:
Oracle8i Enterprise Edition Release 8.1.6.0.0 - Production
With the Partitioning option
JServer Release 8.1.6.0.0 - Production

tkyte@TKYTE816> alter session set sql_trace=true;
Session altered.

tkyte@TKYTE816> set serveroutput on
tkyte@TKYTE816> set serveroutput off
tkyte@TKYTE816> alter session set sql_trace=false;
Session altered.

tkyte@TKYTE816> @gettrace

C.VALUE||'\ORA'||TO_CHAR(A.SPID,'FM00000')||'.TRC'
----------------------------------------------------------------------------------------------------

C:\oracle\admin\tkyte816\udump\ORA01252.trc

tkyte@TKYTE816> host type C:\oracle\admin\tkyte816\udump\ORA01252.trc

Dump file C:\oracle\admin\tkyte816\udump\ORA01252.TRC
Wed Nov 21 15:45:56 2001
ORACLE V8.1.6.0.0 - Production vsnsta=0
vsnsql=e vsnxtr=3
Windows 2000 Version 5.0 , CPU type 586
Oracle8i Enterprise Edition Release 8.1.6.0.0 - Production
With the Partitioning option
JServer Release 8.1.6.0.0 - Production
Windows 2000 Version 5.0 , CPU type 586
Instance name: tkyte816

Redo thread mounted by this instance: 1

Oracle process number: 12

Windows thread id: 1252, image: ORACLE.EXE


*** SESSION ID:(8.99) 2001-11-21 15:45:56.241
APPNAME mod='SQL*Plus' mh=3669949024 act='' ah=4029777240
=====================
PARSING IN CURSOR #1 len=33 dep=0 uid=427 oct=42 lid=427 tim=10030494 hv=3732290820 ad='2f6f128'
alter session set sql_trace=true
END OF STMT
EXEC #1:c=5,e=5,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=10030495
=====================
PARSING IN CURSOR #1 len=39 dep=0 uid=427 oct=47 lid=427 tim=10030728 hv=1585371720 ad='3fff3d4'
BEGIN DBMS_OUTPUT.ENABLE(1000000); END;
END OF STMT
PARSE #1:c=1,e=1,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=10030728
EXEC #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=4,tim=10030729
=====================
PARSING IN CURSOR #1 len=31 dep=0 uid=427 oct=47 lid=427 tim=10031043 hv=607327990 ad='401e258'
BEGIN DBMS_OUTPUT.DISABLE; END;
END OF STMT
PARSE #1:c=1,e=1,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=10031043
EXEC #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=4,tim=10031044
=====================
PARSING IN CURSOR #1 len=34 dep=0 uid=427 oct=42 lid=427 tim=10031515 hv=1582735206 ad='2f6c2f8'
alter session set sql_trace=false
END OF STMT
PARSE #1:c=1,e=1,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=10031516
EXEC #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=10031517

ops$tkyte@ORA920> set serveroutput on format wrapped
ops$tkyte@ORA920> exec dbms_output.put_line( 'how now brown cow, the fox ran away with the spoon' )
how now brown cow, the fox ran away with the spoon

PL/SQL procedure successfully completed.

ops$tkyte@ORA920> set linesize 30
ops$tkyte@ORA920> exec dbms_output.put_line( 'how now brown cow, the fox ran away with the spoon' )
how now brown cow, the fox ran
 away with the spoon

PL/SQL procedure successfully completed.

ops$tkyte@ORA920>


<b>set linesize 100</b>

you are missing something like that.  Suggestion -- it is probably cause you write in perl ;) -- but I think most people would find:

set serveroutput on format wrapped

lots less obscure then ... on for wra.  I know I did a double take trying to remember what exactly that meant. 

...
accept process prompt ">"
set termout off
STORE SET saved_settings REPLACE
set termout on
SET FEEDBACK OFF HEADING OFF
SPOOL query.sql
...

if you have my books -- you'll know my stance on this.

code in production needs to be instrumented even more than code in TEST!!!!!

you need the instrumented code to help debug in production, you cannot just drop in instrumented code at the last minute in production. in production -- stability is the keyword, no changes.

soooo -- leave it in. just leave it all in.

think about it... what if Oracle

o didn't have v$ tables (instrumentation)
o timed statistics
o sql_trace=true
o alert logs
o trace files
o events


sure, we could theoretically "run faster", but only if you got really really lucky. We would mostly run 1,000's of times slow cause you would have no real data with which to figure out "what is wrong"


Every other line of my code is DEBUG and it is always in production. Always. I write it in there from day1 (and wish more people would).....

Change the NO to YES in the url up there and see what happens.

I mandate that anyone that works for me -- or provides code to me in some fashion -- provides is fully instrumented as part of the design from day one.

I'm saying -- you need dbms_output in there in production more than you need it anywhere.

Leave it in, definitely. Imagine if we took away sql_trace, v$tables, statspack, etc when we shipped Oracle. You'd be doing the same thing by taking your instrumentation out for production. It would be the worst thing you can do.

spool does this

spool file.name
query
spool off

query result will appear on screen and in file

10g



ops$tkyte%ORA10GR2> set serveroutput on size unlimited
ops$tkyte%ORA10GR2>

<b>ops$tkyte%ORA10GR2> set linesize 32767
</b>ops$tkyte%ORA10GR2> DECLARE
  2     l_sql VARCHAR2(4000) :=
  3  'SELECT *
  4  FROM (
  5     SELECT OWNER,
  6            OBJECT_NAME,
  7            SUBOBJECT_NAME,
  8            OBJECT_ID,
  9            DATA_OBJECT_ID,
 10            OBJECT_TYPE,
 11            CREATED,
 12            LAST_DDL_TIME,
 13            TIMESTAMP,
 14            STATUS,
 15            TEMPORARY,
 16            GENERATED,
 17            SECONDARY
 18     FROM   all_objects
 19     WHERE  status = ''VALID''
 20     ORDER  BY object_name
 21  )
 22  WHERE  rownum <= 5';
 23
 24  BEGIN
 25     dbms_output.put_line(l_sql);
 26  END;
 27  /
SELECT *
FROM (
   SELECT OWNER,
          OBJECT_NAME,
          SUBOBJECT_NAME,
          OBJECT_ID,
          DATA_OBJECT_ID,
          OBJECT_TYPE,
          CREATED,
          LAST_DDL_TIME,
          TIMESTAMP,
          STATUS,
          TEMPORARY,
          GENERATED,
          SECONDARY
   FROM   all_objects
   WHERE  status = 'VALID'
   ORDER  BY object_name
)
WHERE  rownum <= 5

PL/SQL procedure successfully completed.

well, the documentation is not incorrect - set serveroutput on does in fact do that, but sqlplus doesn't know that was done - so sqlplus doesn't know to call "dbms_output.get_lines" afterwards.

the default setting of serveroutput is OFF (a sqlplus flag)

unless and until you turn it on - sqlplus is not aware you want it printed, it assumes you do not want the overhead of calling dbms_output.get_lines after every statement.

My point is that if 
   SET SERVEROUTPUT ON
in SQL*Plus has the effect of invoking
   DBMS_OUTPUT.ENABLE (buffer_size => NULL);
it is a quick trip-stumble-fall for a newbie to think that 
   DBMS_OUTPUT.ENABLE (buffer_size => NULL);
has the effect of invoking
   SET SERVEROUTPUT ON

Only if you use faulty logic.

You are saying "if A implies B, then B implies A"

If it is raining, the sidewalk is wet.
If the sidewalk is wet, it must be raining (no, i squirted a hose on it)


sqlplus is a client program - just like you could write (you could in fact write sqlplus, there is no magic to it, it is not "special").

Tell you what, why is it that when I run your developed java code and I set dbms_output on - you did not print the output for me?

As for the "But when I use utl_file.put_line, all of a
sudden sqlplus KNOWS to put it into the file I've defined."

well, I'm not really sure how to address that - because you seem to think sqlplus has something to do with the writing of the file - it does not.

sqlplus could be replaced with YOUR CODE and you call the procedure and the file appears, your code did NOTHING to make the file appear.


All dbms_output.put_line does it write to a buffer, an array, in memory. If the client wants to display it - that is fine, if they do not, that is fine - we don't care (in the server), we just either buffer the data (enable) or not (disable)

It is up to the client to retrieve and print the buffer out - if you do not tell sqlplus "RETRIEVE THIS BUFFER AND PRINT IT OUT", sqlplus (a client program, something you could write) will not print it out.

People would be completely annoyed if they said "sqlplus - do not print out anything" and sqlplus started printing out stuff - wouldn't then. serveroutput defaults to off - unless and until you turn it on - it would be a bug to print out anything.

you can call dbms_output.enable - BUT - sqlplus won't know you did that so you'd still need to tell sqlplus "hey, ENABLE OUTPUT please!!!" because sqlplus has to know to retrieve the data from dbms_output and print it.

ops$tkyte%ORA10GR2> set serveroutput off
ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> begin
  2          dbms_output.enable;
  3          dbms_output.put_line( 'hello world' );
  4  end;
  5  /

PL/SQL procedure successfully completed.

ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> begin
  2          dbms_output.put_line( 'more stuff' );
  3  end;
  4  /

PL/SQL procedure successfully completed.

ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> set serveroutput on
ops$tkyte%ORA10GR2> exec null
hello world
more stuff

PL/SQL procedure successfully completed.


ops$tkyte%ORA10GR2> set serveroutput off
ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> begin
  2  --      dbms_output.enable;
  3          dbms_output.put_line( 'hello world' );
  4  end;
  5  /

PL/SQL procedure successfully completed.

ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> begin
  2          dbms_output.put_line( 'more stuff' );
  3  end;
  4  /

PL/SQL procedure successfully completed.

ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> set serveroutput on
ops$tkyte%ORA10GR2> exec null

PL/SQL procedure successfully completed.

so there we see that calling dbms_output.enable enabled dbms_output - but sqplus doesn't KNOW to do it until you tell it.

In the dbms_output package, there is a boolean variable. it defaults to FALSE.

If it is set to false, then when you call dbms_output.put_line, put_line just returns - it does nothing, there is no output.

when you call dbms_output.enable (that is what set serveroutput on in sqlplus does), it sets that flag to true. That makes it so that dbms_output.put_line doesn't just return, it actually records the output so that toad, sqplus,whatever can call dbms_output.get_lines at the end of your plsql call to show you the output it accumulated.

ops$tkyte%ORA11GR2> show serveroutput
serveroutput ON SIZE 1000000 FORMAT WORD_WRAPPED
ops$tkyte%ORA11GR2> exec dbms_output.disable

PL/SQL procedure successfully completed.

ops$tkyte%ORA11GR2> show serveroutput
serveroutput ON SIZE 1000000 FORMAT WORD_WRAPPED
ops$tkyte%ORA11GR2> exec dbms_output.put_line( 'hello' );

PL/SQL procedure successfully completed.

ops$tkyte%ORA11GR2> exec dbms_output.enable

PL/SQL procedure successfully completed.

ops$tkyte%ORA11GR2> exec dbms_output.put_line( 'hello' );
hello

PL/SQL procedure successfully completed.

the command "set serveroutput on" simply issues "dbms_output.enable(...)"

If you explicitly disable output (which you must be doing somewhere, in some stored procedure, in some login.sql script, some script you are running) - then sqlplus might THINK it is enabled - but the database begs to differ


so, look around for someone calling dbms_output.disable