Re: cacheMemUsage, cacheCpuUsage, and Squid

Okay, I think I've tracked down the problem. Source code referred to
below is from Squid-2.3-STABLE2.

In the Squid MIB, version 6, there is the following variable defined
just before cacheMemUsage, in the performance group:

cacheSysDefReads OBJECT-TYPE
                SYNTAX Counter32
                MAX-ACCESS not-accessible
                STATUS current
                DESCRIPTION
                        " see cachemgr "
        ::= { cacheSysPerf 3 }

its OID is 3; the next one in sequence (cacheMemUsage) is 4.

However, when I look in cache_snmp.h, I don't see any flags defined for
cacheSysDefReads (following the logic of the flags, there should be
something along the line of PERF_SYS_DEFR). There's no case line for
returning anything with this value in snmp_agent.c, either.

So I added a few more debug() lines to snmp_agent.c, recompiled, and
turned on "debug_options 49,9" in squid.conf to get some verbose output
on what is happening in snmp_agent.

Then I started working my way down the list of variables in the
performance group with snmpget. When I got to cacheSysDefReads, here´s
what I got from snmpget:

% snmpget -m ~/squid-mib-06.txt -p 3401 localhost passwd
cacheSysDefReads
enterprises.nlanr.squid.cachePerf.cacheSysPerf.cacheSysDefReads = Wrong
Type (should be Counter): 381

And here´s what the cache.log output shows for this request:

2000/04/07 10:15:35| snmpHandleUdp: Called.
2000/04/07 10:15:35| snmpHandleUdp: FD 15: received 60 bytes from
127.0.0.1.
2000/04/07 10:15:35| snmpDecodePacket: Called.
2000/04/07 10:15:35| snmpAgentParse: reqid=[858201541]
2000/04/07 10:15:35| snmpConstructReponse: Called.
2000/04/07 10:15:35| snmpAgentResponse: Called.
2000/04/07 10:15:35| snmpTreeGet: Called
2000/04/07 10:15:35| snmpTreeGet: Current :
2000/04/07 10:15:35| oid = .1.3.6.1.4.1.3495.1.3.1.3
2000/04/07 10:15:35| snmpTreeGet: return
2000/04/07 10:15:35| snmp_prfSysFn: Processing request with magic 3!
2000/04/07 10:15:35| snmp_prfSysFn: PERF_SYS_MEMUSAGE = 3!
2000/04/07 10:15:35| Buffer=82c4de8 BufLenP=82c4dc4, buflen=4096
2000/04/07 10:15:35| snmp_msg_Encode: Encoding community (servicom2000)
(12)
2000/04/07 10:15:35| snmp_msg_Encode:Encoding PDU Header at 0x82c4dfd
(fake len 4075) (4075 bytes so far)
2000/04/07 10:15:35| LIBSNMP: snmp_build(): Packet len 62 (requid
858201541)

Clearly, the flags have got out of whack here. snmp_agent thinks number
three is cacheMemUsage, since it has no idea that cacheSysDefReads even
exists.

If I ask for cacheMemUsage (the next in line after cacheSysDefReads), I
get this in cache.log, and my CPU time is returned...

2000/04/07 10:34:42| snmp_prfSysFn: Processing request with magic 4!
2000/04/07 10:34:42| snmp_prfSysFn: PERF_SYS_CPUTIME = 4!

There is no variable name in the MIB that can be used to retrieve CPU
time (the only way to get it is by using cacheMemUsage).

There´s a shift that takes place, due to a discrepancy between the MIB
and squid. cacheSysDefReads only exists in the MIB, but not in squid,
so squid thinks its OID (3) refers to the next in line, cacheMemUsage;
cacheCpuTime only exists in squid, but not in the MIB, so squid thinks
cacheMemUsage really refers to PERF_SYS_CPUTIME (OID 4). (Clear as mud,
right?)

When I ask for cacheCpuUsage, the enum variables get back on track. I
get this in the log file, and my CPU usage is returned:

2000/04/07 10:38:31| snmp_prfSysFn: Processing request with magic 5!
2000/04/07 10:38:31| snmp_prfSysFn: PERF_SYS_CPUUSAGE = 5!

It seems that the source code is not quite up-to-date with the MIB. I
modified the MIB, getting rid of cacheSysDefReads and adding
cacheCpuTime:

% diff squid-mib-06.txt squid-mib-06.txt.new
201,208d200
< cacheSysDefReads OBJECT-TYPE
< SYNTAX Counter32
< MAX-ACCESS not-accessible
< STATUS current
< DESCRIPTION
< " see cachemgr "
< ::= { cacheSysPerf 3 }
<
215c207
< ::= { cacheSysPerf 4 }

---
>       ::= { cacheSysPerf 3 } 
217c209
<       cacheCpuUsage OBJECT-TYPE
---
>       cacheCpuTime OBJECT-TYPE
222a215,222
>       ::= { cacheSysPerf 4 }
> 
>       cacheCpuUsage OBJECT-TYPE
>               SYNTAX Integer32
>               MAX-ACCESS read-only
>                 STATUS  current
>                 DESCRIPTION
>                         " Percentage of time spent using cpu"
I then ran snmpget again, and all the values returned to normal:
% snmpget -m ~sprater/mrtg/squid-mib-06.txt.new -p 3401 localhost
servicom2000 cacheMemUsage
enterprises.nlanr.squid.cachePerf.cacheSysPerf.cacheMemUsage = 406
% snmpget -m ~sprater/mrtg/squid-mib-06.txt.new -p 3401 localhost
servicom2000 cacheCpuTime
enterprises.nlanr.squid.cachePerf.cacheSysPerf.cacheCpuTime = 1
% snmpget -m ~sprater/mrtg/squid-mib-06.txt.new -p 3401 localhost
servicom2000 cacheCpuUsage
enterprises.nlanr.squid.cachePerf.cacheSysPerf.cacheCpuUsage = 0
(Added note about cacheCpuUsage:  the value returned is an integer, but
rarely does it climb above 1, so usually it just gets truncated to 0. 
It might be nice to take the percentage calculated in snmp_agent and
multiply it by 100 again, before returning it, so we actually get a
useful value.)
I don't know whether the OID/variable confusion would be considered a
bug in the MIB, or a bug in squid.  But by modifying the MIB as I did
above (assuming the developers don't want cacheSysDefReads (which should
be inaccessible anyways), but do want cacheCpuTime), the problem is
solved.
--Scott
Scott Prater escribió:
> 
> Hello, all --
> 
> I'm seeing some odd values returned when I use snmpget to retrieve some
> information from Squid.
> 
> When I ask for the current value of cacheMemUsage, I get the value for
> cacheCpuUsage (as verified independently in cachemgr):
> 
> % snmpget -O n -m ~/squid-mib-06.txt -p 3401 localhost passwd
> cacheMemUsage
> .1.3.6.1.4.1.3495.1.3.1.4 = 258
> 
> and when I ask for the cacheCpuUsage, I get 0:
> 
> % snmpget -O n -m ~/squid-mib-06.txt -p 3401 localhost passwd
> cacheCpuUsage
> .1.3.6.1.4.1.3495.1.3.1.5 = 0
> 
> I´ve verified that the OIDs are coreect...
> 
> Has anyone else seen this occur?  Can anyone else duplicate this
> problem?
> I'm currently using Squid-2.3-STABLE2 on a Linux system.
> 
> Thanks again,
> 
> Scott
> 
**********************************
Scott Prater			
Analista de Sistemas
Servicom2000
Ramón Gordillo 1-entlo
46010 Valencia
España
scott.prater@servicom2000.com
+34-96-361-8776 (tel)
+34-96-360-5508 (fax)
**********************************