[Search for users] [Overall Top Noters] [List of all Conferences] [Download this site]

Conference turris::debug

Title:DEBUG
Notice:Updated locations for reporting QARs -- see note 834.1
Moderator:LOWFAT::DIETER
Created:Fri Jan 24 1986
Last Modified:Wed Jun 04 1997
Last Successful Update:Fri Jun 06 1997
Number of topics:1868
Total number of notes:8200

1840.0. "%DEBUG-I-EXPMEMPOOL using V7.0-03" by CSC32::V_HAVER () Fri Feb 28 1997 20:25

The following COBOL code reproduces the EXPMEMPOOL error when doing SET WATCH on
an array.  It also shows that the array looks as if it is being written to
incorrectly.  Without the SET WATCH, the code runs fine and the array looks ok.
If I do the SET WATCH, do GO a few times (which displays array elements 
incorrectly) and then deactivate the watch, the code runs fine and the array
now looks ok.

Code is running on OpenVMS Alpha V7.0, Debugger ident is V7.0-03.  I just
applied ALPDEBU06_070.  Note 1824 seemed to indicate a similar problem had been
found and fixed in ALPDEBU06_070, but didn't help.

We have had similar reports in Ada, C, etc. but it is hard to get a reproducer.
After the EXPMEMPOOL, the programs may report other errors later in the run
such as ACCVIO, ROPRAND, and from the latest one I have in Ada, %ADA-E-FORTRABAC.

COBOL example:

$COB/NOOPT/DEB/CHECK=ALL SETWATCH
$LINK/DEB SETWATCH

IDENTIFICATION DIVISION.
     program-id.  setwatch.

ENVIRONMENT DIVISION.

DATA DIVISION.
     working-storage section.
     01  cnter   pic 99.
     01  RP-RECORD.
         03 RPID occurs 100 times.
            05 RPIDA pic x(10).
            05 RPIDB pic x(10).
            05 RPIDC pic x(10).
            05 RPIDD pic x(10).
            05 RPIDE pic x(10).
     01 abc pic 9(9).
     01 RPSUB pic 999 value 0.
PROCEDURE DIVISION.
para-main.
         move zeros to cnter.
         display 'count: ' cnter.

para1.
         move 1 to abc.
         display abc.

para2.
         display 'In Para2'.
         perform 100 times
             add 1 to rpsub
             move 'aaaaaaaaaa' to RPIDA (rpsub)
             move 'aaaaaaaaaa' to RPIDB (rpsub)
             move 'aaaaaaaaaa' to RPIDC (rpsub)
             move 'aaaaaaaaaa' to RPIDD (rpsub)
             move 'aaaaaaaaaa' to RPIDE (rpsub)
             display 'count: ' rpsub
         end-perform.
         stop run.




Note: It doesn't seem to matter if I do the set watch before or after
the first GO.


$RUN SETWATCH


         OpenVMS Alpha DEBUG Version V7.0-03R

%DEBUG-I-INITIAL, Language: COBOL, Module: SETWATCH
%DEBUG-I-NOTATMAIN, Type GO to reach MAIN program

DBG> set watch rp-record
DBG> set break/exception
DBG> go
%DEBUG-I-EXPMEMPOOL, expanding debugger memory pool
break at routine SETWATCH_PROB
     2:      program-id.  setwatch-prob.
DBG> go
count: 00
000000001
In Para2
watch of RPIDA of RPID of SETWATCH_PROB\RP-RECORD(1) at SHARE$LIBOTS_CODE0+3896
   old value: ".........."
   new value: "aaaaaaaa.."
break at SHARE$LIBOTS_CODE0+3900
%DEBUG-I-SOURCESCOPE, Source lines not available for .0\%PC
        Displaying source in a caller of the current routine
    35:              move 'aaaaaaaaaa' to RPIDB (rpsub)
DBG> exam rpida(1)
RPIDA of RPID of SETWATCH_PROB\RP-RECORD(1):    "aaaaaaaa.."
DBG> exit

The following gives the EXPMEMPOOL but doesn't blow away the display of the
array.

SUPAI> run setwatch

         OpenVMS Alpha DEBUG Version V7.0-03R

%DEBUG-I-INITIAL, Language: COBOL, Module: SETWATCH_PROB
%DEBUG-I-NOTATMAIN, Type GO to reach MAIN program

DBG> set watch/nostatic/over rp-record
%DEBUG-I-EXPMEMPOOL, expanding debugger memory pool
DBG> set break/exception
DBG> go
%DEBUG-I-EXPMEMPOOL, expanding debugger memory pool
%DEBUG-I-EXPMEMPOOL, expanding debugger memory pool
break at routine SETWATCH_PROB
     2:      program-id.  setwatch-prob.
DBG> set break %line 41
DBG> go
count: 00
000000001
In Para2
count: 001
count: 002
count: 003
count: 004
...
count: 098
count: 099
count: 100
break at SETWATCH_PROB\%LINE 41
    41:          stop run.
DBG> exam rpida(1)
RPIDA of RPID of SETWATCH_PROB\RP-RECORD(1):    "aaaaaaaaaa"
DBG> exam rpida(100)
RPIDA of RPID of SETWATCH_PROB\RP-RECORD(100):  "aaaaaaaaaa"
DBG> exam rpide(100)
RPIDE of RPID of SETWATCH_PROB\RP-RECORD(100):  "aaaaaaaaaa"
DBG> exit
T.RTitleUserPersonal
Name
DateLines
1840.1first a few static watchpoint comments...SSPADE::SSPADE::HILDEMon Mar 03 1997 17:2577
I haven't looked at the EXMEMPOOL yet (I will) although its not surprising in
this case since you are setting a watchpoint on a large array.  The internal
workings of the current debugger breaks down the array into its individual
components and sets watchpoint events on each of them. So...that ends up being
a lot of events, in this case, thus the need to expand the debugger kernel
memory.  I suspect that is what is happening (again I will verify that soon).
Note the EXPMEMPOOL is just an informational message, "-I-", and, by itself,
should NOT be considered an "error".  Indeed, I suspect that in this case
there is no problem with it at all.

I can see how the static watchpoint reporting can be confusing and is not
ideally what we (and our users) would want...but what I see here is not
incorrect!  The underlying archeture of ALPHA only allows memory changes
of as big as a quadword at a time, i.e. STQ.  Your array elements are bigger
than one quadword...so it takes more than one store for your high level
line deposit to finish.  The current debugger static watchpoint implementation
reports any and all changes it sees.  That is, it doesn't save up the changes
it detects until the end of the high level source line.  This example shows
how confusing this can be for high level language debug users who really
don't know or care about the low level implementations.  I will consider an
enhancement that saves up changes until source level line completions for
a future debugger release.  Let me illustrate.  The following debugger log
shows that to finish stepping over one of your�"move 'aaaaaaaaaa' to RBIDB
(rpsub)" lines requires a 2 GOs because of 2 watchpoint hits because of 2
separate STORE instructions (that's what the real code actually does).

DBG_1> go
break at routine SETWATCH in %PROCESS_NUMBER 1
     2:      program-id.  setwatch.
DBG_1> set watch rp-record
DBG_1> set br %line 31
DBG_1> g
%DEBUG-I-EXPMEMPOOL, expanding debugger memory pool
count: 00
000000001
In Para2
break at SETWATCH\%LINE 31 in %PROCESS_NUMBER 1
    31:              move 'aaaaaaaaaa' to RPIDA (rpsub)
DBG_1>
DBG_1> set radix hex
DBG_1> step
watch of RPIDA of RPID of SETWATCH\RP-RECORD(1) at SHARE$LIBOTS_CODE0+0F38 in
%PROCESS_NUMBER 1
   old value: ".........."
   new value: "aaaaaaaa.."
break at SHARE$LIBOTS_CODE0+0F3C in %PROCESS_NUMBER 1
%DEBUG-I-SOURCESCOPE, Source lines not available for .0\%PC
        Displaying source in a caller of the current routine
    32:              move 'aaaaaaaaaa' to RPIDB (rpsub)
DBG_1>
DBG_1> ex/inst SHARE$LIBOTS_CODE0+0F38
SHARE$LIBOTS_CODE0+0F38:                STQ             R28,(R16)
DBG_1>
DBG_1> go
watch of RPIDA of RPID of SETWATCH\RP-RECORD(1) at SHARE$LIBOTS_CODE0+0F4C in
%PROCESS_NUMBER 1
   old value: "aaaaaaaa.."
   new value: "aaaaaaaaaa"
break at SHARE$LIBOTS_CODE0+0F50 in %PROCESS_NUMBER 1
%DEBUG-I-SOURCESCOPE, Source lines not available for .0\%PC
        Displaying source in a caller of the current routine
    32:              move 'aaaaaaaaaa' to RPIDB (rpsub)
DBG_1>
DBG_1> ex/inst SHARE$LIBOTS_CODE0+0F4C
SHARE$LIBOTS_CODE0+0F4C:                STQ_U           R28,#X0007(R16)
DBG_1> g
stepped to SETWATCH\%LINE 32 in %PROCESS_NUMBER 1
    32:              move 'aaaaaaaaaa' to RPIDB (rpsub)
DBG_1>


So, once again, it looks like the array is changing in bits and pieces...
because it actually is!  However, to the high level source debug user this
is of little interest and is perhaps even a bit annoying and confusing.

Lon
1840.2second a nostatic wathcpoint commentSSPADE::SSPADE::HILDEMon Mar 03 1997 17:4831
You can get the kind of behavior you desire with the slower nostatic watchpoints
...IF you are very careful about setting them in the correct scope.  That is,
in this case, you MUST wait and set them AFTER the initial GO (once again,
the EXPMEMPOOLs are likely expected behavior...but I'll investigate that 
further soon).  It's the /OVER switch here that in effect waits until the
low level calls to LIBOTS routines (and the individual stores) complete:


DBG_1> go
break at routine SETWATCH in %PROCESS_NUMBER 1
     2:      program-id.  setwatch.
DBG_1> set watch/nostatic/over rp-record
%DEBUG-I-EXPMEMPOOL, expanding debugger memory pool
DBG_1> g
%DEBUG-I-EXPMEMPOOL, expanding debugger memory pool
%DEBUG-I-EXPMEMPOOL, expanding debugger memory pool
count: 00
000000001
In Para2
watch of RPIDA of RPID of SETWATCH\RP-RECORD(1) at SETWATCH\%LINE 31+88 in
%PROCESS_NUMBER 1
    31:              move 'aaaaaaaaaa' to RPIDA (rpsub)
   old value: ".........."
   new value: "aaaaaaaaaa"
break at SETWATCH\%LINE 32 in %PROCESS_NUMBER 1
    32:              move 'aaaaaaaaaa' to RPIDB (rpsub)
DBG_1>


Lon
1840.3no noticeable memory leaks here...SSPADE::SSPADE::HILDEFri Mar 07 1997 17:005
Looks like all the EXPMEMPOOL informations are indeed related to the watchpoint
events...that is, I've looked and found no evidence of kernel memory leaks.

Lon
1840.4- reviewed your input -CSC32::V_HAVERTue Mar 11 1997 18:5633
Lon,

Re: .1

> Note the EXPMEMPOOL is just an informational message, "-I-", and, by itself,
> should NOT be considered an "error".  Indeed, I suspect that in this case
> there is no problem with it at all.

We understood that the error was informational and usually valid.
However, the behavior with the array didn't make much sense.  But with your 
explanation, I can see that the array really is ok, and the behavior 
reasonable (if not pretty).  We can suggest the use of nostatic, for those
customers who find the multiple breaks an issue.

Since I don't have any code that produces the ACCVIO, ROPRAND, etc. we will
have to assume that those errors had nothing to do with the EXMEMPOOL.  It
may be that the customers have programs with coding errors, and the EXMEMPOOL
message is coincidental.  So, we will direct customers to follow the normal
debugging techniques for finding coding problems that often cause process
memory corruption (i.e. check for array subscripts out of bounds).

If we do get more on this, you'll be the first to know! :^)

re: .3

>Looks like all the EXPMEMPOOL informations are indeed related to the watchpoint
>events...that is, I've looked and found no evidence of kernel memory leaks.

This is good to know.

Thanks for your time and efforts.

Vicky H.
1840.5SSPADE::SSPADE::HILDEWed Mar 12 1997 14:0121
>Since I don't have any code that produces the ACCVIO, ROPRAND, etc. we will
>have to assume that those errors had nothing to do with the EXMEMPOOL.  It
>may be that the customers have programs with coding errors, and the EXMEMPOOL
>message is coincidental.  So, we will direct customers to follow the normal
>debugging techniques for finding coding problems that often cause process
>memory corruption (i.e. check for array subscripts out of bounds).

Yeah, I guess I would agree.  It is true, however, that stepping on ALPHA is
complex and step emulation regions that get orphaned or improperly terminated
or not "recognized" usually lead to ACCVIOs, OPCDECs, or ROPRANDs.  I think
most of these problems have been fixed by/in V7.0.  There is one fix I know
of related to tracepoint stepping, e.g. SET TRACE/INST or SET TRACE/CALL, in
a thread or AST rich application that wasn't fixed until V7.1.


>If we do get more on this, you'll be the first to know! :^)

Good...look forward to it.

Lon