platform: fix mem_trace trace level guard #5614

maciejbocianski · 2017-11-29T11:40:39Z

Description

This change fix "trace inside trace" issue in mem_trace module
It prevents from tracing malloc/free calls inside __wrap__realloc_r/__wrap__calloc_r/SUB_REALLOC/SUB_CALLOC

Status

READY

Migrations

Change mbed_mem_trace module API
add functions: mbed_mem_trace_level_incr mbed_mem_trace_level_decr

YES

0xc0170 · 2017-11-29T17:10:12Z

This change fix "trace inside trace" issue in mem_trace module

Was this reported anywhere? Can you please amend your commit to add more details how is this fixing the issue and why are we introducing new API - how it should be used?

maciejbocianski · 2017-11-29T21:09:42Z

Problem was discovered during mbed_drivers-mem_trace test refactoring.
As I understand (and according description in mbed_mem_trace.c) we don't want to trace nested calls of malloc/free inside realloc/calloc - current implementation doesn't work.
Maybe I'm wrong ?

mbed_mem_trace.c:

/* 'trace_level' guards "trace inside trace" situations (for example, the implementation
 * of realloc() might call malloc() internally, and since malloc() is also traced, this could
 * result in two calls to the callback function instead of one. */
static uint8_t trace_level;

bulislaw · 2017-12-01T13:52:12Z

Could be change the nomenclature used to lock/unlock? And it can be binary, I don't think we need levels really.

maciejbocianski · 2017-12-04T09:25:34Z

@bulislaw updated

maciejbocianski · 2017-12-07T07:47:15Z

ping

0xc0170 · 2017-12-07T08:29:04Z

I do not fully understand this fix. trave_level (typo there? should be trace_level) was implemented internally to prevent this.

Why do we need API to expose locking? It can not be hidden, internally done. Is this expected from a user to use everytime mem_trace API is invoked? I can see that we as a caller, we use mem_trace_mutex above, why this is done on top of mutex (it's invoked before the mutex).

maciejbocianski · 2017-12-07T08:59:39Z

Why do we need API to expose locking? It can not be hidden, internally done. Is this expected from a user to use everytime mem_trace API is invoked? I can see that we as a caller, we use mem_trace_mutex above, why this is done on top of mutex (it's invoked before the mutex).

mem_trace_mutex protects only single trace callback call
When we enter realloc we don't want to trace it's internal calls of malloc/free this is why we lock trace_lock_count at the function beginning.
Without this lock realloc could report also malloc/free trace

0xc0170 · 2017-12-07T09:41:09Z

How previously that level variable inside was failing to prevent this ?

maciejbocianski · 2017-12-07T10:26:40Z

Previously it was protecting mem_trace_cb call only.
And since it's impossible to call mem_trace_cb recursively it was protecting nothing and was redundancy to mem_trace_mutex

0xc0170 · 2017-12-11T09:29:10Z

/morph build

mbed-ci · 2017-12-11T10:09:13Z

Build : SUCCESS

Build number : 675
Build artifacts/logs : http://mbed-os.s3-website-eu-west-1.amazonaws.com/?prefix=builds/5614/

Triggering tests

/morph test
/morph uvisor-test
/morph export-build

mbed-ci · 2017-12-11T12:44:58Z

Exporter Build : SUCCESS

Build number : 319
Build artifacts/logs : http://mbed-os.s3-website-eu-west-1.amazonaws.com/?prefix=builds/exporter/5614/

mbed-ci · 2017-12-11T12:53:27Z

Test : SUCCESS

Build number : 501
Test logs :http://mbed-os-logs.s3-website-us-west-1.amazonaws.com/?prefix=logs/5614/501

c1728p9 · 2017-12-11T17:58:23Z

platform/mbed_alloc_wrappers.cpp

@@ -91,6 +91,9 @@ extern "C" {

 extern "C" void * __wrap__malloc_r(struct _reent * r, size_t size) {
    void *ptr = NULL;
+#ifdef MBED_MEM_TRACING_ENABLED
+    mbed_mem_trace_lock();


The memory trace mutex should be held here, otherwise another thread my have acquired this lock but not the mutex, causing logging on other threads to be dropped. Could mbed_mem_trace_lock() include mem_trace_mutex->lock() to simply this?

I mistakenly assumed that whole __wrap__malloc_r is protected by __malloc_lock but actually __real__malloc_r is protected

Sure we could encapsulate mem_trace_mutex inside mbed_mem_trace.c module but since it's C file we have to use raw OS mutex.
Other solution could be changing this module to cpp and use SingletonPtr<PlatformMutex>

I'm not sure which solution will be acceptable?

c1728p9 · 2017-12-11T17:59:40Z

platform/mbed_mem_trace.c

-static uint8_t trace_level;
+static uint8_t trace_lock_count;
+
+#define TRACE_IS_LOCKED() (trace_lock_count > 1)


This returns false even if lock count is 1. Maybe a different name, such as TRACE_FIRST_LOCK would be more appropriate.

maciejbocianski · 2017-12-18T09:21:40Z

updated
@c1728p9

c1728p9 · 2017-12-18T15:51:49Z

platform/mbed_mem_trace.cpp

+void mbed_mem_trace_lock()
+{
+    mem_trace_mutex->lock();
+    core_util_atomic_incr_u8(&trace_lock_count, 1);


nitpick - this doesn't need to be atomically incremented since this is protected by the mutex.

0xc0170 · 2017-12-19T08:56:48Z

/morph build

mbed-ci · 2017-12-19T09:31:45Z

Build : SUCCESS

Build number : 719
Build artifacts/logs : http://mbed-os.s3-website-eu-west-1.amazonaws.com/?prefix=builds/5614/

Triggering tests

/morph test
/morph uvisor-test
/morph export-build

mbed-ci · 2017-12-19T10:19:00Z

Exporter Build : FAILURE

Build number : 371
Build artifacts/logs : http://mbed-os.s3-website-eu-west-1.amazonaws.com/?prefix=builds/exporter/5614/

mbed-ci · 2017-12-19T10:42:33Z

Test : FAILURE

Build number : 549
Test logs :http://mbed-os-logs.s3-website-us-west-1.amazonaws.com/?prefix=logs/5614/549

0xc0170 · 2017-12-19T11:10:44Z

/morph test

mbed-ci · 2017-12-19T13:42:00Z

Test : SUCCESS

Build number : 551
Test logs :http://mbed-os-logs.s3-website-us-west-1.amazonaws.com/?prefix=logs/5614/551

0xc0170 · 2017-12-22T09:18:04Z

/morph build

mbed-ci · 2017-12-22T10:34:01Z

Build : SUCCESS

Build number : 754
Build artifacts/logs : http://mbed-os.s3-website-eu-west-1.amazonaws.com/?prefix=builds/5614/

Triggering tests

/morph test
/morph uvisor-test
/morph export-build

mbed-ci · 2017-12-22T13:00:28Z

Exporter Build : SUCCESS

Build number : 407
Build artifacts/logs : http://mbed-os.s3-website-eu-west-1.amazonaws.com/?prefix=builds/exporter/5614/

mbed-ci · 2017-12-22T17:38:44Z

Test : FAILURE

Build number : 578
Test logs :http://mbed-os-logs.s3-website-us-west-1.amazonaws.com/?prefix=logs/5614/578

cmonr · 2017-12-28T21:39:38Z

Restarting builds. Results were not reported.

/morph build

mbed-ci · 2017-12-28T21:59:28Z

Build : SUCCESS

Build number : 765
Build artifacts/logs : http://mbed-os.s3-website-eu-west-1.amazonaws.com/?prefix=builds/5614/

Triggering tests

/morph test
/morph uvisor-test
/morph export-build

mbed-ci · 2017-12-28T23:26:05Z

Exporter Build : SUCCESS

Build number : 421
Build artifacts/logs : http://mbed-os.s3-website-eu-west-1.amazonaws.com/?prefix=builds/exporter/5614/

cmonr · 2017-12-28T23:32:13Z

Restarting uVisor test due to odd failure with K64F.

/morph uvisor-test

mbed-ci · 2017-12-29T00:06:53Z

Test : SUCCESS

Build number : 595
Test logs :http://mbed-os-logs.s3-website-us-west-1.amazonaws.com/?prefix=logs/5614/595

0xc0170 requested review from deepikabhavnani and c1728p9 November 29, 2017 11:57

0xc0170 added the needs: review label Nov 29, 2017

maciejbocianski force-pushed the mem_trace_fix branch from 2e8c866 to 742f052 Compare November 29, 2017 12:56

0xc0170 added needs: work and removed needs: review labels Nov 29, 2017

maciejbocianski force-pushed the mem_trace_fix branch 2 times, most recently from 18b5776 to 5500f5d Compare December 4, 2017 09:21

0xc0170 added needs: review and removed needs: work labels Dec 4, 2017

bulislaw approved these changes Dec 5, 2017

View reviewed changes

maciejbocianski mentioned this pull request Dec 7, 2017

mem_trace tests refactoring #5673

Merged

0xc0170 added needs: CI and removed needs: review labels Dec 11, 2017

0xc0170 approved these changes Dec 11, 2017

View reviewed changes

c1728p9 reviewed Dec 11, 2017

View reviewed changes

c1728p9 approved these changes Dec 18, 2017

View reviewed changes

deepikabhavnani approved these changes Dec 18, 2017

View reviewed changes

maciejbocianski force-pushed the mem_trace_fix branch from 923f32d to d78d8c0 Compare December 19, 2017 06:56

maciejbocianski force-pushed the mem_trace_fix branch from d78d8c0 to 1e04d19 Compare December 20, 2017 13:12

0xc0170 added needs: CI and removed needs: work labels Dec 20, 2017

maciejbocianski force-pushed the mem_trace_fix branch from 1e04d19 to 5c417d0 Compare December 21, 2017 13:39

platform: fix mem_trace trace_level guard

aa22ef1

maciejbocianski force-pushed the mem_trace_fix branch from 5c417d0 to aa22ef1 Compare December 23, 2017 08:20

cmonr added ready for merge release-version: 5.7.2 and removed needs: CI labels Dec 29, 2017

adbridge merged commit c4211e1 into ARMmbed:master Dec 29, 2017

adbridge removed the ready for merge label Dec 29, 2017

platform: fix mem_trace trace level guard #5614

platform: fix mem_trace trace level guard #5614

Conversation

maciejbocianski commented Nov 29, 2017

Description

Status

Migrations

0xc0170 commented Nov 29, 2017

maciejbocianski commented Nov 29, 2017

bulislaw commented Dec 1, 2017

maciejbocianski commented Dec 4, 2017

maciejbocianski commented Dec 7, 2017

0xc0170 commented Dec 7, 2017

maciejbocianski commented Dec 7, 2017 • edited Loading

0xc0170 commented Dec 7, 2017

maciejbocianski commented Dec 7, 2017 • edited Loading

0xc0170 commented Dec 11, 2017

mbed-ci commented Dec 11, 2017

Triggering tests

mbed-ci commented Dec 11, 2017

mbed-ci commented Dec 11, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

maciejbocianski Dec 12, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

maciejbocianski commented Dec 18, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

0xc0170 commented Dec 19, 2017

mbed-ci commented Dec 19, 2017

Triggering tests

mbed-ci commented Dec 19, 2017

mbed-ci commented Dec 19, 2017

0xc0170 commented Dec 19, 2017

mbed-ci commented Dec 19, 2017

0xc0170 commented Dec 22, 2017

mbed-ci commented Dec 22, 2017

Triggering tests

mbed-ci commented Dec 22, 2017

mbed-ci commented Dec 22, 2017

cmonr commented Dec 28, 2017

mbed-ci commented Dec 28, 2017

Triggering tests

mbed-ci commented Dec 28, 2017

cmonr commented Dec 28, 2017

mbed-ci commented Dec 29, 2017

maciejbocianski commented Dec 7, 2017 •

edited

Loading

maciejbocianski commented Dec 7, 2017 •

edited

Loading

maciejbocianski Dec 12, 2017 •

edited

Loading