topic Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD? in Operating System - OpenVMS

SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Michael Moroney — Wed, 17 Feb 2010 18:45:44 GMT

I did a SHOW PROCESS/CONTINUOUS of a wayward process and often it is shown as being in CUR mode, but with a PC = 2BAD2BAD.CODE2BAD and a PSL = CODE2BAD, obviously bogus values. Other tools show that it is spending excessive time in kernel mode. Am I correct in assuming that SHOW PROCESS/CONTINUOUS displays those values when the process is at high IPL and not interruptable? (yes I know the concept of a "current" process is ambiguous above sched IPl)

This is OpenVMS V8.3 on an Integrity rx3600.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

John Gillings — Wed, 17 Feb 2010 20:40:35 GMT

Michael,

This is unlikely to be documented except in the source code. Addresses like 2BAD2BAD (and a few others, like DEADBEEF are scattered in the source code as flags).

This *may* be something in SHOW.EXE, but it's also possible it's in the scheduler or $GETJPI. FWIW, I can't see any instances of the string "2BAD" in SHOW.EXE.

Having worked on a derivative of SHOW PROCESS/CONTINUOUS back in VAX days, at that time it got most of its information from globally visible (though privileged) data structures, and the rest from $GETJPI, so chances are SHOW is just displaying what it found. Something else is planting the data. It must have changed fairly radically since then as a lot of the VAX code wasn't portable to Alpha, let alone Integrity.

As they say "Use the Source (Luke)".

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Michael Moroney — Wed, 17 Feb 2010 22:44:57 GMT

There is no "C0DE2BAD" anywhere in the source, list or map of the executable, and I can't find either that string nor its binary equivalent on sys$sysdevice:, which is puzzling.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

H.Becker — Wed, 17 Feb 2010 23:30:11 GMT

As far as I know the SHOW PROCESS queues a special kernel mode AST to the target process. Once that is delivered it walks the call stack and retrieves the PC/PSL of the code thread that was interrupted by this AST. That pair is reported back and displayed by SHOW PROCESS.

If walking the stack fails, for whatever reason, special values are reported: 2BAD...

While walking the stack is simple for VAX and Alpha, it is very different and complex for I64.

Unfortunately there is no indication from the special PC/PSL what the actual failure in walking the stack was. So it is difficult to say why it failed. But these codes do not indicate a problem in your image. You should be able to find the string in sys$loadable_images, in the process management image.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Michael Moroney — Thu, 18 Feb 2010 05:18:20 GMT

I know Shadowing used 2BAD codes. I know how bad frame tracing is on the Itanium, I had to deal with that a couple of years ago.

I used the PC sampler in SDA to see what's going on and why the process is using more CPU time and is visibly slower. I see lots of time in F11BXQP at IPL 8, routine DEL_EXTFCB_C. Now I have to find out what that means. Weird in that it doesn't do much file IO.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Volker Halle — Thu, 18 Feb 2010 07:45:49 GMT

Michael,

DEL_EXTFCB in [F11X]CLENUP removes and de-allocates Extension FCBs (File Control Blocks) linked to a primary FCB during a cleanup operation after a successfully completed file operation.

Is this program working with very fragmented files or files with man ACLs and therefore with many extension file headers ? Or are there a huge number of files open on the associated volumes ? High Trans Count on the mounted devices ?

DEL_EXTFCB runs in kernel mode and follows the FCB queues to the VCB to decrement the transaction count. Long lists of FCBs to be followed may cause this behaviour.

Volker.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Jur van der Burg — Thu, 18 Feb 2010 16:24:46 GMT

The code comes from [sys]proc_read_write_reg.c, routine exe$read_process_reg_ast. It is walking the stack and has a problem interpreting that.

Fwiw,

Jur.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Michael Moroney — Fri, 19 Feb 2010 00:52:52 GMT

I'm going to guess that exe$read_process_reg_ast cannot access the process' registers when the process is at IPL 8, hence the bogus values.

I looked at the drive and it is somewhat fragmented. What is interesting is the process doesn't do much I/O to the drive but another process which uses it heavily is hardly affected. Anyway, I told them to defrag the drive the next chance they get.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Volker Halle — Fri, 19 Feb 2010 06:53:45 GMT

Michael,

DEL_EXTFCB is called to clean up after 'file operations', so just doing IO on open files may not call this routine. Just opening and closing (fragmented) files may cause this behaviour !

Volker.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

H.Becker — Fri, 19 Feb 2010 10:27:48 GMT

Any guess why the name has the "_ast" suffix at all? Or in other words, if at lower IPL, how can code in one process get the PC/PSL of another process?

2BAD2BAD.CODE2BAD shows a problem in walking the call stack not finding the AST frame. It is not an indicator that the target process is at a high IPL.

There were changes in the unwind code after V8.3. But I don't know why the AST frame isn't found in your environment and if any changes so far can fix that.

But I'm sure, this is not the real problem you want to solve. You seem to have a performance problem and SHOW PROCESS/CONT can't help you to find out whats going on.

PS: I was somehow wrong about finding the string in the image. I forgot that moving a 64 bit literal into a register (MOVL) splits the immediate operand into pieces and then into two slots so you can't see the literal as a whole in the code segment of the image. However, ANALYZE/IMAGE/SEGMENT=CODE can show the MOVL and the literal.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Ian Miller. — Fri, 19 Feb 2010 16:57:50 GMT

You may want to use PRF or PCS to see where that processing is spending it's excessive kernel mode time.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Michael Moroney — Fri, 19 Feb 2010 19:12:38 GMT

Yes this is a performance issue. A process wakes up once a second and checks for things to do from a network socket, something that should take milliseconds but has crept up to almost 1/2 second. I initially used show process/cont to try to see where in the code it was spending its time, and most of its time was shown at the bogus address. PCS from SDA has told me it spends most of its time in the XQP at IPL 8.

I noticed the code has a C fsynch() call on each pass. If the disk the file being fsynched is on is fragmented, but the file itself isn't very fragmented, would there be excessive XQP time? There would be 0 or 1 fprintf() calls between the fsynch() calls. The file currently has 5 extents.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Volker Halle — Fri, 19 Feb 2010 19:27:36 GMT

Michael,

I described the operation of DEL_EXTFCB in a previous reply. The code walks FCB chains to the VCB. Are there many files open on that disk ?

Why not write a simple example program doing fsync calls in a tight loop and watch the performance of that test program ?

Volker.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Michael Moroney — Fri, 19 Feb 2010 21:12:33 GMT

That was a good idea, I ran a program that was a loop with a single fprintf(), an fsync() and sleep(1) with the file on the fragmented disk. This is a simplification of the main loop of the program. It ran using very little CPU time, so the problem isn't the fsync to the fragmented disk.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Hoff — Sat, 20 Feb 2010 01:17:42 GMT

Entirely for giggles, try this on the file involved:

SET FILE /CACHING_ATTRIBUTE=NO_CACHING file

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Michael Moroney — Tue, 23 Feb 2010 01:40:14 GMT

We can't apply the cache attribute to an open file. Customer pretty much doesn't want to shut down the application unless there's essentially a near-guarantee of a fix. They're open to get the disk defragmented although I can't explain while another process that's a much heavier user of the drive doesn't seem to have any issues.

I just noticed that SDA also has the "2BADCODE" (as well as "1BADCODE") problem with SHOW PROCESS/FULL but SDA PCS module doesn't.

Those who are into XQP may be amused by the attached pcs sh trace/stat output.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Hein van den Heuvel — Tue, 23 Feb 2010 04:27:34 GMT

fflush just gives records from the Crtl to RMS
fsync maps to an RMS $FLUSH which will tell the xqp to update the file header.

You did not mention revision (-H1?) or patch level. The makes the PCS trace (nice! ) data ambiguous.
Maybe you can use ANAL/SYS.. EXA/INST for one or two of the popular instructions to make sure we are looking at the same sources.
Like that 624 DEL_EXTFCB_C+00360
Is that a "ld4 r18 = [r27]" per chance?
I'm thinking it may be in...
UNTIL .P[VCB$B_TYPE] EQL DYN$C_VCB DO P = .P[FCB$L_FCBFL];

Also, is the system burning significant MPsync?
How about a spinlock trace, perhaps using @ SYS$EXAMPLES:SPL
Is there a lot of FILSYS time?

- Is this a cluster or standalone
- Any TRUNCATE calls happening?

fwiw,
Hein.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Volker Halle — Tue, 23 Feb 2010 07:42:03 GMT

Michael,

this process is clearly spending a lot of CPU cycles in DEL_EXTFCB. One question would be, why does it get there ? The other question is, why does it spend so much time in there once it gets there ?

There are a couple of loops in this routine, which walk the FCB chains.

$ ANAL/SYS
SDA> SHOW DEV disk-device-name
SDA> READ SYSDEF
SDA> VALI QUE vcb+vcb$l_fcbfl

How many FCBs are in that queue ?

Volker.

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Jur van der Burg — Tue, 23 Feb 2010 07:57:07 GMT

>I just noticed that SDA also has the "2BADCODE" (as well as "1BADCODE") problem with SHOW PROCESS/FULL but SDA PCS module doesn't.<

Of course pcs does not display that. The pc is fabricated and never actually sess that address.

Jur (PCS author).

Re: SHOW PROCESS/CONT shows PC=2BAD2BAD.CODE2BAD?

Volker Halle — Tue, 23 Feb 2010 09:07:32 GMT

Michael,

when RMS is flushing the buffers, it looks like it only updates the file header (via a call to the XQP), if the end-of-file block number (IFB$L_EBK) has changed. So a simple fsync test without actually writing to the file may not trigger the behaviour seen in the application.

Volker.