On 20 May 2019, at 00:20, pawel.dunaj@nordicsemi.no wrote:

I think %s capability should be dropped from the logger’s format string processing and a separate API added specifically to log a C string, which makes an immediate copy.

Here I totally agree. I think that formatting of strings is such a well known standard that nobody will read the fine print for a logger to see what magic may lie under its hood. I think we should either assert that %s is never used and use some other format instead (i.e. force people to check the doc at least once when they hit an error) or keep %s for in place rendering and add new format for people who want to go faster.
Another thing is that assert is disabled by default so many people may never notice the problem (especially for error paths).

There's a violation of the "Least Astonishment" principle but it's not with the '%s'. The '%s' traditionally refers to the type of the argument only, it says nothing about memory management. I don't think LOG_ASYNC('%s', ...) or LOG(O_NONBLOCK, '%s', ... ) would surprise anyone.

Confusing memory semantics with format specifiers would break not just user expectations but also tools like this:
https://gcc.gnu.org/onlinedocs/gcc-9.1.0/gcc/Common-Function-Attributes.html#index-format-function-attribute (I found an insane number of bugs with this attribute)
+ other static checkers trying to make C a bit more safe.


BTW the current API is neither "asynchronous" nor "non-blocking" in the usual API meanings.

It's not asynchronous in the usual sense because there's no callback or any other second step to know when the memory can be freed or re-used.

It's not non-blocking because it always succeeds, never asks to retry with EAGAIN/EWOULDBLOCK etc.

It's a "globals-only", "UFO" API like nothing else.

On Fri, May 17, 2019 at 04:24 PM, Boie, Andrew P wrote:

For an operating system that aims to support various functional safety certifications, asynchronous rendering of %s is a terrible idea.

 

It has it's pros and cons. Personally I don't mind it as long as it is well understood and can be turned off.

 

I think %s capability should be dropped from the logger’s format string processing and a separate API added specifically to log a C string, which makes an immediate copy.

 

Here I totally agree. I think that formatting of strings is such a well known standard that nobody will read the fine print for a logger to see what magic may lie under its hood. I think we should either assert that %s is never used and use some other format instead (i.e. force people to check the doc at least once when they hit an error) or keep %s for in place rendering and add new format for people who want to go faster.
Another thing is that assert is disabled by default so many people may never notice the problem (especially for error paths).

 

Hello,

On Fri, 17 May 2019 14:38:14 +0000
"lairdjm" <jamie.mccrae@lairdconnect.com> wrote:

Hi,
I think what confused me is that I was reading about the ‘improved
logging’ from this guide:

Opinions vary on that matter, some people think that the logging was
actually "regressed" and not "improved". Literally, it became so
advanced, smart, and sophisticated, that it goes against what most
people need most of the time. Of course, we'll never know if that's
true unless more people provide feedback, so thanks for posting.

https://foundries.io/insights/2018/08/14/zephyr-logging-part-2/ which
doesn’t mention anything about it, I was changing old code from
printf() to LOG_x() and that’s when the issue arose. Thanks, Jamie

I personally do conversion in that direction (printf -> LOG_x) only
when I'm forced to (like, when submitting code for inclusion to
Zephyr). During development, I always use printk/printf which just
behave as expected.

[]

--
Best Regards,
Paul

Linaro.org | Open source software for ARM SoCs
Follow Linaro: http://www.facebook.com/pages/Linaro
http://twitter.com/#!/linaroorg - http://www.linaro.org/linaro-blog

Hello,

On Fri, 17 May 2019 14:24:41 +0000
"Boie, Andrew P" <andrew.p.boie@intel.com> wrote:

For an operating system that aims to support various functional
safety certifications, asynchronous rendering of %s is a terrible
idea.

Some people think that asynchronous logging, forced on unsuspecting
users, is pretty bad idea and make bets when CONFIG_LOG_IMMEDIATE will
become the default behavior again.

I think %s capability should be dropped from the logger’s format
string processing and a separate API added specifically to log a C
string, which makes an immediate copy.

Andrew

From: devel@lists.zephyrproject.org
[mailto:devel@lists.zephyrproject.org] On Behalf Of
pawel.dunaj@nordicsemi.no Sent: Friday, May 17, 2019 1:16 AM To:
devel@lists.zephyrproject.org Subject: Re: [Zephyr-devel] Logging
with a string via %s

Hi,
To optimize time of log processing message construction is deferred.
For this reason you cannot use arrays that will not live long enough
for logger thread to see them. In other words you can always use
static arrays (like you do when calling `LOG_xyz("%s", "testme")`)
but you must never pass anything from the stack (like in your
example). You can enable `CONFIG_LOG_IMMEDIATE` but this will affect
logging performance and does not actually tells you why the problem
happened in the first place.

If you need to print array declared on stack you must call `
log_strdup()` to duplicate it.

Personally I am against this API and I indicated it will cause bugs
as people do expect `%s` to simply output a string and they also
don't read documentation for something that should just work. But at
least it makes logger faster if you look from the bright side.

Thanks,

--
Best Regards,
Paul

Linaro.org | Open source software for ARM SoCs
Follow Linaro: http://www.facebook.com/pages/Linaro
http://twitter.com/#!/linaroorg - http://www.linaro.org/linaro-blog

On 17 May 2019, at 07:24, Boie, Andrew P <andrew.p.boie@intel.com> wrote:

For an operating system that aims to support various functional safety certifications, asynchronous rendering of %s is a terrible idea.

Such a "sharp tool" should at least not look exactly like the slow but safe version used absolutely everywhere else.

http://www.catb.org/~esr/writings/taouu/html/ch01s03.html#rule-surprise

On the same "least astonishment" principle, I think most developers expect degraded performance when logging.

THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.

Hi,
To optimize time of log processing message construction is deferred. For this reason you cannot use arrays that will not live long enough for logger thread to see them.
In other words you can always use static arrays (like you do when calling `LOG_xyz("%s", "testme")`) but you must never pass anything from the stack (like in your example). You can enable `CONFIG_LOG_IMMEDIATE` but this will affect logging performance and does not actually tells you why the problem happened in the first place.

If you need to print array declared on stack you must call ` log_strdup()` to duplicate it.

Personally I am against this API and I indicated it will cause bugs as people do expect `%s` to simply output a string and they also don't read documentation for something that should just work.
But at least it makes logger faster if you look from the bright side.

Thanks,

Hi,
NRF_GPIO_PIN_MAP will effectively change pin number from 6 to (32+6). This would be ok if you use nrfx but when you use Zephyr GPIO API you should use pin id as is. So you should write to CONFIG_GPIO_P1_DEV_NAME device using pin 6.
I.e. do not use NRF_GPIO_PIN_MAP macro.
Thanks,

Reminder: Zephyr Project: Dev Meeting

When: Thursday, 16 May 2019, 8:00am to 9:00am, (GMT-07:00) America/Los Angeles

Where:https://zoom.us/j/993312203

An RSVP is requested. Click here to RSVP

Organizer: devel@...

Description: Join Zoom Meeting
https://zoom.us/j/993312203

One tap mobile
+16699006833,,993312203# US (San Jose)
+16465588656,,993312203# US (New York)

Dial by your location
        +1 669 900 6833 US (San Jose)
        +1 646 558 8656 US (New York)
        +1 877 369 0926 US Toll-free
        +1 855 880 1246 US Toll-free
Meeting ID: 993 312 203
Find your local number: https://zoom.us/u/ankEMRagf

Hi,

There’s also a log_strdup() API to deal with this issue.

Johan

Hey Lairdjm,

Depending on you logging setup, the log of the string is done inside the "LOG_DBG" command or later.

Later means, that your main function was already left and your local variables are gone = invalid.

Try to add following lines at your proj.conf:

CONFIG_LOG=y
# CONFIG_LOG_PROCESS_THREAD=y
# CONFIG_LOG_INPLACE_PROCESS=y
CONFIG_LOG_IMMEDIATE=y
CONFIG_LOG_BACKEND_SHOW_COLOR=y

This will force the logger "execute" the log function.

Good luck!

Stefan

THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.

THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.

Hi Robert,

On 14 May 2019, at 18.18, robert.konc@controlmatik.eu wrote:

In disconnect callback event I was try to update advertising data but function "bt_le_adv_update_data" return with -11 (error code).
As I understand BLE stack start to advwrise after disconnect automaticly. Is there and event or callback function that indicate this.
I can not use disconnect event because this event is fired befor stack start to advertise.

Any suggestion?

You could try using BT_LE_ADV_OPT_ONE_TIME with bt_le_adv_start(). That should ensure that the stack doesn’t automatically restart advertising after a disconnection event.

Johan

Reminder: Zephyr Project: APIs

When: Tuesday, 14 May 2019, 9:00am to 10:00am, (GMT-07:00) America/Los Angeles

Where:https://zoom.us/j/177647878

An RSVP is requested. Click here to RSVP

Organizer: devel@...

Description: Join from PC, Mac, Linux, iOS or Android: https://zoom.us/j/177647878

Or iPhone one-tap :
    US: +16465588656,,177647878# or +16699006833,,177647878# 
Or Telephone:
    Dial(for higher quality, dial a number based on your current location): 
        US: +1 646 558 8656 or +1 669 900 6833 or +1 855 880 1246 (Toll Free) or +1 877 369 0926 (Toll Free)
    Meeting ID: 177 647 878
    International numbers available: https://zoom.us/zoomconference?m=ioAR9GK1OE5LkN1ojt-heTCl7yPcJrhY

---

 Live meeting minutes: https://docs.google.com/document/d/1lv-8B5QE2m4FjBcvfqAXFIgQfW5oz6306zJ7GIZIWCk/edit?usp=sharing

In disconnect callback event I was try to update advertising data but function "bt_le_adv_update_data" return with -11 (error code).
As I understand BLE stack start to advwrise after disconnect automaticly. Is there and event or callback function that indicate this.
I can not use disconnect event because this event is fired befor stack start to advertise.

Any suggestion?

Best regards