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

tls_wrap: Unlink TLSWrap and SecureContext objects asap. #1580

Closed
wants to merge 1 commit into from

Conversation

ChALkeR
Copy link
Member

@ChALkeR ChALkeR commented May 1, 2015

This makes TLSWrap and SecureContext objects collectable by the incremental gc.

res = null; destroys the cyclic reference in the reading property, delete this.ssl removes the remaining reference. delete this.ssl._secureContext.context; makes SecureContext objects collectable by the incremental gc even though there might be references to this.ssl._secureContext somewhere.

The reading property will throw an error if accessed after the socket is closed. If this is unwanted then the property getter/setter should be altered. Can someone please comment on this part? Should be ok as it is.

Test results for 20000 opened-closed non keep-alive connections to localhost (100 parallel requests):

  1. b4ad5d7:
    1. Incremental GC timings: [2,3,3,5,6,6,11,11,10,10,10,11,11,9,10,10,11,10,10,11,12,10,12,10,12] = 226ms.
    2. Full GC timings: [31,29,31,30,29,30,31,22,32,29,31,30,29,29,29,30,31,29,29,19,27] = 607ms.
    3. GC runs: 25 incremental + 21 full = 46 total.
    4. Total GC time: 883ms.
    5. Average GC time: 19ms.
  2. b4ad5d7 + this pull request:
    1. Incremental GC timings: [2,3,3,5,6,6,13,11,12,11,10,11,14,10,11,12,10,13,11,12,10,11,12,10,11,13,11,11,12,10,14,10,13,10,12,11,11,10] = 388ms.
    2. Full GC timings: [16,12,13,11,12,15,13,16,13,13,14,14,13,12] = 187ms.
    3. GC runs: 38 incremental + 14 full = 52 total.
    4. Total GC time: 525ms.
    5. Average GC time: 11ms.

@ChALkeR
Copy link
Member Author

ChALkeR commented May 1, 2015

cc @indutny, @shigeki

@mscdex mscdex added the tls Issues and PRs related to the tls subsystem. label May 1, 2015
@ChALkeR
Copy link
Member Author

ChALkeR commented May 2, 2015

Just tested — the same results are applicable to the server — a full gc run goes from ~30ms to ~14ms.

@ChALkeR
Copy link
Member Author

ChALkeR commented May 2, 2015

delete this.ssl breaks aborted connections with iojs: ../src/stream_base.cc:373: static void node::StreamBase::AfterWrite(node::WriteWrap*, int): Assertion "(wrap->GetAsyncWrap()->persistent().IsEmpty()) == (false)” failed. I will take a look at that.
Fixed by @indutny with #1590.

@indutny
Copy link
Member

indutny commented May 2, 2015

Full stack trace:

* thread #1: tid = 0x76edba, 0x00007fff8ec85286 libsystem_kernel.dylib`__pthread_kill + 10, queue = 'com.apple.main-thread', stop reason = signal SIGABRT
  * frame #0: 0x00007fff8ec85286 libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fff8dff342f libsystem_pthread.dylib`pthread_kill + 90
    frame #2: 0x00007fff83ffab53 libsystem_c.dylib`abort + 129
    frame #3: 0x00007fff83fc2c39 libsystem_c.dylib`__assert_rtn + 321
    frame #4: 0x0000000100a9c110 iojs`node::StreamBase::AfterWrite(req_wrap=0x0000000104b06350, status=-89) + 304 at stream_base.cc:373
    frame #5: 0x0000000100a4aa52 iojs`node::StreamReq<node::WriteWrap>::Done(this=0x0000000104b06440, status=-89) + 34 at stream_base.h:26
    frame #6: 0x0000000100ad3b3e iojs`node::TLSWrap::InvokeQueued(this=0x0000000102059920, status=-89) + 142 at tls_wrap.cc:112
    frame #7: 0x0000000100ad3a04 iojs`node::TLSWrap::~TLSWrap(this=0x0000000102059920) + 196 at tls_wrap.cc:93
    frame #8: 0x0000000100ad3ba5 iojs`node::TLSWrap::~TLSWrap(this=0x0000000102059920) + 21 at tls_wrap.cc:77
    frame #9: 0x0000000100ad3c29 iojs`node::TLSWrap::~TLSWrap(this=0x0000000102059920) + 25 at tls_wrap.cc:77
    frame #10: 0x0000000100ad8344 iojs`void node::BaseObject::WeakCallback<node::TLSWrap>(data=0x00007fff5fbf5188) + 84 at base-object-inl.h:45
    frame #11: 0x00000001005426f6 iojs`v8::internal::GlobalHandles::Node::PostGarbageCollectionProcessing(this=0x0000000102899b40, isolate=0x0000000102804c00) + 614 at global-handles.cc:330
    frame #12: 0x000000010053f224 iojs`v8::internal::GlobalHandles::PostScavengeProcessing(this=0x000000010200aa00, initial_post_gc_processing_count=6) + 260 at global-handles.cc:779
    frame #13: 0x000000010053f7fa iojs`v8::internal::GlobalHandles::PostGarbageCollectionProcessing(this=0x000000010200aa00, collector=SCAVENGER) + 170 at global-handles.cc:863
    frame #14: 0x0000000100570eb6 iojs`v8::internal::Heap::PerformGarbageCollection(this=0x0000000102804c20, collector=SCAVENGER, gc_callback_flags=kNoGCCallbackFlags) + 854 at heap.cc:1185
    frame #15: 0x00000001005707a2 iojs`v8::internal::Heap::CollectGarbage(this=0x0000000102804c20, collector=SCAVENGER, gc_reason=0x0000000100c139a8, collector_reason=0x0000000000000000, gc_callback_flags=kNoGCCallbackFlags) + 674 at heap.cc:895
    frame #16: 0x0000000100271503 iojs`v8::internal::Heap::CollectGarbage(this=0x0000000102804c20, space=NEW_SPACE, gc_reason=0x0000000100c139a8, callbackFlags=kNoGCCallbackFlags) + 83 at heap-inl.h:576
    frame #17: 0x00000001004fbeb3 iojs`v8::internal::Factory::NewFixedArray(this=0x0000000102804c00, size=7, pretenure=NOT_TENURED) + 387 at factory.cc:66
    frame #18: 0x000000010086a8ca iojs`v8::internal::GetOwnProperty(isolate=0x0000000102804c00, obj=Handle<v8::internal::JSObject> at 0x00007fff5fbf5710, name=Handle<v8::internal::Name> at 0x00007fff5fbf5708) + 1066 at runtime-object.cc:409
    frame #19: 0x0000000100860804 iojs`v8::internal::__RT_impl_Runtime_GetOwnProperty(args=Arguments at 0x00007fff5fbf5788, isolate=0x0000000102804c00) + 308 at runtime-object.cc:442
    frame #20: 0x00000001008606be iojs`v8::internal::Runtime_GetOwnProperty(args_length=2, args_object=0x00007fff5fbf5828, isolate=0x0000000102804c00) + 110 at runtime-object.cc:436
    frame #21: 0x0000262f2bc060bb
    frame #22: 0x0000262f2bdae806
    frame #23: 0x0000262f2bdae36a
    frame #24: 0x0000262f2bdad1de
    frame #25: 0x0000262f2bdad0b7
    frame #26: 0x0000262f2bc14b35
    frame #27: 0x0000262f2bdacebc
    frame #28: 0x0000262f2bc14b35
    frame #29: 0x0000262f2bdac7fc
    frame #30: 0x0000262f2bdaaa4a
    frame #31: 0x0000262f2bda919c
    frame #32: 0x0000262f2bc14b35
    frame #33: 0x0000262f2bda87fb
    frame #34: 0x0000262f2bc1ad4c
    frame #35: 0x0000262f2bda6b6c
    frame #36: 0x0000262f2bc14b35
    frame #37: 0x0000262f2bc153bc
    frame #38: 0x0000262f2bc140d1
    frame #39: 0x00000001004ef522 iojs`v8::internal::Invoke(is_construct=false, function=Handle<v8::internal::JSFunction> at 0x00007fff5fbf5f80, receiver=Handle<v8::internal::Object> at 0x00007fff5fbf5f78, argc=1, args=0x00007fff5fbf6180) + 1330 at execution.cc:128
    frame #40: 0x00000001004eec9c iojs`v8::internal::Execution::Call(isolate=0x0000000102804c00, callable=Handle<v8::internal::Object> at 0x00007fff5fbf6020, receiver=Handle<v8::internal::Object> at 0x00007fff5fbf6018, argc=1, argv=0x00007fff5fbf6180, convert_receiver=true) + 748 at execution.cc:179
    frame #41: 0x0000000100845b99 iojs`v8::internal::__RT_impl_Runtime_Apply(args=Arguments at 0x00007fff5fbf6168, isolate=0x0000000102804c00) + 1625 at runtime-function.cc:607
    frame #42: 0x000000010084552e iojs`v8::internal::Runtime_Apply(args_length=5, args_object=0x00007fff5fbf6288, isolate=0x0000000102804c00) + 110 at runtime-function.cc:576
    frame #43: 0x0000262f2bc060bb
    frame #44: 0x0000262f2bd86ebd
    frame #45: 0x0000262f2bc14b35
    frame #46: 0x0000262f2bda22b4
    frame #47: 0x0000262f2bd72f9f
    frame #48: 0x0000262f2bcb9fe2
    frame #49: 0x0000262f2bc14b35
    frame #50: 0x0000262f2bd96d8e
    frame #51: 0x0000262f2bd72f9f
    frame #52: 0x0000262f2bcb9fe2
    frame #53: 0x0000262f2bc14b35
    frame #54: 0x0000262f2bd8f274
    frame #55: 0x0000262f2bc1ad4c
    frame #56: 0x0000262f2bd73298
    frame #57: 0x0000262f2bd86337
    frame #58: 0x0000262f2bcb9fa2
    frame #59: 0x0000262f2bd8eb24
    frame #60: 0x0000262f2bc1ad4c
    frame #61: 0x0000262f2bd71203
    frame #62: 0x0000262f2bc153c0
    frame #63: 0x0000262f2bc140d1
    frame #64: 0x00000001004ef522 iojs`v8::internal::Invoke(is_construct=false, function=Handle<v8::internal::JSFunction> at 0x00007fff5fbf6b00, receiver=Handle<v8::internal::Object> at 0x00007fff5fbf6af8, argc=0, args=0x0000000000000000) + 1330 at execution.cc:128
    frame #65: 0x00000001004eec9c iojs`v8::internal::Execution::Call(isolate=0x0000000102804c00, callable=Handle<v8::internal::Object> at 0x00007fff5fbf6ba0, receiver=Handle<v8::internal::Object> at 0x00007fff5fbf6b98, argc=0, argv=0x0000000000000000, convert_receiver=true) + 748 at execution.cc:179
    frame #66: 0x00000001002580c8 iojs`v8::Function::Call(this=0x0000000103005be0, recv=(val_ = 0x0000000103005a80), argc=0, argv=0x0000000000000000) + 472 at api.cc:4217
    frame #67: 0x0000000100a37dbc iojs`node::AsyncWrap::MakeCallback(this=0x00000001023cbf08, cb=(val_ = 0x0000000103000028), argc=3, argv=0x00007fff5fbf7130) + 2908 at async-wrap.cc:172
    frame #68: 0x0000000100a3afab iojs`node::AsyncWrap::MakeCallback(this=0x00000001023cbf08, symbol=(val_ = 0x0000000103005138), argc=3, argv=0x00007fff5fbf7130) + 219 at async-wrap-inl.h:76
    frame #69: 0x0000000100a9cae2 iojs`node::StreamBase::EmitData(this=0x00000001023cbec0, nread=-4095, buf=Local<v8::Object> at 0x00007fff5fbf7128, handle=Local<v8::Object> at 0x00007fff5fbf7120) + 418 at stream_base.cc:417
    frame #70: 0x0000000100ad367e iojs`node::TLSWrap::OnReadSelf(nread=-4095, buf=0x0000000000000000, pending=UV_UNKNOWN_HANDLE, ctx=0x00000001023cbdf0) + 174 at tls_wrap.cc:653
    frame #71: 0x0000000100a49972 iojs`node::StreamResource::OnRead(this=0x00000001023cbec0, nread=18446744073709547521, buf=0x0000000000000000, pending=UV_UNKNOWN_HANDLE) + 82 at stream_base.h:141
    frame #72: 0x0000000100ad617a iojs`node::TLSWrap::DoRead(this=0x00000001023cbdf0, nread=-4095, buf=0x00007fff5fbf7448, pending=UV_UNKNOWN_HANDLE) + 138 at tls_wrap.cc:671
    frame #73: 0x0000000100ad3533 iojs`node::TLSWrap::OnReadImpl(nread=-4095, buf=0x00007fff5fbf7448, pending=UV_UNKNOWN_HANDLE, ctx=0x00000001023cbdf0) + 51 at tls_wrap.cc:634
    frame #74: 0x0000000100a49972 iojs`node::StreamResource::OnRead(this=0x00000001023cbc90, nread=18446744073709547521, buf=0x00007fff5fbf7448, pending=UV_UNKNOWN_HANDLE) + 82 at stream_base.h:141
    frame #75: 0x0000000100aa1a09 iojs`node::StreamWrap::OnReadCommon(handle=0x00000001023cbce0, nread=-4095, buf=0x00007fff5fbf7448, pending=UV_UNKNOWN_HANDLE) + 377 at stream_wrap.cc:250
    frame #76: 0x0000000100aa14f6 iojs`node::StreamWrap::OnRead(handle=0x00000001023cbce0, nread=-4095, buf=0x00007fff5fbf7448) + 118 at stream_wrap.cc:265
    frame #77: 0x0000000100b1de5f iojs`uv__stream_eof(stream=0x00000001023cbce0, buf=0x00007fff5fbf7448) + 335 at stream.c:965
    frame #78: 0x0000000100b1dc11 iojs`uv__read(stream=0x00000001023cbce0) + 1505 at stream.c:1143
    frame #79: 0x0000000100b195ac iojs`uv__stream_io(loop=0x0000000101110fd8, w=0x00000001023cbd68, events=1) + 380 at stream.c:1219
    frame #80: 0x0000000100b2810c iojs`uv__io_poll(loop=0x0000000101110fd8, timeout=0) + 3564 at kqueue.c:247
    frame #81: 0x0000000100b0ca41 iojs`uv_run(loop=0x0000000101110fd8, mode=UV_RUN_ONCE) + 225 at core.c:324
    frame #82: 0x0000000100a58454 iojs`node::StartNodeInstance(arg=0x00007fff5fbff8e0) + 468 at node.cc:3899
    frame #83: 0x0000000100a581fd iojs`node::Start(argc=2, argv=0x0000000102008ef0) + 269 at node.cc:3964
    frame #84: 0x0000000100a840b2 iojs`main(argc=2, argv=0x00007fff5fbff980) + 34 at node_main.cc:44
    frame #85: 0x0000000100001934 iojs`start + 52

Looking into it...

indutny added a commit to indutny/io.js that referenced this pull request May 2, 2015
`StreamBase::AfterWrite` is passing handle as an argument to the
`afterWrite` function in net.js. Thus GC should not collect the handle
and the request separately and assume that they are tied together.

With this commit - request will always outlive the StreamBase instance,
helping us survive the GC pass.

Fix: nodejs#1580
@indutny
Copy link
Member

indutny commented May 2, 2015

Should be fixed by #1590

@ChALkeR
Copy link
Member Author

ChALkeR commented May 2, 2015

Yes, that issue is fixed by #1590 for me. It didn't affect the GC timings I posted above.

indutny added a commit that referenced this pull request May 3, 2015
`StreamBase::AfterWrite` is passing handle as an argument to the
`afterWrite` function in net.js. Thus GC should not collect the handle
and the request separately and assume that they are tied together.

With this commit - request will always outlive the StreamBase instance,
helping us survive the GC pass.

Same applies to the ShutdownWrap instances, they should never be
collected after the StreamBase instance.

Fix: #1580
PR-URL: #1590
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
@ChALkeR ChALkeR force-pushed the unlink-tlswrap-securecontext branch from 7fa24d6 to 0bc9ec8 Compare May 3, 2015 08:43
@ChALkeR
Copy link
Member Author

ChALkeR commented May 3, 2015

Rebased against current master (with #1590 fix), the timings are about the same as above so I won't copy them here again.
Works for me now.

@shigeki
Copy link
Contributor

shigeki commented May 4, 2015

Is there any reason to use delete?

I wonder that it deletes properties defined in a constructor so that it would break a reference to the hidden class. Substituting nuIl instead of using delete also gets gc improvements as below. Tested the same parameter (100 concurrent, 20000 iteration).

master

gc_count=57 mark_sweep_count=24 max_gc_pause=30.5 total_gc_time=821.0 min_in_mutator=0.3 max_alive_after_gc=25839280 total_marking_time=583.6 total_sweeping_time=336.3

this PR

gc_count=61 mark_sweep_count=12 max_gc_pause=11.1 total_gc_time=511.9 min_in_mutator=0.3 max_alive_after_gc=35002000 total_marking_time=207.5 total_sweeping_time=93.5

PR without using delete.

diff --git a/lib/_tls_wrap.js b/lib/_tls_wrap.js
index c0edd0e..0a30cd3 100644
--- a/lib/_tls_wrap.js
+++ b/lib/_tls_wrap.js
@@ -302,9 +302,9 @@ TLSSocket.prototype._destroySSL = function _destroySSL() {
   this.ssl.destroySSL();
   if (this.ssl._secureContext.singleUse) {
     this.ssl._secureContext.context.close();
-    delete this.ssl._secureContext.context;
+    this.ssl._secureContext.context = null;
   }
-  delete this.ssl;
+  this.ssl = null;
 };

 TLSSocket.prototype._init = function(socket, wrap) {
gc_count=52 mark_sweep_count=10 max_gc_pause=14.1 total_gc_time=417.1 min_in_mutator=0.3 max_alive_after_gc=32727904 total_marking_time=159.4 total_sweeping_time=71.3

@ChALkeR ChALkeR force-pushed the unlink-tlswrap-securecontext branch from 0bc9ec8 to 725d7ba Compare May 4, 2015 07:30
@ChALkeR
Copy link
Member Author

ChALkeR commented May 4, 2015

@shigeki No, there is no specific need in delete. I updated the PR, thanks!

@shigeki
Copy link
Contributor

shigeki commented May 4, 2015

@ChALkeR LGTM. Nice work!
@indutny How about you?

@indutny
Copy link
Member

indutny commented May 4, 2015

LGTM to me too, landing.

@indutny
Copy link
Member

indutny commented May 4, 2015

Oh, @ChALkeR ! May I ask you to review this paragraph of the CONTRIBUTING.md:

https://github.com/iojs/io.js/blob/master/CONTRIBUTING.md#step-3-commit

Particularly, please format the commit log according to it, and please add some contents to it as well ;)

Thank you again!

@ChALkeR ChALkeR force-pushed the unlink-tlswrap-securecontext branch from 725d7ba to f214b9a Compare May 4, 2015 10:51
This makes `TLSWrap` and `SecureContext` objects collectable by the
incremental gc.

`res = null` destroys the cyclic reference in the `reading` property.
`this.ssl = null` removes the remaining reference to the `TLSWrap`.
`this.ssl._secureContext.context = null` removes the reference to
the `SecureContext` object, even though there might be references
to `this.ssl._secureContext` somewhere.

The `reading` property will now throw an error if accessed after the
socket is closed, but that should not happen.
@ChALkeR ChALkeR force-pushed the unlink-tlswrap-securecontext branch from f214b9a to 9ab8f9d Compare May 4, 2015 10:52
@ChALkeR
Copy link
Member Author

ChALkeR commented May 4, 2015

@indutny I added info from the PR to the commit message. Rebased against current master.

indutny pushed a commit that referenced this pull request May 4, 2015
This makes `TLSWrap` and `SecureContext` objects collectable by the
incremental gc.

`res = null` destroys the cyclic reference in the `reading` property.
`this.ssl = null` removes the remaining reference to the `TLSWrap`.
`this.ssl._secureContext.context = null` removes the reference to
the `SecureContext` object, even though there might be references
to `this.ssl._secureContext` somewhere.

The `reading` property will now throw an error if accessed after the
socket is closed, but that should not happen.

PR-URL: #1580
Reviewed-By: Fedor Indutny <fedor@indutny.com>
Reviewed-By: Shigeki Ohtsu <ohtsu@iij.ad.jp>
@indutny
Copy link
Member

indutny commented May 4, 2015

Landed in f7620fb, thank you!

@indutny indutny closed this May 4, 2015
@rvagg rvagg mentioned this pull request May 4, 2015
@ChALkeR
Copy link
Member Author

ChALkeR commented May 4, 2015

Thanks!

@ChALkeR ChALkeR deleted the unlink-tlswrap-securecontext branch May 4, 2015 21:14
Fishrock123 pushed a commit to Fishrock123/node that referenced this pull request May 19, 2015
`StreamBase::AfterWrite` is passing handle as an argument to the
`afterWrite` function in net.js. Thus GC should not collect the handle
and the request separately and assume that they are tied together.

With this commit - request will always outlive the StreamBase instance,
helping us survive the GC pass.

Same applies to the ShutdownWrap instances, they should never be
collected after the StreamBase instance.

Fix: nodejs#1580
PR-URL: nodejs#1590
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Fishrock123 pushed a commit to Fishrock123/node that referenced this pull request May 19, 2015
This makes `TLSWrap` and `SecureContext` objects collectable by the
incremental gc.

`res = null` destroys the cyclic reference in the `reading` property.
`this.ssl = null` removes the remaining reference to the `TLSWrap`.
`this.ssl._secureContext.context = null` removes the reference to
the `SecureContext` object, even though there might be references
to `this.ssl._secureContext` somewhere.

The `reading` property will now throw an error if accessed after the
socket is closed, but that should not happen.

PR-URL: nodejs#1580
Reviewed-By: Fedor Indutny <fedor@indutny.com>
Reviewed-By: Shigeki Ohtsu <ohtsu@iij.ad.jp>
@ChALkeR ChALkeR added the memory Issues and PRs related to the memory management or memory footprint. label Aug 17, 2015
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
memory Issues and PRs related to the memory management or memory footprint. tls Issues and PRs related to the tls subsystem.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants