Prevent after_commit from being called multiple times

[joshjordan]

Ran into this while upgrading from neo4jrb 9 to activegraph. Our rails model test detected that after_commit hooks were being called multiple times. Something like this failed:

it "schedules do not disturb after the flag is changed" do
      expect(@user).to receive(:schedule_notification)

      @user.update_attributes(
        pending_notification: true
      )
end

where our User model had:

  after_update_commit do
    self.schedule_notification
  end

Our test failed claiming that schedule_notification was being called twice, and I went on to do some logging in activegraph to find that there was no guard against multiple close calls on a transaction, and auto_closable is causing close to be called both as part of successfully running the transaction and as part of auto-closing.

This pull introduces/changes:

• Prevent erroneous calls to after_commit multiple times when a single transaction is closing
• Prevent unnecessary calls, which add overhead, to other close functions including the super method from neo4j-ruby-driver
  • Minor fix to README, which tripped me up, because it does not reflect what the port that set_default_driver is acutally attempting to use

[codeclimate[bot]]

Code Climate has analyzed commit 5a95fa3d and detected 0 issues on this pull request.

View more on Code Climate.

[klobuczek]

@joshjordan thanks for your contribution. However, I don't see how the transaction could be closed multiple times. Are you calling explicitly close in addition to autoclose? The changed specs pass even without the changes to ActiveGraph::Transaction so we need to understand a bit more here. Please note that activegraph does not support explicit transactions anymore as neo4j(rb) did. Only transaction functions (lambdas in ruby) are supported.

[joshjordan]

No, not calling close explicitly. I’m confused — I discovered this in our neo4j rails project, but a fresh check out of active graph on my machine with this spec fails because data equals 2 at the end of the test. Why would our tests be producing different results?

On Mon, Dec 7, 2020 at 6:30 PM Heinrich Klobuczek notifications@github.com wrote:

@joshjordan https://github.com/joshjordan thanks for your contribution. However, I don't see how the transaction could be closed multiple times. Are you calling explicitly close in addition to autoclose? The changed specs pass even without the changes to ActiveGraph::Transaction so we need to understand a bit more here. Please note that activegraph does not support explicit transactions anymore as neo4j(rb) did. Only transaction functions (lambdas in ruby) are supported.

— You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub https://github.com/neo4jrb/activegraph/pull/1636#issuecomment-740244641, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAD7LSU6OZEABW57MUXETWTSTVQQBANCNFSM4URCW26Q .

[joshjordan]

If I removed my change in transaction.rb:

$ NEO4J_URL=bolt://localhost:7687 rspec spec/active_graph/base_spec.rb:136
Run options: include {:locations=>{"./spec/active_graph/base_spec.rb"=>[136]}}
F..

Failures:

  1) ActiveGraph::Base transactions after_commit hook gets called when the root transaction is closed
     Failure/Error:
       expect do
         subject.transaction do |tx1|
           subject.transaction do |tx2|
             subject.transaction do |tx3|
               tx3.after_commit { data += 1 }
             end
           end
         end
       end.to change { data }.to(1)

       expected `data` to have changed to 1, but is now 2
     # ./spec/active_graph/base_spec.rb:139:in `block (4 levels) in <top (required)>'

Finished in 0.21798 seconds (files took 0.72649 seconds to load)
3 examples, 1 failure

Failed examples:

rspec ./spec/active_graph/base_spec.rb:137 # ActiveGraph::Base transactions after_commit hook gets called when the root transaction is closed

Coverage report generated for RSpec to /Users/jjordan/code/activegraph/coverage. 2412 / 5141 LOC (46.92%) covered.
Stopped processing SimpleCov as a previous error not related to SimpleCov has been detected

[joshjordan]

Full diff to show that's my only local change:

[joshjordan]

Would you like me to push another branch to Travis to see if CI experiences the same failure?

[klobuczek]

yes, please do. It would be good to know where the extra close is coming from.

[klobuczek]

I think I know. The session.close is calling tx.close assuming it is idempotent. This is a neo4j driver problem and only on MRI. The jRuby version does not have the issue and hence our discrepancy. The travis build should show it too.

[joshjordan]

In any case, it would make sense to prevent double closed even if the client code (eg my code) attempted to do so, no?

On Mon, Dec 7, 2020 at 6:54 PM Heinrich Klobuczek notifications@github.com wrote:

I think I know. The session.close is calling tx.close assuming it is idempotent. This is a neo4j driver problem and only on MRI. The jRuby version does not have the issue and hence our discrepancy. The travis build should show it too.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/neo4jrb/activegraph/pull/1636#issuecomment-740253138, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAD7LSUPFCKBMZN2TNXEVZLSTVTLVANCNFSM4URCW26Q .

[klobuczek]

for the client-side I would say no. There is no api for that. Someone would have to call close within that block, which is not well defined and may have other side effects, but the session.close has to be addressed either in the driver or activegraph. BTW: Transaction has open? method.

[joshjordan]

Well, I'm mostly indifferent to where this gets fixed, but for what its worth: the activegraph read_transaction and write_transaction methods do expose the transaction object, so the API does exist. We've certainly seen third party code that calls close at the end of a transaction when its actually unnecessary to do so (where open? would return true, but close would still end up called twice). But, as a larger issue ignoring the client-side, consider this: even the maintainers of activegraph made this mistake. Isn't that evidence enough that the code should guard against accidental double-calls to close?

On Mon, Dec 7, 2020 at 7:04 PM Heinrich Klobuczek notifications@github.com wrote:

for the client-side I would say no. There is no api for that. Someone would have to call close within that block, which is not well defined and may have other side effects, but the session.close has to be addressed either in the driver or activegraph. BTW: Transaction has open? method.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/neo4jrb/activegraph/pull/1636#issuecomment-740256828, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAD7LSVBBCMGFO7GIBES3S3STVURHANCNFSM4URCW26Q .

[codecov-io]

Codecov Report

Merging #1636 (5a95fa3) into master (6a124dc) will decrease coverage by 0.13%. The diff coverage is 100.00%.

@@            Coverage Diff             @@
##           master    #1636      +/-   ##
==========================================
- Coverage   93.91%   93.78%   -0.14%     
==========================================
  Files         126      126              
  Lines        5735     5709      -26     
==========================================
- Hits         5386     5354      -32     
- Misses        349      355       +6     

Impacted Files	Coverage Δ
lib/active_graph/transaction.rb	100.00% <100.00%> (ø)
lib/active_graph/shared/initialize.rb	86.20% <0.00%> (-13.80%)	:arrow_down:
lib/active_graph/core/schema.rb	96.77% <0.00%> (-3.23%)	:arrow_down:
lib/active_graph/node/has_n/association.rb	94.07% <0.00%> (-1.41%)	:arrow_down:
lib/active_graph/node/query/query_proxy_methods.rb	96.45% <0.00%> (-0.75%)	:arrow_down:
lib/active_graph/shared/persistence.rb	95.13% <0.00%> (-0.70%)	:arrow_down:
lib/active_graph/node/query/query_proxy.rb	95.62% <0.00%> (-0.63%)	:arrow_down:
lib/active_graph/node/property.rb	94.11% <0.00%> (-0.17%)	:arrow_down:
lib/active_graph/node/labels.rb	94.73% <0.00%> (-0.11%)	:arrow_down:
lib/active_graph/shared/declared_property.rb	93.65% <0.00%> (-0.10%)	:arrow_down:
... and 14 more

---

Continue to review full report at Codecov.

Legend - Click here to learn more Δ = absolute <relative> (impact), ø = not affected, ? = missing data Powered by Codecov. Last update 6a124dc...5a95fa3. Read the comment docs.

[hut8]

Thanks for raising this. We just discovered that we've been double-emailing users from one of our after commit hooks due to this. Ouch.

Any word on when this will be merged? It does look like it should be fixed in Active Graph instead of the ruby driver, since it is Active Graph that has the code that's erroneous to repeat. The ruby driver's code appears to be safe if called more than once.

[klobuczek]

@joshjordan @hut8 the issue has already been solved in a different way in activegraph 11. I retrofitted the change into activegraph 10 to keep consistency. See https://github.com/neo4jrb/activegraph/commit/0dad770ff84a365f3cbc72fd2138c9e650bd4e9e Release of 10.0.2 within the next hour. Thank you again.

[joshjordan]

Thanks @klobuczek !