Follow

Use Runtime Tracing

Introduction

Elastic COBOL Runtime Tracing is an internal runtime facility that provides tracing information with contextual data.

Tracing covers COBOL paragraphs/sections, calls, performs, gotos, and file i/o & SQL i/o operations. It can also be used to provide simple time profiling, either between each trace or to measure the time an application takes to execute.

Options

Tracing is enabled with compiler directives. Tracing information can be controlled at runtime using environment variables.

Compiler directives (can be combined):

  • -run:trace -- activates trace for PARAGRAPH/SECTION, CALL, GOTO, PERFORM and FILE I/O & SQL I/O operations
  • -run:tracetime -- activates trace for PARAGRAPH/SECTION, CALL, GOTO, PERFORM and FILE I/O & SQL I/O operations and measures the time between each activated trace (in seconds)
  • -run:tracepara -- activates trace for PARAGRAPH & SECTION only
  • -run:tracecall -- activates trace for CALL only
  • -run:tracegoto -- activates trace for GOTO only
  • -run:traceperf -- activates trace for PERFORM only
  • -run:traceio -- activates trace for FILE I/O operations only
  • -run:tracesql -- activates trace for SQL I/O operations only
  • -run:traceage -- measures time (the age) of app execution (in seconds)

Runtime settings (can be set in cblconfig and/or environment):

  • RUN_TRACE=0|1 -- turns 'trace' on/off
  • RUN_TRACETIME=0|1 -- turns 'tracetime' on/off
  • RUN_TRACEPARA=0|1 -- turns 'tracepara' on/off
  • RUN_TRACECALL=0|1 -- turns 'tracecall' on/off
  • RUN_TRACEGOTO=0|1 -- turns 'tracegoto' on/off
  • RUN_TRACEPERF=0|1 -- turns 'traceperf' on/off
  • RUN_TRACEIO=0|1 -- turns 'traceio' on/off
  • RUN_TRACESQL=0|1 -- turns 'tracesql' on/off
  • RUN_TRACEAGE=0|1 -- turns 'traceage' on/off

Use Examples

$ ecobol -run:trace a.cbl b.cbl c.cbl
Elastic COBOL V19.1.1 Copyright (C) 2010-2019 Heirloom Computing
LOC: 51 (11 variables in 8 records)
Warnings: 0
Errors: 0
Result: Compilation SUCCESSFUL
Building: Class files
$ java a
PROG=[a] SECT=[A-SECTION] SOURCE=[a.cbl]
PROG=[a] PARA=[A-PARA OF A-SECTION] SOURCE=[a.cbl]
PROG=[a]*CALL=[b:literal] USING=[(null)]
PROG=[b] SECT=[B-SECTION] SOURCE=[b.cbl]
PROG=[b] PARA=[B-PARA OF B-SECTION] SOURCE=[b.cbl]
PROG=[b] SECT=[B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B1-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B2-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[b]*CALL=[c:literal] USING=[lnk.b_item]
PROG=[c] SECT=[C-SECTION] SOURCE=[c.cbl]
PROG=[c] PARA=[C-PARA OF C-SECTION] SOURCE=[c.cbl]
PROG=[a]*CALL=[b:wrk.b_name.toDisplayString()] USING=[wrk.a_item,wrk.b_item] GIVING=[wrk.x_item]
PROG=[b] SECT=[B-SECTION] SOURCE=[b.cbl]
PROG=[b] PARA=[B-PARA OF B-SECTION] SOURCE=[b.cbl]
PROG=[b] SECT=[B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B1-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B2-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[b]*CALL=[c:literal] USING=[lnk.b_item]
PROG=[c] SECT=[C-SECTION] SOURCE=[c.cbl]
PROG=[c] PARA=[C-PARA OF C-SECTION] SOURCE=[c.cbl]
PROG=[a]*CALL=[c:literal] USING=["fred","bill","jane"]
PROG=[c] SECT=[C-SECTION] SOURCE=[c.cbl]
PROG=[c] PARA=[C-PARA OF C-SECTION] SOURCE=[c.cbl]
PROG=[a]*CALL=[b:wrk.c_name.toDisplayString()] USING=["123","456","78.9"]
PROG=[b] SECT=[B-SECTION] SOURCE=[b.cbl]
PROG=[b] PARA=[B-PARA OF B-SECTION] SOURCE=[b.cbl]
PROG=[b] SECT=[B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B1-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B2-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[b]*CALL=[c:literal] USING=[lnk.b_item]
PROG=[c] SECT=[C-SECTION] SOURCE=[c.cbl]
PROG=[c] PARA=[C-PARA OF C-SECTION] SOURCE=[c.cbl]
PROG=[a]*CALL=[c:wrk.c_name.toDisplayString()] USING=[wrk.x_item,"STRING"]
PROG=[c] SECT=[C-SECTION] SOURCE=[c.cbl]
PROG=[c] PARA=[C-PARA OF C-SECTION] SOURCE=[c.cbl]
PROG=[a] PARA=[A-EXIT OF A-SECTION] SOURCE=[a.cbl]
PROG=[a]*CALL=[M$ALLOC:literal] USING=["1048576",wrk.p_item]
$ export RUN_TRACE=0
$ java a
[no output]
$ unset RUN_TRACE
$ export RUN_TRACEPARA=0
$ java a
PROG=[a]*CALL=[b:literal] USING=[(null)]
PROG=[b]*CALL=[c:literal] USING=[lnk.b_item]
PROG=[a]*CALL=[b:wrk.b_name.toDisplayString()] USING=[wrk.a_item,wrk.b_item] GIVING=[wrk.x_item]
PROG=[b]*CALL=[c:literal] USING=[lnk.b_item]
PROG=[a]*CALL=[c:literal] USING=["fred","bill","jane"]
PROG=[a]*CALL=[b:wrk.c_name.toDisplayString()] USING=["123","456","78.9"]
PROG=[b]*CALL=[c:literal] USING=[lnk.b_item]
PROG=[a]*CALL=[c:wrk.c_name.toDisplayString()] USING=[wrk.x_item,"STRING"]
PROG=[a]*CALL=[M$ALLOC:literal] USING=["1048576",wrk.p_item]
$ unset RUN_TRACEPARA
$ export RUN_TRACECALL=0
$ java a
PROG=[a] SECT=[A-SECTION] SOURCE=[a.cbl]
PROG=[a] PARA=[A-PARA OF A-SECTION] SOURCE=[a.cbl]
PROG=[b] SECT=[B-SECTION] SOURCE=[b.cbl]
PROG=[b] PARA=[B-PARA OF B-SECTION] SOURCE=[b.cbl]
PROG=[b] SECT=[B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B1-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B2-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[c] SECT=[C-SECTION] SOURCE=[c.cbl]
PROG=[c] PARA=[C-PARA OF C-SECTION] SOURCE=[c.cbl]
PROG=[b] SECT=[B-SECTION] SOURCE=[b.cbl]
PROG=[b] PARA=[B-PARA OF B-SECTION] SOURCE=[b.cbl]
PROG=[b] SECT=[B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B1-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B2-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[c] SECT=[C-SECTION] SOURCE=[c.cbl]
PROG=[c] PARA=[C-PARA OF C-SECTION] SOURCE=[c.cbl]
PROG=[c] SECT=[C-SECTION] SOURCE=[c.cbl]
PROG=[c] PARA=[C-PARA OF C-SECTION] SOURCE=[c.cbl]
PROG=[b] SECT=[B-SECTION] SOURCE=[b.cbl]
PROG=[b] PARA=[B-PARA OF B-SECTION] SOURCE=[b.cbl]
PROG=[b] SECT=[B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B1-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[b] PARA=[B2-PARA OF B-EXTENDED] SOURCE=[b.cbl]
PROG=[c] SECT=[C-SECTION] SOURCE=[c.cbl]
PROG=[c] PARA=[C-PARA OF C-SECTION] SOURCE=[c.cbl]
PROG=[c] SECT=[C-SECTION] SOURCE=[c.cbl]
PROG=[c] PARA=[C-PARA OF C-SECTION] SOURCE=[c.cbl]
PROG=[a] PARA=[A-EXIT OF A-SECTION] SOURCE=[a.cbl]
$ unset RUN_TRACECALL
$ ecobol -run:tracecall -run:tracetime a.cbl b.cbl c.cbl
$ export RUN_TIMEFORMAT=###.### [this format is as per the Java DecimalFormat class]
$ java a
TIME=[0.035] PROG=[a]*CALL=[b:literal] USING=[(null)]
TIME=[0.002] PROG=[b]*CALL=[c:literal] USING=[lnk.b_item]
TIME=[0.013] PROG=[a]*CALL=[b:wrk.b_name.toDisplayString()] USING=[wrk.a_item,wrk.b_item] GIVING=[wrk.x_item]
TIME=[0.009] PROG=[b]*CALL=[c:literal] USING=[lnk.b_item]
TIME=[0.004] PROG=[a]*CALL=[c:literal] USING=["fred","bill","jane"]
TIME=[0.001] PROG=[a]*CALL=[b:wrk.c_name.toDisplayString()] USING=["123","456","78.9"]
TIME=[0.005] PROG=[b]*CALL=[c:literal] USING=[lnk.b_item]
TIME=[0.004] PROG=[a]*CALL=[c:wrk.c_name.toDisplayString()] USING=[wrk.x_item,"STRING"]
TIME=[0.001] PROG=[a]*CALL=[M$ALLOC:literal] USING=["1048576",wrk.p_item]
$ ecobol -run:traceage a.cbl b.cbl c.cbl
$ java a
$ java a
AGE =[Running...]
AGE =[0.331]
$ export RUN_TRACE=0
$ export RUN_TRACECALL=1
$ java a
[no output -- RUN_TRACE overrides all other settings]

 

Was this article helpful?
0 out of 0 found this helpful
Have more questions? Submit a request

0 Comments

Please sign in to leave a comment.
Powered by Zendesk