# DS 1.2.0 & 2.0.0 TRACE limitation

**URL:** <https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049>\
**Category:** Development tools\
**Created:** [May 9, 2011, 11:14pm UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049 "2011-05-09T23:14:43Z")\
**Posts on this page:** 19\
**Page:** 1

<div class="post-metadata">

**Author:** ![awneil](https://avatars.discourse-cdn.com/v4/letter/a/49beb7/32.png) [@awneil](https://forum.sierrawireless.com/u/awneil)\
**Post date:** [May 9, 2011, 11:14pm UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/1 "2011-05-09T23:14:43Z")

</div>

> [@TMT](#):
>
> 69.532 Trace ADL 6 RTC Time: 2010/10/06 17:30:47 = UTC seconds: 1095106560

For the same code,

> [@DS 1.2.0](#):
>
> 2011/05/09,19:22:19.078 - 007;ADL;6; RTC Time: %04d-%02d-%02d %02d:%02d:%02d = UTC seconds: %d

ie, DS 1.2.0 has failed to expand the format fields.

It seems that DS 1.2.0 has a limit to the number of fields that it will expand in a TRACE - beyond that limit, no fields will be expanded.

The limit seems to be about 6?

---

<div class="post-metadata">

**Author:** ![awneil](https://avatars.discourse-cdn.com/v4/letter/a/49beb7/32.png) [@awneil](https://forum.sierrawireless.com/u/awneil)\
**Post date:** [May 10, 2011, 12:08am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/2 "2011-05-10T00:08:38Z")

</div>

DS 2.0.0 is the same.

---

<div class="post-metadata">

**Author:** ![awneil](https://avatars.discourse-cdn.com/v4/letter/a/49beb7/32.png) [@awneil](https://forum.sierrawireless.com/u/awneil)\
**Post date:** [May 10, 2011, 6:30am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/3 "2011-05-10T06:30:54Z")

</div>

A workaround, of course, is to sprintf to a buffer first, and then TRACE the buffer; ie,

instead of this:

```auto
TRACE(( TRACE_LEVEL, " RTC Time: %04d/%02d/%02d %02d:%02d:%02d = UTC seconds: %d",
        rtcTimeStruct.Year, rtcTimeStruct.Month, rtcTimeStruct.Day, 
        rtcTimeStruct.Hour, rtcTimeStruct.Minute, rtcTimeStruct.Second, 
        rtcTimeStamp.TimeStamp ));
```

do this:

```auto
sprintf( buffer, " RTC Time: %04d/%02d/%02d %02d:%02d:%02d = UTC seconds: %d",
         rtcTimeStruct.Year, rtcTimeStruct.Month, rtcTimeStruct.Day, 
         rtcTimeStruct.Hour, rtcTimeStruct.Minute, rtcTimeStruct.Second, 
         rtcTimeStamp.TimeStamp );
TRACE(( TRACE_LEVEL, buffer ));
```

But what is the implication for TRACE performance?

---

<div class="post-metadata">

**Author:** ![daav](https://sea1.discourse-cdn.com/flex025/user_avatar/forum.sierrawireless.com/daav/32/2767_2.png) [@daav](https://forum.sierrawireless.com/u/daav)\
**Post date:** [May 10, 2011, 9:22am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/4 "2011-05-10T09:22:44Z")

</div>

We’ll have a look at this and keep you informed.  
Concerning the performance aspect, it’s true that when you use sprintf on the target side, you’ll loose some additional time regarding sole TRACE macro usage.  
Indeed, when using TRACE, the string processing (“sprintf”-like) is done on the PC side. When using DS, the Java String.format() method is used, with the drawback that it is not always a perfect match of what the C sprintf is supposed to do.  
Anyway, it actually depends on how often (how many times per second 😉) you use this kind of trace…

---

<div class="post-metadata">

**Author:** ![awneil](https://avatars.discourse-cdn.com/v4/letter/a/49beb7/32.png) [@awneil](https://forum.sierrawireless.com/u/awneil)\
**Post date:** [May 10, 2011, 10:45am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/5 "2011-05-10T10:45:04Z")

</div>

Do you agree that this is a DS limitation?

I’ve had this “problem” before a while ago, but then I just gave up and did sprintf instead.

Then it happened again yesterday, and I had the idea of trying it in TMT - where it worked!

---

<div class="post-metadata">

**Author:** ![daav](https://sea1.discourse-cdn.com/flex025/user_avatar/forum.sierrawireless.com/daav/32/2767_2.png) [@daav](https://forum.sierrawireless.com/u/daav)\
**Post date:** [May 11, 2011, 6:36am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/6 "2011-05-11T06:36:47Z")

</div>

> [@awneil](#):
>
> Do you agree that this is a DS limitation?  
> I’ve had this “problem” before a while ago, but then I just gave up and did sprintf instead.  
> Then it happened again yesterday, and I had the idea of trying it in TMT - where it worked!

As it’s working in TMT but not in DS, let’s call it a bug 😉  
Can’t imagine any technical reason which should prevent us to fix it.

---

<div class="post-metadata">

**Author:** ![awneil](https://avatars.discourse-cdn.com/v4/letter/a/49beb7/32.png) [@awneil](https://forum.sierrawireless.com/u/awneil)\
**Post date:** [September 13, 2011, 11:59pm UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/7 "2011-09-13T23:59:41Z")

</div>

> [@awneil](#):
>
> The limit seems to be about 6?

DS 2.1.0 seems to be failing to expand even traces with just 2 variables in 😮❗

> [@DS 2.1.0](#):
>
> 2011/09/14;00:42:40:890;001;ADL;1;atDnldFsm NewSt=%u Rslt=%u  
> 2011/09/14;00:42:43:781;001;ADL;1;atDnldFsm S=%u E=%u L=%u

The corresponding source lines are:

```auto
TRACE(( TRCLVL_BASE, "atDnldFsm NewSt=%u Rslt=%u", dnldState, dnldRslt ));
```

and:

```auto
TRACE(( TRCLVL_BASE, "atDnldFsm S=%u E=%u L=%u", dnldState, callEvent, rxDataLen ));
```

---

<div class="post-metadata">

**Author:** ![daav](https://sea1.discourse-cdn.com/flex025/user_avatar/forum.sierrawireless.com/daav/32/2767_2.png) [@daav](https://forum.sierrawireless.com/u/daav)\
**Post date:** [September 14, 2011, 7:30am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/8 "2011-09-14T07:30:58Z")

</div>

Arg, sounds like a regression in 2.1.0…  
We’ve added preferences to handle these cases where it’s needed to pre-replace sprintf formating characters:

 ![](https://us1.discourse-cdn.com/flex025/uploads/sierrawireless/original/2X/6/694b3abe46f54e861d72c6f423bb773e6d3c8d6f.PNG)  
  
But it seems that it doesn’t work…  
We’re taking a look and probably will publish a patch here ASAP.

---

<div class="post-metadata">

**Author:** ![awneil](https://avatars.discourse-cdn.com/v4/letter/a/49beb7/32.png) [@awneil](https://forum.sierrawireless.com/u/awneil)\
**Post date:** [September 14, 2011, 8:19am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/9 "2011-09-14T08:19:19Z")

</div>

As a workaround, I changed the code to:

```auto
TRACE(( TRCLVL_BASE, "atDnldFsm NewSt=%d Rslt=%d", dnldState, dnldRslt ));
```

and:

```auto
TRACE(( TRCLVL_BASE, "atDnldFsm S=%d E=%d L=%d", dnldState, callEvent, rxDataLen ));
```

and that now seems to work:

> [@DS 1.2.0](#):
>
> 2011/09/14;09:04:36:718;003;ADL;1;atDnldFsm NewSt=1 Rslt=0  
> 2011/09/14;09:04:39:703;001;ADL;1;atDnldFsm S=1 E=8 L=0

Does the limit of 6 (or whatever) replacement fields still apply?

---

<div class="post-metadata">

**Author:** ![daav](https://sea1.discourse-cdn.com/flex025/user_avatar/forum.sierrawireless.com/daav/32/2767_2.png) [@daav](https://forum.sierrawireless.com/u/daav)\
**Post date:** [September 14, 2011, 12:40pm UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/10 "2011-09-14T12:40:20Z")

</div>

> [@awneil](#):
>
> Does the limit of 6 (or whatever) replacement fields still apply?

The fact that the target can’t send more than 6 arguments in traces is, actually, a target limitation.  
But we’ve fixed the DS behavior in 2.1.0 to at least replace the 6 first arguments in the displayed trace (supplementary replacement fields will be displayed unchanged).

---

<div class="post-metadata">

**Author:** ![daav](https://sea1.discourse-cdn.com/flex025/user_avatar/forum.sierrawireless.com/daav/32/2767_2.png) [@daav](https://forum.sierrawireless.com/u/daav)\
**Post date:** [September 14, 2011, 12:48pm UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/11 "2011-09-14T12:48:28Z")

</div>

Just pushed a patch to fix the replace bug:  
[url][https://forum.sierrawireless.com/t/patch-traces-view-replacement-bug-in-ds-2-1-0/5240/1](https://forum.sierrawireless.com/t/patch-traces-view-replacement-bug-in-ds-2-1-0/5240/1)]

---

<div class="post-metadata">

**Author:** ![awneil](https://avatars.discourse-cdn.com/v4/letter/a/49beb7/32.png) [@awneil](https://forum.sierrawireless.com/u/awneil)\
**Post date:** [September 14, 2011, 2:06pm UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/12 "2011-09-14T14:06:13Z")

</div>

> [@daav](#):
>
> The fact that the target can’t send more than 6 arguments in traces is, actually, a target limitation.

So why could I get more than 6 in TMT (see initial post) ❓

---

<div class="post-metadata">

**Author:** ![daav](https://sea1.discourse-cdn.com/flex025/user_avatar/forum.sierrawireless.com/daav/32/2767_2.png) [@daav](https://forum.sierrawireless.com/u/daav)\
**Post date:** [September 15, 2011, 7:05am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/13 "2011-09-15T07:05:59Z")

</div>

> [@awneil](#):
>
> So why could I get more than 6 in TMT (see initial post) ❓

Mmmm, pretty sure that even in TMT, a trace with more than 6 formatting chars isn’t correctly processed.  
(unless proven otherwise; if you’ve got an evidence, please just tell 😉 )

---

<div class="post-metadata">

**Author:** ![awneil](https://avatars.discourse-cdn.com/v4/letter/a/49beb7/32.png) [@awneil](https://forum.sierrawireless.com/u/awneil)\
**Post date:** [September 15, 2011, 8:41am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/14 "2011-09-15T08:41:29Z")

</div>

> [@daav](#):
>
> if you’ve got an evidence, please just tell 😉 )

See the initial post in this very thread:

> [@I](#):
>
> > [@TMT](#):
> >
> > 69.532 Trace ADL 6 RTC Time: 2010/10/06 17:30:47 = UTC seconds: 1095106560
> 
> For the same code,
> 
> > [@DS 1.2.0](#):
> >
> > 2011/05/09,19:22:19.078 - 007;ADL;6; RTC Time: %04d-%02d-%02d %02d:%02d:%02d = UTC seconds: %d
> 
> ie, DS 1.2.0 has failed to expand the format fields.

That example contained 7 fields!

Note that those examples are from the same executable in the same device - the only difference is whether TMT or DS was used to view the traces.

---

<div class="post-metadata">

**Author:** ![daav](https://sea1.discourse-cdn.com/flex025/user_avatar/forum.sierrawireless.com/daav/32/2767_2.png) [@daav](https://forum.sierrawireless.com/u/daav)\
**Post date:** [September 16, 2011, 6:51am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/15 "2011-09-16T06:51:04Z")

</div>

Please can you elaborate on the used embedded SW versions?  
Done the test with FW 7.46 + OS 6.36, and got the same behavior with TMT & DS: 7th field is not replaced.  
Maybe a regression in recent embedded SW…

---

<div class="post-metadata">

**Author:** ![awneil](https://avatars.discourse-cdn.com/v4/letter/a/49beb7/32.png) [@awneil](https://forum.sierrawireless.com/u/awneil)\
**Post date:** [September 16, 2011, 7:16am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/16 "2011-09-16T07:16:43Z")

</div>

> [@daav](#):
>
> Please can you elaborate on the used embedded SW versions?

Hmmm… digs back to find old Trace file from May:

> [@The Trace File](#):
>
> 2011/05/09,19:15:56.906 - 201;ATI;1;ati9  
> 2011/05/09,19:15:56.921 - 204;ATI;1;“DWL”,“V08b0g”,“”,“Sierra Wireless”,54680,“071609 15:36”,“16bb6f5c”,“00010000”
> 
> 2011/05/09,19:15:56.937 - 206;ATI;1;“FW”,“FW\_SRC\_744\_12.Q2686G”,“R7.44.0.201008311212.FXT001”,“Sierra Wireless”,2146096,“083110 12:12”,“456cf17c”,“00020000”
> 
> 2011/05/09,19:15:56.953 - 208;ATI;1;“OAT”,“0.0.0”,“xxxxxxxxxxxxxxx”,“Antronics Ltd”,1444176,“050911 19:13”,“97635b0a”,“00260000”
> 
> 2011/05/09,19:15:56.968 - 210;ATI;1; -“Developer Studio”,“1.2.0.201012171243-R6026”
> 
> 2011/05/09,19:15:56.968 - 212;ATI;1; -“Open AT Embedded Software Suite package”,“2.33.0.201009161739”
> 
> 2011/05/09,19:15:56.984 - 214;ATI;1; -“Open AT OS Package”,“6.32.0.03”
> 
> 2011/05/09,19:15:57.000 - 001;ATI;1; -“Firmware Package”,“7.43.0.201009151513”
> 
> 2011/05/09,19:15:57.015 - 003;ATI;1; -“C-GPS-OPUS-I Open AT Plug-in Package”,“1.7.0.2010”
> 
> 2011/05/09,19:15:57.031 - 008;ATI;1;  
> OK

> [@daav](#):
>
> Done the test with FW 7.46 + OS 6.36, and got the same behavior with TMT & DS: 7th field is not replaced.

Do you mean that the other six were replaced?

If so, that is certainly a different issue: in my original report it was “all or nothing” - not “first n”

---

<div class="post-metadata">

**Author:** ![daav](https://sea1.discourse-cdn.com/flex025/user_avatar/forum.sierrawireless.com/daav/32/2767_2.png) [@daav](https://forum.sierrawireless.com/u/daav)\
**Post date:** [September 19, 2011, 6:35am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/17 "2011-09-19T06:35:24Z")

</div>

> [@awneil](#):
>
> Do you mean that the other six were replaced?  
> If so, that is certainly a different issue: in my original report it was “all or nothing” - not “first n”

To be clear (with a trace sent from embedded app with 7 replacement fields):

- DS \< 2.1.0: nothing is replaced
- DS 2.1.0: first six are replaced, seventh and more not replaced
- TMT: all is replaced, but seventh and more values are completely random (or at least nothing to do with the real expected values)

Concerning this third point, are you sure that seventh (and more) values were correct with TMT?  
I’ve done the test even with 7.44 FW, and behavior is the same.  
Quite dangerous (can lead to bad interpretation); that’s why in DS we preferred not replacing fields for which we don’t have values coming from the target.

---

<div class="post-metadata">

**Author:** ![awneil](https://avatars.discourse-cdn.com/v4/letter/a/49beb7/32.png) [@awneil](https://forum.sierrawireless.com/u/awneil)\
**Post date:** [September 19, 2011, 11:51am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/18 "2011-09-19T11:51:37Z")

</div>

> [@daav](#):
>
> - DS 2.1.0: first six are replaced, seventh and more not replaced

Excellent 😃

> [@](#):
>
> - TMT: all is replaced, but seventh and more values are completely random (or at least nothing to do with the real expected values)

Stupid 😠

> [@daav](#):
>
> Concerning this third point, are you sure that seventh (and more) values were correct with TMT?

Looking at the example from earlier:

> [@TMT](#):
>
> 69.532 Trace ADL 6 RTC Time: 2010/10/06 17:30:47 = UTC seconds: 1095106560

The “UTC seconds” field there should be the UNIX timestamp for the “RTC Time”  
Putting 1095106560 into [onlineconversion.com/unix\_time.htm](http://www.onlineconversion.com/unix_time.htm) gives:

> [@Online UNIX time converter](#):
>
> Mon, 13 Sep 2004 20:16:00 UTC

So, aparently, the value presented by TMT is wrong!😒

> [@](#):
>
> I’ve done the test even with 7.44 FW, and behavior is the same.

Has it always been this way?  
The limitation was not documented before Open-AT v6.31

> [@](#):
>
> Quite dangerous (can lead to bad interpretation)

Indeed! Especially as it was undocumented in the releases when TMT was current!

> [@](#):
>
> that’s why in DS we preferred not replacing fields for which we don’t have values coming from the target.

Whoever decided to do otherwise deserves a good slapping!

---

<div class="post-metadata">

**Author:** ![daav](https://sea1.discourse-cdn.com/flex025/user_avatar/forum.sierrawireless.com/daav/32/2767_2.png) [@daav](https://forum.sierrawireless.com/u/daav)\
**Post date:** [September 20, 2011, 7:10am UTC](https://forum.sierrawireless.com/t/ds-1-2-0-2-0-0-trace-limitation/5049/19 "2011-09-20T07:10:39Z")

</div>

> [@awneil](#):
>
> Has it always been this way?  
> The limitation was not documented before Open-AT v6.31

AFAIR yes…
