pmrep/pmfetchgroup cannot find dynamic instance

[andreasgerstmayr]

Somehow pmrep cannot filter instances which are present at the beginning of the archive, but not at the end.

I'm running pcp-zeroconf on Fedora 34 in a VM from the latest main branch. While logging an archive, I've restarted pmcd, so I have two instances of pmcd in the proc metrics:

$ pmdumplog 20210518.17.21 | grep pmcd
[snip]
        inst [318696 or "318696 /usr/libexec/pcp/bin/pmcd"] value "/usr/libexec/pcp/bin/pmcd"
[snip]
        inst [320385 or "320385 /usr/libexec/pcp/bin/pmcd"] value "/usr/libexec/pcp/bin/pmcd"

i.e. the first invocation of pmcd had PID 318696, and the second one PID 320385.

Running pmrep and filtering for the first invocation gives:

pmrep -a 20210518.17.21 proc.psinfo.psargs -i 318696
  p.p.psargs
  318696 /us
            
pmrep: Insufficient elements in list 
No metrics or instances to report present.

Running pmrep and filtering for the second invocation works fine.

Here is the archive: archive.zip

@myllynen already investigated this, can you share your findings here?

[myllynen]

This looks to be an issue on the library level as this can be reproduced with a rudimentary C test program as well.

QA 1135, 1136, and 1169 test pmrep/pmfg handling of dynamic instances which come and go, and those work just fine.

As shown above pmrep and pmfg have read the instance domain from the archive and detected that the instance 318696 exists as otherwise an error "No matching instances found" would have been printed. The behavior looks as if it was a transient live instance which has vanished after getting the instance ID but before calling pmfg's extend_indom().

It also turned out that running pmlogextract(1) on the archive and keeping only the two above instances gives an archive which doesn't lead to this error, meaning that pmrep/pmfg work as expected with both instances.

The error pmrep is printing for the user is raised when doing the first fetch as there is nothing in the fetchgroup. We end up to this situation when earlier pmfg's extend_indom() failed but that error was silently ignored. Silently ignoring the failure to add an instance to fetchgroup is ok with transient live metrics and has also worked fine so far with all test archives. Regardless, this is not the root cause.

The error ignored by pmrep is Instance identifier not defined in the PCP archive log which seems unexpected given that earlier pmrep has verified the type etc of the instance by reading its metadata from the archive before proceeding to add it to the fetchgroup (which, as said, then fails).

I did this to create a new archive with pmlogextract(1) that creates a working archive:

# cat le.conf
proc.psinfo.psargs['320385 /usr/libexec/pcp/bin/pmcd','318696 /usr/libexec/pcp/bin/pmcd']
# pmlogextract -c le.conf 20210518.17.21 new-archive

And then using the attached rudimentary C program we can notice this difference:

# ./pmfg-test 20210518.17.21 proc.psinfo.psargs '318696 /usr/libexec/pcp/bin/pmcd'
Instance identifier not defined in the PCP archive log
# ./pmfg-test new-archive proc.psinfo.psargs '318696 /usr/libexec/pcp/bin/pmcd'          
Tue May 18 20:21:22 2021
318696 /usr/libexec/pcp/bin/pmcd:	/usr/libexec/pcp/bin/pmcd
Tue May 18 20:22:22 2021
318696 /usr/libexec/pcp/bin/pmcd:	/usr/libexec/pcp/bin/pmcd
End of PCP archive log

The only even remotely related looking part in pmfetchgroup(1) says:

If the fetchgroup context is a set of archives, it is possible that the
metric / instance pair is not yet defined at the current time origin.
Therefore, this function may attempt to seek to the end of the current
set of archives temporarily to retry the metric / instance lookup.

But that works fine for example with existing QA and in cases like #433 where the archive may not be completely optimal the results are still available for reporting.

It would be great if those familiar with archive log handling internals could have a look at this at some point. Thanks.

pmfg-test.c.txt