Creating a log file to trap system failures

Started by Mike King, October 21, 2019, 04:44:16 PM

Previous topic - Next topic

Mike King

Whenever a application failure occurs within PxPlus (GPF, Segmentation fault, etc) the system will attempt to record key system information on the system LOGFILE in the hopes it will provide insight as to what caused the failure.  Given this, if you are having problems you should assign a log file to your tasks in order to assist in problem resolution, however managing these LOGFILEs can be problematic.

One simple solution is to create individual log file for each process, place these in a separate directory and have the system delete them if the process normally terminates.  Here is an example of some logic you can use to accomplish this:

x$="log_directory/log."+dte(0:"MMDD-%Hz%mz")+"."+str(tcb(89))+".txt
serial x$
setdev (0) set "Logfile" to x$

open (gfn) x$
setdev (lfo) set "DeleteOnClose" to "Yes"


Basically the logic creates a unique log file name based on the date, time and process id and assigns as the application LOGFILE.  In order to have the system automatically delete the file when the session closes, we OPEN the file on a global channel and then set its "DeleteOnClose" property so that when the PxPlus shuts down normally, the file will be deleted. 

Should the PxPlus process terminate abnormally for any reason the DeleteOnClose will not occur leaving the failing LOGFILE on the system for subsequent analysis.

NOTE: If desired you can have your application also write information to this LOGFILE using the SETTRACE RECORD string$
Mike King
President - BBSysco Consulting
eMail: mike.king@bbsysco.com

Gilles

Interesting
Is this available for all operating systems?
What is it written automatically in this file by Pxplus?

Thomas Bock

Can this be applied to the client side as well?
We have an increasing number of issues concerning vanishing processes while doing CSV-imports to Excel. Maybe this can put some light to such situations.

Frank Dre├čler

If you want to see how the log would look, you can cause a memory access violation with the following PXP code. This triggers the creation of the log file.

The code works under the assumption that strings in PXP are stored in memory prefixed with 4 bytes that store their length. This assumption can be verified by patching the length prefix of a 16 B string to e.g. 4, then read the variable and see that only 4 bytes are returned.

The following code creates a string, then patches the length to 1 G (0x40 00 00 00), then reads the string, hoping that somewhere in that 1 G range there is memory that may not be read. This leads to a crash and the log file is written.


x$ = ""
_$ = mem(mem(x$)-4, swp($40000000$))
print x$

Thomas Bock

Great!
I hope someone on this planet can do something useful that ;)

Oct 23 16:23 [<sigterm>:0] Segmentation fault
Oct 23 16:23 [<sigterm>:0]  - ERR=0 CTL=0 RET=258 LFA=0 LFO=32767
Oct 23 16:23 [<sigterm>:0]  - Last path used: /u1/gui/pvx/1400/lib/_cmd/system/paste
Oct 23 16:23 [<sigterm>:0] --- Program stack ---
Oct 23 16:23 [<sigterm>:0]  - STK(0) = line 00000 in <no name>
Oct 23 16:23 [<sigterm>:0] --- Files ---
Oct 23 16:23 [<sigterm>:0]  - PTH(0) =
Oct 23 16:23 [<sigterm>:0]  - PTH(64999) = /u1/tmp/pid-20191023-162327-27356-01.txt
Oct 23 16:23 [<sigterm>:0]  - PTH(65000) = *memory*;keydef=[1:1:30:C]+[2:1:30:C]+[3:1:30:C]
Oct 23 16:23 [<sigterm>:0]  - PTH(65003) = /u1/koss/pgm/ab/res/mawimsg.de
Oct 23 16:23 [<sigterm>:0]     - Keyed file.  KEY:<Start of file>
Oct 23 16:23 [<sigterm>:0]  - PTH(65003) = /u1/koss/pgm/fi/res/fimsg.de
Oct 23 16:23 [<sigterm>:0]     - Keyed file.  KEY:<Start of file>
Oct 23 16:23 [<sigterm>:0]  - PTH(65003) = /u1/koss/pgm/gd/res/gdmsg.de
Oct 23 16:23 [<sigterm>:0]     - Keyed file.  KEY:<Start of file>
Oct 23 16:23 [<sigterm>:0]  - PTH(65003) = /u1/koss/pgm/gd/res/_msglib.de
Oct 23 16:23 [<sigterm>:0]     - Keyed file.  KEY:<Start of file>
Oct 23 16:23 [<sigterm>:0] --- Err() Info ---
Oct 23 16:23 [<sigterm>:0]        Current Err:12 Prog:  Stno: 64999 LFA: 1 LastPath: *udev/WINDOWS (pvxlod.c@782)
Oct 23 16:23 [<sigterm>:0] --- Stack dump ---
Oct 23 16:23 [<sigterm>:0] linux-gate.so.1(__kernel_sigreturn+0) [0xf77a9e50]
Oct 23 16:23 [<sigterm>:0] /u1/gui/pvx/1400/pxplus() [0x804d84a]
Oct 23 16:23 [<sigterm>:0] /u1/gui/pvx/1400/pxplus() [0x804c687]
Oct 23 16:23 [<sigterm>:0] /u1/gui/pvx/1400/pxplus() [0x804b1d6]
Oct 23 16:23 [<sigterm>:0] /u1/gui/pvx/1400/pxplus() [0x804adf3]
Oct 23 16:23 [<sigterm>:0] /u1/gui/pvx/1400/pxplus() [0x804acb5]
Oct 23 16:23 [<sigterm>:0] /u1/gui/pvx/1400/pxplus() [0x804aad4]
Oct 23 16:23 [<sigterm>:0] /u1/gui/pvx/1400/pxplus() [0x8115bf5]
Oct 23 16:23 [<sigterm>:0] /u1/gui/pvx/1400/pxplus() [0x8115b59]
Oct 23 16:23 [<sigterm>:0] /lib/libc.so.6(__libc_start_main+0xf3) [0xf7591993]

Mike King

If you are having a problem and have a log file you should forward it to whoever provides you product support.

The log generally provides us some indication as to the current directive being used, files opened, along with some internal stack information which can often be helpful in determining the nature of the problem.

In the case of log file you posted the error was caused by something you entered at command mode and the last file you accessed was the command line utility 'paste'.

We suspect you copied the code Frank posted.  :)

Mike King
President - BBSysco Consulting
eMail: mike.king@bbsysco.com

Thomas Bock

Yes, I pasted Frank's sample.
Meanwhile I tried the log file on the windx side. It seems to work, though I cannot force a GPF.

logFileName$ = "C:\Users\bock\AppData\Local\Temp\WindXLog.txt"
serial "[WDX]" + logFileName$
cmd$ = "setdev (0) set " + quo + "Logfile" + quo + " to " + quo + logFileName$ + quo
execute "[WDX]" + cmd$
,cmd$ = "open (gfn) " + quo + logFileName$ + quo
execute "[WDX]" + cmd$
cmd$ = "setdev (lfo) set " + quo + "DeleteOnClose" + quo + " to " + quo + "Yes" + quo
execute "[WDX]" + cmd$

Mike King

To force a GPF in Windows or fault on Linux try

X = dll (*,0)

Basically force the program to execute a external call to location zero.

For WindX try an EXECUTE "[lcl]x=dll(*,0)"

Mike King
President - BBSysco Consulting
eMail: mike.king@bbsysco.com