Trace Script Processing on Devices Running Junos OS Evolved
When you execute an interactive script, the script can generate output, including warnings and errors, in the CLI or RPC reply. When the system triggers non-interactive scripts, for example, when an event policy triggers an event script, the script does not direct output to the terminal. In either case, you might need more information about the execution of the script. Junos OS Evolved captures trace data for all applications by default. You can view the collected traces for additional script processing information, including the memory and CPU usage, script arguments, script execution, and warnings and errors.
Junos OS Evolved collects trace data from all applications on all nodes on the Routing Engine. Whereas Junos OS logs the trace data for each type of script in separate log files, Junos OS Evolved stores the trace data for all scripts in the same location. The trace log includes data for commit, event, op, and SNMP scripts; YANG action and translation scripts; and Juniper Extension Toolkit scripts.
How to Display Trace Data for Scripts
Junos OS Evolved stores the trace data from all nodes that is collected on the primary
Routing Engine under the /var/log/traces directory. The
cscript application handles scripts, and the trace data for scripts is
stored under the
node.cscript.sequence-number
subdirectories.
To view trace data for scripts, issue the show trace application cscript
operational mode command.
user@host> show trace application cscript 2021-05-20 09:11:42.239695672 re0:cscript:4176:TRACE_INFO CSCRIPT_RUSAGE_CSCRIPT_RUSAGE_1 msg = "Process's current softlimit [134217728] hardlimit [-1]" 2021-05-20 09:11:42.239773157 re0:cscript:4176:TRACE_INFO CSCRIPT_RUSAGE_CSCRIPT_RUSAGE_1 msg = "Process's limits are already set by parent process" 2021-05-20 09:11:42.239812430 re0:cscript:4176:TRACE_INFO CSCRIPT_EVENTS_CSCRIPT_EVENTS_1 msg = "op script processing begins" 2021-05-20 09:11:42.239855140 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: /usr/libexec/ui/cscript" 2021-05-20 09:11:42.239865140 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: -mop" 2021-05-20 09:11:42.239866196 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: -p" 2021-05-20 09:11:42.239867156 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: /" 2021-05-20 09:11:42.239868116 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: -Q2" 2021-05-20 09:11:42.239869131 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: -f" 2021-05-20 09:11:42.239882048 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: hello.py" 2021-05-20 09:11:42.239883202 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: -d134217728" 2021-05-20 09:11:42.239884135 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: -E" 2021-05-20 09:11:42.239885131 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: user admin logname admin host host tty /dev/pts/0 agent op-script current-directory /var/home/admin pid 32212 ppid 32206" 2021-05-20 09:11:42.239886175 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: -u" 2021-05-20 09:11:42.239887176 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: admin" 2021-05-20 09:11:42.239888251 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: -U" 2021-05-20 09:11:42.239889287 re0:cscript:4176:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: -i9" 2021-05-20 09:11:42.245988806 re0:cscript:4176:TRACE_INFO CSCRIPT_EVENTS_CSCRIPT_EVENTS_1 msg = "running op script 'hello.py'" 2021-05-20 09:11:42.246006519 re0:cscript:4176:TRACE_INFO CSCRIPT_EVENTS_CSCRIPT_EVENTS_1 msg = "opening op script '/var/db/scripts/op/hello.py'" ...
You can include the terse option to display just the timestamp and
message.
user@host> show trace application cscript terse 2021-05-20 09:11:42.239695672 msg = "Process's current softlimit [134217728] hardlimit [-1]" 2021-05-20 09:11:42.239773157 msg = "Process's limits are already set by parent process" 2021-05-20 09:11:42.239812430 msg = "op script processing begins" ...
You can also refine the traces to display by specifying the trace time elapsed, process ID, and node. For example, the following command shows trace data for a specific process ID.
user@host> show trace application cscript pid 10683 2021-05-24 09:42:09.552687492 re0:cscript:10683:TRACE_INFO CSCRIPT_RUSAGE_CSCRIPT_RUSAGE_1 msg = "Process's current softlimit [134217728] hardlimit [-1]" 2021-05-24 09:42:09.552819712 re0:cscript:10683:TRACE_INFO CSCRIPT_RUSAGE_CSCRIPT_RUSAGE_1 msg = "Process's limits are already set by parent process" 2021-05-24 09:42:09.552897412 re0:cscript:10683:TRACE_INFO CSCRIPT_EVENTS_CSCRIPT_EVENTS_1 msg = "action script processing begins" 2021-05-24 09:42:09.553025992 re0:cscript:10683:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: /usr/libexec/ui/cscript" 2021-05-24 09:42:09.553095062 re0:cscript:10683:TRACE_INFO CSCRIPT_ARGUMENTS_CSCRIPT_ARGUMENTS_1 msg = "arg: -maction" ...
How to Modify Trace Settings for Scripts
Junos OS Evolved traces script processing by default and traces all applications at the
info level for informational messages. You can configure trace settings for specific
applications at the [edit system application] hierarchy level. For example,
you can specify the trace level of the application on a given node.
To modify script tracing operations, configure the settings under the [edit system
trace application cscript] hierarchy level. The following example configures the
cscript application to trace script processing on node re0 at the debug
level:
[edit] user@host# set system trace application cscript node re0 level debug user@host# commit
For more information about configuring trace settings, see trace.