Backport resampler log enhancement to v0.25.x

[daniel-zullo-frequenz]

Log when no relevant samples are found for resampling.

These additional logs will help in understanding why certain microgrid components, such as meters, fail to provide relevant samples for resampling.

[llucax]

Please make sure to make sure tests pass locally, and ideally even try it out with some app, because I think the CI doesn't work properly for this branch (or maybe it was just the branch restrictions?).

[daniel-zullo-frequenz]

I've cherry-pick'ed the commit from v1.x.x. Though pytest_max tests failed in my local environment :/

================================================================== short test summary info ==================================================================
FAILED tests/actor/test_battery_status.py::TestBatteryStatusRecovery::test_critical_error - assert <Status.NOT_WORKING: 0> is _Timeout
FAILED tests/actor/power_distributing/test_power_distributing.py::TestPowerDistributingActor::test_power_distributor_exclusion_bounds - AssertionError: assert 1 == 0
========================================================= 2 failed, 349 passed, 1 warning in 55.00s =========================================================

[llucax]

Mmm, did you tried more than once? Given it is a timeout, it might be a timing issue, we have flaky tests in the past.

Also did you try to run the tests locally without your modifications? If they still fail I guess we can take it in despite the failure as it is probably unrelated.

[daniel-zullo-frequenz]

Mmm, did you tried more than once? Given it is a timeout, it might be a timing issue, we have flaky tests in the past.

yes, I did and it consistently failed in all runs

Also did you try to run the tests locally without your modifications? If they still fail I guess we can take it in despite the failure as it is probably unrelated.

It failed without my changes too.

The tests only fail for pytest_max, all tests pass running pytest_min 🤔

[llucax]

Oh, that sounds familiar. It might be it is trying to use a too new time-machine if the dependency is not pinned?

• Upgrade to time-machine 2.13.0+ breaks our tests #832

[daniel-zullo-frequenz]

the time-machine dependency is pinned to 2.12.0. I also tried a previous time-machine version and the tests failed

[llucax]

Then I don't know, I guess we need to do some sort of bisection comparing the dependencies between min and max to find out which one is causing issues.

[llucax]

I'm not sure if it is worth it though, since I guess v0.25.x will be dropped soon, right?

[daniel-zullo-frequenz]

All tests passed setting frequenz-channels==0.16.0. Updating to frequenz-channels==0.16.1 causes the test to fail

nox > Session pytest_max was successful.
nox > Ran multiple sessions:
nox > * formatting: success
nox > * mypy: success
nox > * pylint: success
nox > * docstrings: success
nox > * pytest_min: success
nox > * pytest_max: success

(.venv) daniz@fz-536:~/projects/frequenz-sdk-python(6418523f ✗)$ git diff
diff --git a/pyproject.toml b/pyproject.toml
index ff9157c6..7fc8f796 100644
--- a/pyproject.toml
+++ b/pyproject.toml
@@ -30,7 +30,7 @@ dependencies = [
   # Make sure to update the mkdocs.yml file when
   # changing the version
   # (plugins.mkdocstrings.handlers.python.import)
-  "frequenz-channels >= 0.16.0, < 0.17.0",
+  "frequenz-channels >= 0.16.0, < 0.16.1",
   "google-api-python-client >= 2.71, < 3",
   "grpcio >= 1.54.2, < 2",
   "grpcio-tools >= 1.54.2, < 2",

[llucax]

Ohhh, interesting. v0.16.1 only fixed one bug:

• Timer: Fix bug that was causing calls to reset() to not reset the timer, if the timer was already being awaited.

Maybe the tests in this version somehow relied on that bug.

And if you do a pip freeze in both environments is that the only difference? It might also be an indirect dependency pulled by channels the one causing the issue.

[daniel-zullo-frequenz]

I only pip-installed channels 0.16.0 in the pytest_max environment and the tests passed.

Anyway these are all the differences for both environments:
The changes in red (removed) belongs to the pytest_min virtual environment
The changes in green (added) belongs to the pytest_max virtual environment

diff --git a/pytest.txt b/pytest.txt
index 8f1af3a..578ea51 100644
--- a/pytest.txt
+++ b/pytest.txt
@@ -1,4 +1,4 @@
-anyio==3.7.1
+anyio==4.3.0
 argcomplete==3.3.0
 astroid==2.15.8
 async-solipsism==0.5
@@ -10,19 +10,21 @@ colorlog==6.8.2
 dill==0.3.8
 distlib==0.3.8
 filelock==3.13.4
-frequenz-api-common==0.3.0
-frequenz-api-microgrid==0.15.1
-frequenz-channels==0.16.0
+frequenz-api-common==0.5.5
+frequenz-api-microgrid==0.15.3
+frequenz-channels==0.16.1
 frequenz-repo-config==0.5.2
 -e git+https://github.com/frequenz-floss/frequenz-sdk-python.git@da44d7e2d577a1cc57283f759c3cd5ab24ca12e8#egg=frequenz_sdk
 ghp-import==2.1.0
 google-api-core==2.18.0
-google-api-python-client==2.71.0
+google-api-python-client==2.126.0
 google-auth==2.29.0
 google-auth-httplib2==0.2.0
 googleapis-common-protos==1.63.0
-grpcio==1.54.2
-grpcio-tools==1.54.2
+googleapis-common-protos-stubs==2.2.0
+grpc-stubs==1.53.0.5
+grpcio==1.62.1
+grpcio-tools==1.62.1
 httplib2==0.22.0
 idna==3.7
 iniconfig==2.0.0
@@ -35,19 +37,19 @@ mccabe==0.7.0
 mergedeep==1.3.4
 mkdocs==1.5.3
 mkdocs-gen-files==0.5.0
-networkx==2.8
+networkx==3.3
 nox==2024.4.15
-numpy==1.24.2
+numpy==1.26.4
 packaging==24.0
 pathspec==0.12.1
 platformdirs==4.2.0
 pluggy==1.4.0
 polars==0.18.15
 proto-plus==1.23.0
-protobuf==4.21.6
+protobuf==4.25.3
 pyasn1==0.6.0
 pyasn1_modules==0.4.0
-pydantic==1.9.0
+pydantic==1.10.15
 pylint==2.17.5
 pyparsing==3.1.2
 pytest==7.4.0
@@ -63,11 +65,12 @@ sniffio==1.3.1
 sybil==5.0.3
 time-machine==2.12.0
 tomlkit==0.12.4
-tqdm==4.38.0
-typing_extensions==4.4.0
+tqdm==4.66.2
+types-protobuf==4.25.0.20240417
+typing_extensions==4.11.0
 uritemplate==4.1.1
 urllib3==2.2.1
 virtualenv==20.25.3
 watchdog==4.0.0
-watchfiles==0.15.0
+watchfiles==0.19.0
 wrapt==1.16.0

Having frequenz-channels 0.16.0 in pytest_min and pytest_max:

diff --git a/pyproject.toml b/pyproject.toml
index ff9157c6..7fc8f796 100644
--- a/pyproject.toml
+++ b/pyproject.toml
@@ -30,7 +30,7 @@ dependencies = [
   # Make sure to update the mkdocs.yml file when
   # changing the version
   # (plugins.mkdocstrings.handlers.python.import)
-  "frequenz-channels >= 0.16.0, < 0.17.0",
+  "frequenz-channels >= 0.16.0, < 0.16.1",
   "google-api-python-client >= 2.71, < 3",
   "grpcio >= 1.54.2, < 2",
   "grpcio-tools >= 1.54.2, < 2",
diff --git a/pytest/pytest.freeze b/pytest/pytest.freeze
index 8f1af3a8..7f5d33b5 100644
--- a/pytest/pytest.freeze
+++ b/pytest/pytest.freeze
@@ -1,4 +1,4 @@
-anyio==3.7.1
+anyio==4.3.0
 argcomplete==3.3.0
 astroid==2.15.8
 async-solipsism==0.5
@@ -10,19 +10,21 @@ colorlog==6.8.2
 dill==0.3.8
 distlib==0.3.8
 filelock==3.13.4
-frequenz-api-common==0.3.0
-frequenz-api-microgrid==0.15.1
+frequenz-api-common==0.5.5
+frequenz-api-microgrid==0.15.3
 frequenz-channels==0.16.0
 frequenz-repo-config==0.5.2
 -e git+https://github.com/frequenz-floss/frequenz-sdk-python.git@da44d7e2d577a1cc57283f759c3cd5ab24ca12e8#egg=frequenz_sdk
 ghp-import==2.1.0
 google-api-core==2.18.0
-google-api-python-client==2.71.0
+google-api-python-client==2.126.0
 google-auth==2.29.0
 google-auth-httplib2==0.2.0
 googleapis-common-protos==1.63.0
-grpcio==1.54.2
-grpcio-tools==1.54.2
+googleapis-common-protos-stubs==2.2.0
+grpc-stubs==1.53.0.5
+grpcio==1.62.1
+grpcio-tools==1.62.1
 httplib2==0.22.0
 idna==3.7
 iniconfig==2.0.0
@@ -35,19 +37,19 @@ mccabe==0.7.0
 mergedeep==1.3.4
 mkdocs==1.5.3
 mkdocs-gen-files==0.5.0
-networkx==2.8
+networkx==3.3
 nox==2024.4.15
-numpy==1.24.2
+numpy==1.26.4
 packaging==24.0
 pathspec==0.12.1
 platformdirs==4.2.0
 pluggy==1.4.0
 polars==0.18.15
 proto-plus==1.23.0
-protobuf==4.21.6
+protobuf==4.25.3
 pyasn1==0.6.0
 pyasn1_modules==0.4.0
-pydantic==1.9.0
+pydantic==1.10.15
 pylint==2.17.5
 pyparsing==3.1.2
 pytest==7.4.0
@@ -63,11 +65,12 @@ sniffio==1.3.1
 sybil==5.0.3
 time-machine==2.12.0
 tomlkit==0.12.4
-tqdm==4.38.0
-typing_extensions==4.4.0
+tqdm==4.66.2
+types-protobuf==4.25.0.20240417
+typing_extensions==4.11.0
 uritemplate==4.1.1
 urllib3==2.2.1
 virtualenv==20.25.3
 watchdog==4.0.0
-watchfiles==0.15.0
+watchfiles==0.19.0
 wrapt==1.16.0

[llucax]

I would start with the version using v0.16 for max and then do a manual pip install dep==ver to the new version of each differing dependency one by one to see exactly which one is making the change in behaviour. I see quite a few candidates related to asyncio that could be the culprit. I doubt it is channels, but I wouldn't discard it either.

[daniel-zullo-frequenz]

I tested it in the other way around, I've set the dependencies exactly as it is done for pytest_min virtual environment (all tests passed) and then set frequenz-channel==0.16.1, that was enough to reproduce the failed test.

Anyway this behavior was previously observed in PRs based on v0.25.x. The problem was first observed here and an issue was created to investigate/fix it in #814

I also tested locally v1.0.0-rc1, v1.0.0-rc2 and v1.0.0-rc3 and the same test failed for pytest_max. Then tests were fixed in #838 which changes were shipped as part of v1.0.0-rc4

My conclusion is the patch done for frequenz-channel v0.16.1 is correct, and the tests in branch v0.25.x are flaky tests and I believe we shouldn't continue investigating the issue here as applications will likely use or migrate to SDK v1.0.0 (or latest release candidate) where the tests have been already fixed.