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

Double free on tlv encryption #140

Closed
timwr opened this Issue Oct 8, 2018 · 1 comment

Comments

Projects
None yet
1 participant
@timwr
Contributor

timwr commented Oct 8, 2018

I can only reproduce this on arm-iphone-darwin, but it seems valid:

[10-08-2018 12:03:52.580s] [mettle.c:74] Heartbeat
[10-08-2018 12:03:52.582s] [network_client.c:467] resolving 'tcp://192.168.0.1:4444'
[10-08-2018 12:03:52.583s] [network_client.c:345] connecting to tcp://192.168.0.1:4444
[10-08-2018 12:03:52.590s] [network_client.c:278] connected to 'tcp://192.168.0.1:4444'
[10-08-2018 12:03:53.259s] [tlv.c:562] processing method: 'core_negotiate_tlv_encryption' id: '99915465627355007360930290209782'
metnew(913,0x395b5000) malloc: *** error for object 0x14d40000: pointer being freed was not allocated
*** set a breakpoint in malloc_error_break to debug

I added the following printf calls:

diff --git a/mettle/src/crypttlv.c b/mettle/src/crypttlv.c
index 980f23b..27b3cc0 100644
--- a/mettle/src/crypttlv.c
+++ b/mettle/src/crypttlv.c
@@ -142,6 +142,8 @@ void * encrypt_tlv(struct tlv_encryption_ctx* ctx, void *p, size_t buf_len)
                                                        break;
                                                }
                                        } else {
+                                               fprintf(stdout, "free %p %s %d\n", out_buf, __FILE__, __LINE__);
+                                               fflush(stdout);
                                                free(out_buf);
                                                ctx->initialized = true;
                                        }
diff --git a/mettle/src/mettle.c b/mettle/src/mettle.c
index e26d20b..c5f5422 100644
--- a/mettle/src/mettle.c
+++ b/mettle/src/mettle.c
@@ -187,6 +187,8 @@ static void on_tlv_response(struct tlv_dispatcher *td, void *arg)

        while ((buf = tlv_dispatcher_dequeue_response(td, true, &len))) {
                c2_write(m->c2, buf, len);
+               fprintf(stdout, "free %p %s %d\n", buf, __FILE__, __LINE__);
+               fflush(stdout);
                free(buf);
        }
 }
diff --git a/mettle/src/tlv.c b/mettle/src/tlv.c
index 3098dee..9cc169a 100644
--- a/mettle/src/tlv.c
+++ b/mettle/src/tlv.c
@@ -65,6 +65,8 @@ struct tlv_packet *tlv_packet_new(uint32_t type, int initial_len)

 void tlv_packet_free(struct tlv_packet *p)
 {
+       fprintf(stdout, "free %p %s %d\n", p, __FILE__, __LINE__);
+       fflush(stdout);
        free(p);
 }
I then get either this:

[10-08-2018 11:58:30.590s] [mettle.c:74] Heartbeat
[10-08-2018 11:58:30.591s] [network_client.c:467] resolving 'tcp://192.168.0.1:4444'
[10-08-2018 11:58:30.593s] [network_client.c:345] connecting to tcp://192.168.0.1:4444
[10-08-2018 11:58:30.600s] [network_client.c:278] connected to 'tcp://192.168.0.1:4444'
[10-08-2018 11:58:31.118s] [tlv.c:564] processing method: 'core_negotiate_tlv_encryption' id: '42201925267011386347435249349904'
free 0x18aeea00 /mettle/mettle/src/tlv.c 68
free 0x17d590f0 /mettle/mettle/src/crypttlv.c 145
free 0x17d58ec0 /mettle/mettle/src/tlv.c 68
free 0x17d58ec0 /mettle/mettle/src/mettle.c 190
metnew(892,0x395b5000) malloc: *** error for object 0x17d58ec0: pointer being freed was not allocated
*** set a breakpoint in malloc_error_break to debug

or this:

[10-08-2018 12:05:44.451s] [mettle.c:74] Heartbeat
[10-08-2018 12:05:44.452s] [network_client.c:467] resolving 'tcp://192.168.0.1:4444'
[10-08-2018 12:05:44.453s] [network_client.c:345] connecting to tcp://192.168.0.1:4444
[10-08-2018 12:05:44.462s] [network_client.c:278] connected to 'tcp://192.168.0.1:4444'
free 0x15276600 /mettle/mettle/src/tlv.c 68
free 0x14e299a0 /mettle/mettle/src/crypttlv.c 145
free 0x14e299a0 /mettle/mettle/src/tlv.c 68
[10-08-2018 12:05:44.978s] [tlv.c:564] processing method: 'core_negotiate_tlv_encryption' id: '17117006685375890484474876493774'
metnew(928,0x395b5000) malloc: *** error for object 0x14e299a0: pointer being freed was not allocated
*** set a breakpoint in malloc_error_break to debug

I'm a bit stuck because removing the calls to free either gives me a different crash (access violation) or it gets stuck (without crashing) after processing method: 'core_negotiate_tlv_encryption'.

It appears there is some kind of heisenbug/schroedenbug/race condition occurring.

@timwr timwr added the bug label Oct 8, 2018

@timwr

This comment has been minimized.

Show comment
Hide comment
@timwr

timwr Oct 20, 2018

Contributor

It seems even after disabling TLV encryption (in the same way it's disabled for MINGW), the double free is fixed but the session still gets stuck:

[10-20-2018 12:00:04.270s] [tlv.c:562] processing method: 'core_negotiate_tlv_encryption' id: '02501631259874523319055204556026'
[10-20-2018 12:00:06.238s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:11.266s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:16.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:21.284s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:26.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:31.194s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:36.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:41.287s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:46.288s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:51.290s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:56.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:01.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:01.329s] [tlv.c:562] processing method: 'core_channel_eof' id: '90187191314102744240900835511059'
[10-20-2018 12:01:06.268s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:11.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:16.272s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:21.279s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:26.284s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:31.271s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:36.278s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:41.288s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:46.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:51.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:56.279s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:01.286s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:06.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:11.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:16.279s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:21.283s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:26.286s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:31.212s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:36.280s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:41.286s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:46.269s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:51.290s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:56.282s] [mettle.c:74] Heartbeat
[10-20-2018 12:03:01.268s] [mettle.c:74] Heartbeat

The only thing that works so far is reverting https://github.com/rapid7/mettle/pull/136/files :(

Contributor

timwr commented Oct 20, 2018

It seems even after disabling TLV encryption (in the same way it's disabled for MINGW), the double free is fixed but the session still gets stuck:

[10-20-2018 12:00:04.270s] [tlv.c:562] processing method: 'core_negotiate_tlv_encryption' id: '02501631259874523319055204556026'
[10-20-2018 12:00:06.238s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:11.266s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:16.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:21.284s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:26.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:31.194s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:36.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:41.287s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:46.288s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:51.290s] [mettle.c:74] Heartbeat
[10-20-2018 12:00:56.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:01.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:01.329s] [tlv.c:562] processing method: 'core_channel_eof' id: '90187191314102744240900835511059'
[10-20-2018 12:01:06.268s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:11.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:16.272s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:21.279s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:26.284s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:31.271s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:36.278s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:41.288s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:46.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:51.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:01:56.279s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:01.286s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:06.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:11.289s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:16.279s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:21.283s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:26.286s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:31.212s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:36.280s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:41.286s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:46.269s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:51.290s] [mettle.c:74] Heartbeat
[10-20-2018 12:02:56.282s] [mettle.c:74] Heartbeat
[10-20-2018 12:03:01.268s] [mettle.c:74] Heartbeat

The only thing that works so far is reverting https://github.com/rapid7/mettle/pull/136/files :(

timwr added a commit to timwr/mettle that referenced this issue Oct 20, 2018

@busterb busterb closed this in 1c0209c Oct 23, 2018

busterb added a commit that referenced this issue Oct 23, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment