Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: add ioredis instrumentation #301

Merged

Conversation

Flarna
Copy link
Member

@Flarna Flarna commented Jan 12, 2021

Created ioredis instrumentation because the plugin API will be removed from OTel.

fixes: #251

@Flarna Flarna requested a review from a team January 12, 2021 18:14
Created ioredis instrumentation because the plugin API will be removed from OTel.
@Flarna Flarna force-pushed the ioredis-instrumentation branch from 0ed630d to 2d36e9e Compare January 12, 2021 18:15
@codecov
Copy link

codecov bot commented Jan 12, 2021

Codecov Report

Merging #301 (5941ec3) into main (9336cdc) will decrease coverage by 0.18%.
The diff coverage is n/a.

@@            Coverage Diff             @@
##             main     #301      +/-   ##
==========================================
- Coverage   95.47%   95.29%   -0.19%     
==========================================
  Files         119      124       +5     
  Lines        6277     6690     +413     
  Branches      614      639      +25     
==========================================
+ Hits         5993     6375     +382     
- Misses        284      315      +31     
Impacted Files Coverage Δ
...opentelemetry-instrumentation-ioredis/src/utils.ts 89.36% <0.00%> (ø)
...entelemetry-instrumentation-ioredis/src/ioredis.ts 93.33% <0.00%> (ø)
...entelemetry-instrumentation-ioredis/src/version.ts 100.00% <0.00%> (ø)
...opentelemetry-instrumentation-ioredis/.eslintrc.js 0.00% <0.00%> (ø)
...metry-instrumentation-ioredis/test/ioredis.test.ts 93.11% <0.00%> (ø)

@Flarna
Copy link
Member Author

Flarna commented Jan 12, 2021

the failed test seems to be caused by reusing the redis instance. If I run test local they pass the first them but fail the second time - plugin and instrumentation.

@Flarna Flarna force-pushed the ioredis-instrumentation branch from 42d499b to 9596827 Compare January 12, 2021 19:49
@Flarna
Copy link
Member Author

Flarna commented Jan 13, 2021

plugin-ioredis test failed again because a single redis instance is used for testing serveral node versions in parallel.
should create a child span for del deletes the test key and if this happens at a bad time the should create a child span for get promise test fails.

As this is unrelated to this PR I don't think it should be fixed here.

@Flarna
Copy link
Member Author

Flarna commented Jan 13, 2021

test improvements are in #303

@dyladan
Copy link
Member

dyladan commented Jan 14, 2021

Is this a direct port of the Plugin or did you make any behavior changes?

@Flarna
Copy link
Member Author

Flarna commented Jan 14, 2021

It's a direct port. If there are behavior changes they are not intended.

@vmarchaud vmarchaud linked an issue Jan 18, 2021 that may be closed by this pull request
Copy link
Member

@obecny obecny left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

lgtm

Base automatically changed from master to main January 27, 2021 22:21
@Flarna
Copy link
Member Author

Flarna commented Jan 29, 2021

@blumamir I merge your changes but now a test fails - but only in node 14.
My gut feeling tells that this is a race in the test and depends on the internal timing inside redis. Any hints how to improve this?

@Flarna
Copy link
Member Author

Flarna commented Jan 29, 2021

ok, it is a flaky test as rerun resulting in green CI. For the records this was the failure:

  1) ioredis
       #send_internal_message()
         Instrumenting query operations
           should create a child span for pubsub:
     AssertionError [ERR_ASSERTION]: ifError got unwanted exception: Expected values to be strictly equal:
+ actual - expected

+ 'subscribe'
- 'info'
      at /root/project/plugins/node/opentelemetry-plugin-ioredis/test/ioredis.test.ts:47:60
      at processTicksAndRejections (internal/process/task_queues.js:93:5)
      at Context.<anonymous> (test/ioredis.test.ts:47:60)

@dyladan
Copy link
Member

dyladan commented Jan 29, 2021

@Flarna should we hold off merging this while you look at the flaky test?

@Flarna
Copy link
Member Author

Flarna commented Jan 29, 2021

I moved to other tasks meanwhile. I think this can be done via a separate PR.
I think the best solution would be to isolate the test runs for each node version and let them use a dedicated redis,... instance. But this is for sure out of scope for this PR.

@vmarchaud
Copy link
Member

I agree that it could be done in another PR, we'll also need to make other PR to add #239 (and other changes that have been suggested while reviewing).

@Flarna
Copy link
Member Author

Flarna commented Jan 30, 2021

changes from #239 are already integrated here via afde553

@blumamir
Copy link
Member

blumamir commented Jan 31, 2021

@blumamir I merge your changes but now a test fails - but only in node 14.
My gut feeling tells that this is a race in the test and depends on the internal timing inside redis. Any hints how to improve this?

The test is creating two ioredis clients.
Since we are not setting the client option enableReadyCheck to false, the default is true, which means that following a connect, the client is sending an info command to the server.

Now we have the pub client which is sending connect -> info,
And we have the sub client which is sending connect -> info -> subscribe.
Since these happen asynchronously, we can get both:

  1. connect, connect, info, info, subscribe ...
  2. connect, connect, info, subscribe, info ...

The double subscribe spans in the result for a single subscribe operation is a bug which is explained in issue #288 .

            const spanNames = [
              'connect',
              'connect',
              'info',
              'info',
              'subscribe',
              'subscribe', // <============= BUG
              'publish',
              'publish',
              'unsubscribe',
              'quit',
              'quit',
              'test span',
            ];

To fix the test - making it deterministic, we can do either:

  1. start the clients with enableReadyCheck: false, which will remove the info span:
            const pub = new ioredis(URL, {enableReadyCheck: false});
            const sub = new ioredis(URL, {enableReadyCheck: false});
  1. create the sub client, let it subscribe, and only after we are subscribed, create the pub client:
...
            const sub = new ioredis(URL);
            await sub.subscribe('news', 'music');
            const pub = new ioredis(URL);
            await pub.publish('news', 'Hello world!');
...
  1. wait for the clients to connect successfully, and only then send the commands. This can be achieved by calling connect explicitly (after disabling auto connect) and awaiting the response:
            const sub = new ioredis(URL, {lazyConnect: true});
            const pub = new ioredis(URL, {lazyConnect: true});
            await Promise.all([sub.connect(), pub.connect()]);
            await sub.subscribe('news', 'music');
            await pub.publish('news', 'Hello world!');
            await pub.publish('music', 'Hello again!');

There might be some other way to await on connection to the DB which I'm not aware of.


Notice that some of the suggested fixes above are also fixing the double subscribe span bug (#288) because it syncs the subscribe to be called only after connection is completed, thus it's not going into the offline queue and only single-span is created for it. Those will require a fix in the test as well:

  • remove one subscribe from the expectedspanNames array.
  • Expecting 10/11 spans instead of 11/12.
  • changing the index of the subscribe span from 5 to 4 in the assertion below.

Hope it will get the flaky test fixed.

@blumamir
Copy link
Member

@Flarna If you want, I can fix this flaky test in a separate PR once merged, or you can fix it in your PR. whichever you prefer.

@Flarna
Copy link
Member Author

Flarna commented Feb 1, 2021

@blumamir Thanks for the infos! I think it's better to fix this in a separate PR to avoid that I have to touch files from plugin in this PR.

@Flarna Flarna force-pushed the ioredis-instrumentation branch from f3ef976 to d4d5f5a Compare February 1, 2021 18:58
@blumamir blumamir mentioned this pull request Feb 2, 2021
@blumamir
Copy link
Member

blumamir commented Feb 2, 2021

@blumamir Thanks for the infos! I think it's better to fix this in a separate PR to avoid that I have to touch files from plugin in this PR.

opened an issue for that, so it won't get lost: #332

@vmarchaud
Copy link
Member

I think its good to go, /cc @dyladan are you good with merging it since you made about the flaky test ?

@obecny obecny added the enhancement New feature or request label Feb 2, 2021
@Flarna Flarna merged commit 118c5b1 into open-telemetry:main Feb 9, 2021
@Flarna Flarna deleted the ioredis-instrumentation branch February 9, 2021 14:38
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement New feature or request
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Convert ioredis plugin to instrumentation
5 participants