Fix of pmproxy crashes

[kurik]

Fix concurrent call of uv_timer's causing pmproxy crashes

When multiple worker threads simultaneously call uv_timer_start/stop on
timers belonging to the same event loop, they concurrently modify the
shared heap data structure without synchronization. This causes segmentation
faults in pmproxy.
This fix:

• removes the unsafe calls uv_timer_start() and uv_update_time() from worker threads
• uses thread-safe time tracking uv_hrtime()
• moves timer logic to the event loop thread

Fix of expansion of delta indom causing pmproxy crashes

When expanding a delta indom into a full indom, the function copies name
pointers by reference (shallow copy) from the previous full indom into
the new namelist. This creates a mismatch when two different memory
allocation schemes coexist in the same hashindom chain leading to free()
of invalid pointers causing SIGABRT.
This fix: is replacing shallow copies of pointers with strdup() and sets
PMLID_NAMES to ensure the expanded namelist is an independent allocation
that can be safely freed.

[kurik]

fedora-rawhide and ubuntu2204 pipelines failed due to issues starting the container - not related to the proposed fix.

However the changes here are quite significant in the way how context timers are handled, so I would appreciate some review from @kmcdonell or @natoscott . Thanks guys in advance.

[natoscott]

I'll defer to @kmcdonell comment on the libpcp namelist change, but the libpcp_web changes make sense. We may need a similar hrtimer transition in pmproxy/src too?

[kmcdonell]

@kurik Thanks for the triage here. I'll defer to @natoscott for the libpcp_web changes, but with one small improvement I think the libpcp ones are OK.

Do you have a reproducer for this? I'm guessing not, it is just the corpses from pmproxy that are scattered on the ground.

I've managed to build a new QA app and test (qa/src/undelta.c et al, commit incoming) that dies spectacularly with the unmodified logmeta.c, but passes with (my version) of the changes in place.

I'm a little surprised that this has not bitten before, but I think the reason is that the common code path below pmNewContext() that most archive consuming tools are using ends up allocating the components of all the __pmLogInDom structs in a way that avoids the problem you've identified, pmproxy on the other hand is reading metadata records directly from disk for the "fail -f" mode of ingestion and is probably building the __pmLogInDom structs in a slightly different way.

[kmcdonell]

I suspect the proposed changes are fixing one problem and introducing a potential memory leak.

On review of the code, I believe __pmLogUndeltaInDom() should honour the PMLID_NAMES bit in the alloc field of the delta __pmLogInDom.

So a slightly different change for the last strdup() would be along the lines:

if (tidp->alloc & PMLID_NAMES)
    namelist[k] = didp->namelist[j];
else
    namelist[k] = strdup(didp->namelist[j]);

[kurik]

Do you have a reproducer for this? I'm guessing not, it is just the corpses from pmproxy that are scattered on the ground.

The fix comes from an analysis of a bunch of core files I am collecting from my test runs. I do not have a "reliable" reproducer, but this Fedora gating test reliably reproduces it. The test starts 10 containers in the background where each container calls set of REST API endpoints in a cycle (work as a pmproxy clients). To make the test more stressful for the pmproxy I can start more background clients and/or prolong the test run. However even with the default parameters it always generates some core file for me.

So a slightly different change for the last strdup() would be along the lines:...

Thanks for this @kmcdonell . I am going to rebuild PCP with this code change and will test it.

[kurik]

@kmcdonell I reworked the patch with you suggestion, tested it for a day and it seems to work well. I do not observe any memory leaks. Can you please review it once more ? Thanks in advance.

[kmcdonell]

Hey @kurik,
The more I stare at this code, the less I'm convinced that it is correct (not the changes in the PR, the whole basic algorithm).
I've refactored the code to change the logic, but preserve most of the strdup() changes here.
Gimme a day or two to soak test locally and I'll add a new logmeta.c here for you take for a spin.
Sorry this has turned so ugly.

[kurik]

Thanks a lot @kmcdonell . I would be happy if those crashes will be fixed, it does not need to be fixed by my code :-)

[kmcdonell]

@kurik I've committed my new logmeta.c in commit bf0dfb6 over in my tree. It looks solid in my QA testing and I've attached the new source file to this PR.

logmeta.c

Suggest you take it for a spin, and if it looks OK, you can close this PR and I'll make the same change to the libpcp3 version, commit that and push both.

Thanks for you on-going assistance on this one, and your initial triage that pin pointed the root cause.

[kurik]

@kmcdonell The patch in bf0dfb6 looks mostly good. However I have some comments :-)

During testing I observed some core dumps of the pmproxy process. The first crash occurred in logFreeHashLabels() while freeing labelset->json during context destruction.

Trying to understand the patch, it seems to me like the code starting on line

pcp/src/libpcp/src/logmeta.c

Line 1203 in bf0dfb6

numinst = didp->next->numinst;

assumes that every delta entry either adds or removes exactly one instance. However it might not always be the case. If there are more instances in the delta entry, the numinst is then overcounted or undercounted . This leads to heap corruption and unrelated free() is then called during the context destruction. Changing

pcp/src/libpcp/src/logmeta.c

Line 1312 in bf0dfb6

didp->numinst = numinst;

from didp->numinst = numinst; to didp->numinst = k; should fix this issue with the unrelated free().

There is also a next problem, causing another pmproxy crash. The code hits assert() on lines

pcp/src/libpcp/src/logmeta.c

Line 1266 in bf0dfb6

assert (k < numinst);

and/or

pcp/src/libpcp/src/logmeta.c

Line 1285 in bf0dfb6

assert (k < numinst);

. This is IMO caused by skipping entries on line

pcp/src/libpcp/src/logmeta.c

Line 1260 in bf0dfb6

pmflush();

which is a different algorithm comparing to the way how required memory is calculated on line

pcp/src/libpcp/src/logmeta.c

Line 1208 in bf0dfb6

numinst--;

. It is causing the numinst to be too small. I guess the simplest fix for this will be to remove lines

pcp/src/libpcp/src/logmeta.c

Line 1207 in bf0dfb6

else

and

pcp/src/libpcp/src/logmeta.c

Line 1208 in bf0dfb6

numinst--;

which will overallocate memory a bit, but does not lead to memory leaks and it is safe from the buffer overflow point of view..

At last there is also one typo, I guess, where on line

pcp/src/libpcp/src/logmeta.c

Line 1288 in bf0dfb6

pmNoMem("__pmLogUndeltaInDom name from full", strlen(fidp->namelist[j]), PM_FATAL_ERR);

the fidp->namelist[j] should be fidp->namelist[i] (change the index j -> i).

With all three proposed fixes above implemented in the code, I do not observe memory leaks nor crashes.
There is still the problem with the libpcp_web but I will address this in another pull request.

[kmcdonell]

@kurik Jeez, it is time I was put out to pasture. Sorry for my sloppiness here ... let me undertake some penance and when I've digested your changes and if I have no further questions I'll simply take your version, commit this and push it and close this PR so we can all move onto something more productive.

[kmcdonell]

@kurik Sigh.

We start with all the instances from the full indom then add 1 for each new instance and subtract 1 for each deleted instance. This is correct for normal libpcp uses, but it seems not for pmproxy [because it is "tailing" the end of the archive it maybe is chewing on incomplete metadata].

Now it starts to get murky .... any chance you still have pmproxy.log? If so, I'd expect to see some __pmLogUndeltaInDom: Botch: InDom messages. If not the skipping at around line 1260 (or 1233) is not happening.

But the fact that you hit the assert makes me suspect the Botch case is happening ... this is again a "problem" only with pmproxy because it is not processing the whole archive as expected by the libpcp code [so there maybe a deeper, darker problem here for pmproxy]. I've updated qa/src/undelta.c to simulate the two Botch cases, and sure enough Kaboom, qa/1655 hits the assert() at line 1266.

I added the extra integrity checks in the earlier commit(s) "to be sure, to be sure" not expecting 'em to catch anything, but looks like pmproxy is tripping these integrity checks and then the remaining count and skip logic in logmeta.c was incorrect, leading to the assert()s.

New commit 0473ab3 in my repo addresses the above by making over-estimating the size of the undelta'd indom, fixing the accounting of instances to be more robust in the presence of unexpected delta indom data.

Thanks once again, let's give it another try.

[kurik]

@kurik Sigh.
Now it starts to get murky .... any chance you still have pmproxy.log? If so, I'd expect to see some __pmLogUndeltaInDom: Botch: InDom messages. If not the skipping at around line 1260 (or 1233) is not happening.

Unfortunately, I do not have the pmproxy.log. I was experimenting with other stuff on the same machine and the log is gone.

New commit 0473ab3 in my repo addresses the above by making over-estimating the size of the undelta'd indom, fixing the accounting of instances to be more robust in the presence of unexpected delta indom data.

So far, I was not able to reproduce the problem with the 0473ab3 commit. All seem to work well with this version of logmeta.c. I am +1 to merge the 0473ab3.

I have not run the full QA testsuite, assuming you did. If not let me know and I can run it on Monday.

[kmcdonell]

All good @kurik.

I've pushed that commit, plus another couple to
(a) conditionally realloc() the arrays before return to accommodate the over-allocation when that happens and
(b) backport to libpcp3 (not that I expect anyone using the older PMAPI will be able to trip this) but the code is 100% broken over there and the backport is a simple drop-in replacements for __pmLogUndeltaInDom().

And yes, I've been running full QA with this fix in the QA Farm across multiple platforms now.

I'm going to close this PR, as the real commits are elsewhere, ending with fed1b80

Thanks once again, for your assistance on this one.