dbg_Message print's out of order from C++ (multi-threaded printing?); very strange behavior | developer.brewmp.com dbg_Message print's out of order from C++ (multi-threaded printing?); very strange behavior | developer.brewmp.com

Developer

dbg_Message print's out of order from C++ (multi-threaded printing?); very strange behavior

Forums:

Problem:
Calling several dbg_Message in a row with different DBG_MSG_LEVEL_* prints a few out of order.
This code is behaving like it's multi-threaded yet the printing occurs within one thread.
Is this a symptom of a serious bug?
Is this expected behavior for different DBG_MSG_LEVEL_* values?
Is this the result of a background debug printing thread mixing the order of queued messages?
This occurs on the Windows Simulator.
I have not tried running this code on a handset.
This out-of-order printing only appears to happen with C++ code (see the output below).
The order of print messages is not consistent.
You will have to play around with the code to isolate the circumstances.

Reproduction Code:
File: project_foo.c
#include "project_foo_helpers.h"
...
static int Project_Foo_CtorZ(Project_Foo* pMe, IEnv* piEnv)
{
// ... default generated startup code ...
// user code starts here...
dbg_Message("dbg_Message 01: LOW (dbg_Message)" , DBG_MSG_LEVEL_LOW, __FILE__ , __LINE__);
dbg_Message("dbg_Message 02: MEDIUM (dbg_Message)" , DBG_MSG_LEVEL_MEDIUM, __FILE__ , __LINE__);
dbg_Message("dbg_Message 03: HIGH (dbg_Message)" , DBG_MSG_LEVEL_HIGH, __FILE__ , __LINE__);
dbg_Message("dbg_Message 04: ERROR (dbg_Message)" , DBG_MSG_LEVEL_ERROR, __FILE__ , __LINE__);
dbg_Message("dbg_Message 05: FATAL (dbg_Message)" , DBG_MSG_LEVEL_FATAL, __FILE__ , __LINE__);
dbg_Message("dbg_Message 06: LOW (dbg_Message)" , DBG_MSG_LEVEL_LOW, __FILE__ , __LINE__);
dbg_Message("dbg_Message 07: MEDIUM (dbg_Message)" , DBG_MSG_LEVEL_MEDIUM, __FILE__ , __LINE__);
dbg_Message("dbg_Message 08: HIGH (dbg_Message)" , DBG_MSG_LEVEL_HIGH, __FILE__ , __LINE__);
dbg_Message("dbg_Message 09: ERROR (dbg_Message)" , DBG_MSG_LEVEL_ERROR, __FILE__ , __LINE__);
dbg_Message("dbg_Message 10: FATAL (dbg_Message)" , DBG_MSG_LEVEL_FATAL, __FILE__ , __LINE__);

PrintProgData((void *) pMe);
...

File: project_foo_helpers.h
extern "C" void PrintProgData(const void * pMeAsVoid);
File: project_foo_helpers.cpp
void PrintProgData(const void * pMeAsVoid)
{
dbg_Message("dbg_Message 11: LOW (dbg_Message)" , DBG_MSG_LEVEL_LOW, __FILE__ , __LINE__);
dbg_Message("dbg_Message 12: MEDIUM (dbg_Message)" , DBG_MSG_LEVEL_MEDIUM, __FILE__ , __LINE__);
dbg_Message("dbg_Message 13: HIGH (dbg_Message)" , DBG_MSG_LEVEL_HIGH, __FILE__ , __LINE__);
dbg_Message("dbg_Message 14: ERROR (dbg_Message)" , DBG_MSG_LEVEL_ERROR, __FILE__ , __LINE__);
dbg_Message("dbg_Message 15: FATAL (dbg_Message)" , DBG_MSG_LEVEL_FATAL, __FILE__ , __LINE__);
dbg_Message("dbg_Message 16: LOW (dbg_Message)" , DBG_MSG_LEVEL_LOW, __FILE__ , __LINE__);
dbg_Message("dbg_Message 17: MEDIUM (dbg_Message)" , DBG_MSG_LEVEL_MEDIUM, __FILE__ , __LINE__);
dbg_Message("dbg_Message 18: HIGH (dbg_Message)" , DBG_MSG_LEVEL_HIGH, __FILE__ , __LINE__);
dbg_Message("dbg_Message 19: ERROR (dbg_Message)" , DBG_MSG_LEVEL_ERROR, __FILE__ , __LINE__);
dbg_Message("dbg_Message 20: FATAL (dbg_Message)" , DBG_MSG_LEVEL_FATAL, __FILE__ , __LINE__);
...

Output:
Quote:
2010/05/21 16:04:06 project_foo.c:174 - dbg_Message 01: LOW (dbg_Message)
2010/05/21 16:04:06 project_foo.c:175 - dbg_Message 02: MEDIUM (dbg_Message)
2010/05/21 16:04:06 project_foo.c:176 - dbg_Message 03: HIGH (dbg_Message)
2010/05/21 16:04:06 project_foo.c:177 - dbg_Message 04: ERROR (dbg_Message)
2010/05/21 16:04:06 project_foo.c:178 - dbg_Message 05: FATAL (dbg_Message)
2010/05/21 16:04:06 project_foo.c:179 - dbg_Message 06: LOW (dbg_Message)
2010/05/21 16:04:06 project_foo.c:180 - dbg_Message 07: MEDIUM (dbg_Message)
2010/05/21 16:04:06 project_foo.c:181 - dbg_Message 08: HIGH (dbg_Message)
2010/05/21 16:04:06 project_foo.c:182 - dbg_Message 09: ERROR (dbg_Message)
2010/05/21 16:04:06 project_foo.c:183 - dbg_Message 10: FATAL (dbg_Message)
2010/05/21 16:04:06 project_foo_helpers.cpp:969 - dbg_Message 12: MEDIUM (dbg_Message)
2010/05/21 16:04:06 project_foo_helpers.cpp:968 - dbg_Message 11: LOW (dbg_Message)
2010/05/21 16:04:06 project_foo_helpers.cpp:970 - dbg_Message 13: HIGH (dbg_Message)
2010/05/21 16:04:06 project_foo_helpers.cpp:971 - dbg_Message 14: ERROR (dbg_Message)
2010/05/21 16:04:06 project_foo_helpers.cpp:972 - dbg_Message 15: FATAL (dbg_Message)
2010/05/21 16:04:06 project_foo_helpers.cpp:973 - dbg_Message 16: LOW (dbg_Message)
2010/05/21 16:04:06 project_foo_helpers.cpp:974 - dbg_Message 17: MEDIUM (dbg_Message)
2010/05/21 16:04:06 project_foo_helpers.cpp:975 - dbg_Message 18: HIGH (dbg_Message)
2010/05/21 16:04:06 project_foo_helpers.cpp:976 - dbg_Message 19: ERROR (dbg_Message)
2010/05/21 16:04:06 project_foo_helpers.cpp:977 - dbg_Message 20: FATAL (dbg_Message)

Using
+ Project Brew MP Version 1.0.2.320
+ BREW MP Simulator 6.0.19.517
+ Sapphire simulator model
+ running on Windows XP SP3

-J_Tom_Moon_79

Hello jtmoon79,
When I use dbg_Message() and running the program on simulator, access violation to address 0x00000000 happens.
How to use dbg_Message()?
My program is statically linked with a1_imp.lib
What initialization procedure I have to do before calling dbg_Message() ?

Hello jtmoon79,
When I use dbg_Message() and running the program on simulator, access violation to address 0x00000000 happens.
How to use dbg_Message()?
My program is statically linked with a1_imp.lib
What initialization procedure I have to do before calling dbg_Message() ?

Quote:access violation to address 0x00000000
Your code is passing a pointer with value NULL (value 0x0000000) to dbg_Message().
-J_Tom_Moon_79

Quote:access violation to address 0x00000000
Your code is passing a pointer with value NULL (value 0x0000000) to dbg_Message().
-J_Tom_Moon_79

Hello jtmoon79,
I use dbg_Message() with valid arguments, like following:
dbg_Message("hello", 1, __FILE__, __LINE__);
Below is assembly code running on Simulator:
0B791DD3 push 1F5h
0B791DD8 push offset ___xt_z+1C8h (0B7EAC0Ch)
0B791DDD push 1
0B791DDF push offset ___xt_z+1D8h (0B7EAC1Ch)
0B791DE4 call dbg_Message (0B7D5C20h)
0B791DE9 add esp,10h
Code is linked with a1_imp.lib in C:\Program Files\Qualcomm\Brew MP SDK\Platforms\1.0.2.267\platform\system\lib\Win32_Debug
Below is assembly code implementation of dbg_Message:
--- d:\p4c\rel1.5.0_apione_reference_builds\apione\src\a1_imp\a1_imp.c ---------
0B7D5C20 push ebp
0B7D5C21 mov ebp,esp
0B7D5C23 push esi
0B7D5C24 mov esi,esp
0B7D5C26 mov eax,dword ptr [nLine]
0B7D5C29 push eax
0B7D5C2A mov ecx,dword ptr [lpszFileName]
0B7D5C2D push ecx
0B7D5C2E mov edx,dword ptr [nLevel]
0B7D5C31 push edx
0B7D5C32 mov eax,dword ptr [lpszMessage]
0B7D5C35 push eax
0B7D5C36 call dword ptr [_dbg_dbg_Message (0B7FD4B8h)]
0B7D5C3C add esp,10h
While _dbg_dbg_Message is referenced, memory access violation to null pointer error happens.

Hello jtmoon79,
I use dbg_Message() with valid arguments, like following:
dbg_Message("hello", 1, __FILE__, __LINE__);
Below is assembly code running on Simulator:
0B791DD3 push 1F5h
0B791DD8 push offset ___xt_z+1C8h (0B7EAC0Ch)
0B791DDD push 1
0B791DDF push offset ___xt_z+1D8h (0B7EAC1Ch)
0B791DE4 call dbg_Message (0B7D5C20h)
0B791DE9 add esp,10h
Code is linked with a1_imp.lib in C:\Program Files\Qualcomm\Brew MP SDK\Platforms\1.0.2.267\platform\system\lib\Win32_Debug
Below is assembly code implementation of dbg_Message:
--- d:\p4c\rel1.5.0_apione_reference_builds\apione\src\a1_imp\a1_imp.c ---------
0B7D5C20 push ebp
0B7D5C21 mov ebp,esp
0B7D5C23 push esi
0B7D5C24 mov esi,esp
0B7D5C26 mov eax,dword ptr [nLine]
0B7D5C29 push eax
0B7D5C2A mov ecx,dword ptr [lpszFileName]
0B7D5C2D push ecx
0B7D5C2E mov edx,dword ptr [nLevel]
0B7D5C31 push edx
0B7D5C32 mov eax,dword ptr [lpszMessage]
0B7D5C35 push eax
0B7D5C36 call dword ptr [_dbg_dbg_Message (0B7FD4B8h)]
0B7D5C3C add esp,10h
While _dbg_dbg_Message is referenced, memory access violation to null pointer error happens.

Miku Liu,
Would you please start your question in a new thread? Your topic distracts from the original topic.
Private Message me if you would like me to respond to the new thread.
-J_Tom_Moon_79

Miku Liu,
Would you please start your question in a new thread? Your topic distracts from the original topic.
Private Message me if you would like me to respond to the new thread.
-J_Tom_Moon_79

Do you see the same behavior with DBGPRINTF ?
What about if you set synchronous mode on for dbgprintf using BREWDEBUG?
Also curious to know if this still happens if all priority paramters are set to the same priority
e.g. DBG_MSG_LEVEL_HIGH.

Do you see the same behavior with DBGPRINTF ?
What about if you set synchronous mode on for dbgprintf using BREWDEBUG?
Also curious to know if this still happens if all priority paramters are set to the same priority
e.g. DBG_MSG_LEVEL_HIGH.

jmiller2, thanks for the good questions.
This bug does not affect my current project. This bug is a low priority for me. So I'm not spending any more time investigating this bug.
I was hoping a BREWMP engineer might post the exact answer (is this is a bug or is it by design?).
Here's my best answers to your questions.
Quote:Do you see the same behavior with DBGPRINTF ?I have not tried.
Quote:What about if you set synchronous mode on for dbgprintf using BREWDEBUG?How is this done? I could did not find information about this mode (after one minute of searching).
Quote:if this still happens if all priority paramters are set to the same priority e.g. DBG_MSG_LEVEL_HIGH. The output is in the correct order. No out of order output.
-J_Tom_Moon_79

jmiller2, thanks for the good questions.
This bug does not affect my current project. This bug is a low priority for me. So I'm not spending any more time investigating this bug.
I was hoping a BREWMP engineer might post the exact answer (is this is a bug or is it by design?).
Here's my best answers to your questions.
Quote:Do you see the same behavior with DBGPRINTF ?I have not tried.
Quote:What about if you set synchronous mode on for dbgprintf using BREWDEBUG?How is this done? I could did not find information about this mode (after one minute of searching).
Quote:if this still happens if all priority paramters are set to the same priority e.g. DBG_MSG_LEVEL_HIGH. The output is in the correct order. No out of order output.
-J_Tom_Moon_79