Hi,

(Sorry for the click bait-ish subject)

As per Dirk's suggestion moving the discussion on the pinmux model[1][2] to
the mailing list.

Quoting Dirk:

So I like the idea here to move all the code common to manipulating
the pinmux registers in to a single place.

The way this change goes about that is wrong IMHO. Each board should
have its own driver that uses the library code, not a single driver
that picks up the board specific code at link time. This forces the
user to look in their .config to figure out what board specific code
is included in their image.

Makes sense.

Where the library code lands is an open question ATM. This is very
similar to the QMSI stuff where we will be using a library for
accessing the registers in the IP block.

The only thing that may complicate matters a bit is the point that today
we have two ways of interacting with the pinmux registers, one that is
used by the board specific code and one that may be used by applications
(disabled by default).

Or do you mean we continue providing two pinmux APIs?

We need to figure out the correct long term model. This discussion
should happen on the mailing list instead of gerrit so all involved
can see whats going on.

Cheers,
--
Vinicius

[1] https://gerrit.zephyrproject.org/r/#/c/385

[2] https://gerrit.zephyrproject.org/r/#/c/386

On Mon, 2016-02-22 at 11:27 -0800, Dirk Brandewie wrote:

On 02/22/2016 09:59 AM, Yannis Damigos wrote:

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On 02/22/2016 07:26 PM, Dirk Brandewie wrote:

On 02/22/2016 08:42 AM, Yannis Damigos wrote:

On 02/22/2016 05:10 PM, Dirk Brandewie wrote:

On 02/20/2016 07:50 AM, Yannis Damigos wrote:

Dear all,

Building the philosophers sample fails when the sdk is not
installed under the default path (/opt/zephyr-sdk) in
Archlinux with the following error:
make[1]: Entering directory
'/home/xekarfwtos/projects/zephyr'
make[2]: Entering directory
'/home/xekarfwtos/projects/philosophers/outdir'
     Using /home/xekarfwtos/projects/zephyr as source for
kernel
     GEN     ./Makefile
     CHK     include/generated/version.h
     HOSTCC  scripts/basic/fixdep
     HOSTCC  scripts/gen_idt/version.o
     HOSTCC  scripts/gen_idt/gen_idt.o
     HOSTLD  scripts/gen_idt/gen_idt
     HOSTCC  scripts/gen_offset_header/gen_offset_header.o
     HOSTLD  scripts/gen_offset_header/gen_offset_header
     CHK     misc/generated/configs.c
     UPD     misc/generated/configs.c
i586-poky-elf-gcc: error trying to exec 'cc1': execvp: No
such file or directory
/home/xekarfwtos/projects/zephyr/./Kbuild:98: recipe for
target 'arch/x86/core/offsets/offsets.o' failed
make[3]: *** [arch/x86/core/offsets/offsets.o] Error 1
/home/xekarfwtos/projects/zephyr/Makefile:892: recipe for
target 'prepare' failed
make[2]: *** [prepare] Error 2
make[2]: Leaving directory
'/home/xekarfwtos/projects/philosophers/outdir'
Makefile:169: recipe for target 'sub-make' failed
make[1]: *** [sub-make] Error 2
make[1]: Leaving directory
'/home/xekarfwtos/projects/zephyr'
/home/xekarfwtos/projects/zephyr/Makefile.inc:61: recipe
for target 'all' failed
make: *** [all] Error 2

Is ZEPHYR_SDK_INSTALL_DIR pointing to the SDK install
directory?

When the sdk is installed under the default path compiling
succeeded.

Best regards,
Yannis

Yes, ZEPHYR_SDK_INSTALL_DIR is pointing to the correct SDK
install directory.

Hmmm :-/  Can you send the output of the make command adding V=1
to the
command line?

Here it is https://gist.github.com/xekarfwtos/78d9c85f018ed2a0ce4b

Hmm looks like an SDK issue :-(  I have created a bug for it
https://jira.zephyrproject.org/browse/ZEP-65

I don't have any more useful advice unfortunately.

Yannis can you provide an trace log?

$ strace -fo trace.log make ... [ETC ETC] ...

Thanks,

Hi all,

Here is one proposal on how we can deal with pinmux drivers and board-
specific pinmux configurations:

1. All pinmux drivers land in driver/pinmux/ directory and they all
implement the include/pinmux.h API only.

2. Board-specific code (e.g. board/quark_d2000_crb/board.c) defines
the pinmux table and uses the pinmux APIs to apply its specific
configurations. To achieve that, we could define the board_init()
function in board.c which would handle any board-specific initialization,
including pinmux configuration. We could use SYS_INIT() so board_init()
is executed during kernel initialization.

In order to this approach work, we have to ensure the pinmux driver is
initialized before board_init() is called. This can be achieved by setting
pinmux driver initialization to PRIMARY level and board_init() to SECONDARY
level.

AFAICS, this approach would work for all boards, besides Galileo. Pinmux
in Galileo is quite different and it would require a special handling.

Since Galileo pinmux driver depends on others devices (I2C, PCA9535 and
PCAL9685) we cannot init it on PRIMARY level. So the Galileo board_init()
would be set to SECONDARY level and we use the 'prio' argument from
SYS_INIT() to ensure board_init() is executed after galileo pinmux
initialization.

Regards,

Andre

Quoting Vinicius Costa Gomes (2016-02-23 15:18:25)

On 02/23/2016 09:07 PM, Perez-Gonzalez, Inaky wrote:

On Mon, 2016-02-22 at 11:27 -0800, Dirk Brandewie wrote:

On 02/22/2016 09:59 AM, Yannis Damigos wrote:

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On 02/22/2016 07:26 PM, Dirk Brandewie wrote:

On 02/22/2016 08:42 AM, Yannis Damigos wrote:

On 02/22/2016 05:10 PM, Dirk Brandewie wrote:

On 02/20/2016 07:50 AM, Yannis Damigos wrote:

Dear all,

Building the philosophers sample fails when the sdk is not
installed under the default path (/opt/zephyr-sdk) in
Archlinux with the following error:
make[1]: Entering directory
'/home/xekarfwtos/projects/zephyr'
make[2]: Entering directory
'/home/xekarfwtos/projects/philosophers/outdir'
Using /home/xekarfwtos/projects/zephyr as source for
kernel
GEN ./Makefile
CHK include/generated/version.h
HOSTCC scripts/basic/fixdep
HOSTCC scripts/gen_idt/version.o
HOSTCC scripts/gen_idt/gen_idt.o
HOSTLD scripts/gen_idt/gen_idt
HOSTCC scripts/gen_offset_header/gen_offset_header.o
HOSTLD scripts/gen_offset_header/gen_offset_header
CHK misc/generated/configs.c
UPD misc/generated/configs.c
i586-poky-elf-gcc: error trying to exec 'cc1': execvp: No
such file or directory
/home/xekarfwtos/projects/zephyr/./Kbuild:98: recipe for
target 'arch/x86/core/offsets/offsets.o' failed
make[3]: *** [arch/x86/core/offsets/offsets.o] Error 1
/home/xekarfwtos/projects/zephyr/Makefile:892: recipe for
target 'prepare' failed
make[2]: *** [prepare] Error 2
make[2]: Leaving directory
'/home/xekarfwtos/projects/philosophers/outdir'
Makefile:169: recipe for target 'sub-make' failed
make[1]: *** [sub-make] Error 2
make[1]: Leaving directory
'/home/xekarfwtos/projects/zephyr'
/home/xekarfwtos/projects/zephyr/Makefile.inc:61: recipe
for target 'all' failed
make: *** [all] Error 2

Is ZEPHYR_SDK_INSTALL_DIR pointing to the SDK install
directory?

When the sdk is installed under the default path compiling
succeeded.

Best regards,
Yannis

Yes, ZEPHYR_SDK_INSTALL_DIR is pointing to the correct SDK
install directory.

Hmmm :-/ Can you send the output of the make command adding V=1
to the
command line?

Here it is https://gist.github.com/xekarfwtos/78d9c85f018ed2a0ce4bYou could

Hmm looks like an SDK issue :-( I have created a bug for it
https://jira.zephyrproject.org/browse/ZEP-65

I don't have any more useful advice unfortunately.

Yannis can you provide an trace log?

$ strace -fo trace.log make ... [ETC ETC] ...

Thanks,

You could find the trace log uploaded under the issue ZEP-65 in jira:

https://jira.zephyrproject.org/browse/ZEP-65

Yannis

In the future, when you're making architectural changes like this, send to the mailing list first. Submitting it to gerrit only is NOT advised, and limits the audience which can view the commentary. This highlights the entire reason why we have an RFC process in the first place.

Returning a handler maybe is good for app to invoke other fiber related APIs for operation on same fiber.

But regarding the case described below, I have question can "nano_sem_give" be used instead of requesting fiber_wakeup()? From Zephyr document I learnt both "semaphore wait" and "sleep" blocks the execution of fiber and triggers the scheduler to dequeue another executable fiber.

Thanks,
Sharron

Hi Peter & Ben,

I am seeing couple of issues when trying to wake up a fiber.

1) if my fiber tries to to wake up itself (yes, there was a bug in my
program), there seems to be weird issues (hangs). This could be just
symptoms of 2)

2) after making sure that I am not trying to wake the running fiber, I
am seeing weird issues. After running several rounds of sleeps and
wakes, the OS just hangs when calling fiber_sleep(). I wonder how to
debug this, any suggestions?

Cheers,
Jukka

I managed to get following backtrace when the system is hanging:


_nano_fiber_ready (tcs=tcs(a)entry=0xa800f020 <tx_fiber_stack>)
    at /home/jukka/src/zephyr/kernel/nanokernel/nano_fiber.c:53
53 while (pQ->link && (tcs->prio >= pQ->link->prio)) {
(gdb) bt
#0  _nano_fiber_ready (tcs=tcs(a)entry=0xa800f020 <tx_fiber_stack>)
    at /home/jukka/src/zephyr/kernel/nanokernel/nano_fiber.c:53
#1  0x40033ea9 in _nano_wait_q_remove_no_check (wait_q=<optimized out>)
    at /home/jukka/src/zephyr/kernel/nanokernel/include/wait_q.h:57
#2  _fifo_put_non_preemptible (fifo=<optimized out>, data=0xa8006520
<tx_buffers>)
    at /home/jukka/src/zephyr/kernel/nanokernel/nano_fifo.c:118
#3  0x4003c77b in net_driver_15_4_send (buf=0xa8006520 <tx_buffers>)
    at /home/jukka/src/zephyr/net/ip/net_driver_15_4.c:81
#4  0x400350f3 in net_tcpip_output (buf=0xa8006520 <tx_buffers>,
lladdr=<optimized out>)
    at /home/jukka/src/zephyr/net/ip/net_core.c:801
#5  0x400369e9 in tcpip_ipv6_output (buf=buf(a)entry=0xa8006520
<tx_buffers>)
    at /home/jukka/src/zephyr/net/ip/contiki/ip/tcpip.c:785
#6  0x4003a15f in uip_nd6_rs_output (buf=0xa8006520 <tx_buffers>)
    at /home/jukka/src/zephyr/net/ip/contiki/ipv6/uip-nd6.c:870
#7  0x40038d43 in uip_ds6_send_rs (buf=buf(a)entry=0x0)
    at /home/jukka/src/zephyr/net/ip/contiki/ipv6/uip-ds6.c:708
#8  0x40036b76 in eventhandler (buf=0x0, data=<optimized out>, ev=118
'v')
    at /home/jukka/src/zephyr/net/ip/contiki/ip/tcpip.c:471
#9  process_thread_tcpip_process (process_pt=process_pt(a)entry=0xa80092b
8 <tcpip_process+12>, 
    ev=ev(a)entry=136 '\210', data=0xa800cda0 <uip_ds6_timer_rs>,
buf=0x0)
    at /home/jukka/src/zephyr/net/ip/contiki/ip/tcpip.c:885
#10 0x40036c32 in call_process (p=0xa80092ac <tcpip_process>,
ev=<optimized out>, data=<optimized out>, 
    buf=0x0) at
/home/jukka/src/zephyr/net/ip/contiki/os/sys/process.c:198
#11 0x40036e90 in process_post_synch (p=<optimized out>, ev=<optimized
out>, data=<optimized out>, buf=0x0)
    at /home/jukka/src/zephyr/net/ip/contiki/os/sys/process.c:375
#12 0x400370d7 in process_thread_etimer_process (
    process_pt=process_pt(a)entry=0xa80092c8 <etimer_process+12>, ev=ev(a)e
ntry=130 '\202', 
    data=<optimized out>, buf=0x0) at
/home/jukka/src/zephyr/net/ip/contiki/os/sys/etimer.c:117
#13 0x40036c32 in call_process (p=0xa80092bc <etimer_process>,
ev=<optimized out>, data=<optimized out>, 
    buf=0x0) at
/home/jukka/src/zephyr/net/ip/contiki/os/sys/process.c:198
#14 0x40036e90 in process_post_synch (p=p(a)entry=0xa80092bc
<etimer_process>, ev=ev(a)entry=130 '\202', 
    data=data(a)entry=0x0, buf=0x0) at
/home/jukka/src/zephyr/net/ip/contiki/os/sys/process.c:375
#15 0x400370fb in etimer_request_poll () at
/home/jukka/src/zephyr/net/ip/contiki/os/sys/etimer.c:130
#16 0x40034ac8 in net_timer_fiber () at
/home/jukka/src/zephyr/net/ip/net_core.c:674
#17 0x400340e0 in _thread_entry (pEntry=0x40034a7c <net_timer_fiber>,
parameter1=<optimized out>, 
    parameter2=<optimized out>, parameter3=0x0)

(gdb) p pQ->link
$6 = (struct tcs *) 0xa800e620 <timer_fiber_stack>
(gdb) p tcs->prio
$7 = 7
(gdb) p pQ->link->prio
$8 = 7


Any ideas what is going on?


Cheers,
Jukka


On Wed, 2016-02-24 at 12:03 +0200, Jukka Rissanen wrote:

Hi Peter & Ben,

I am seeing couple of issues when trying to wake up a fiber.

1) if my fiber tries to to wake up itself (yes, there was a bug in my
program), there seems to be weird issues (hangs). This could be just
symptoms of 2)

2) after making sure that I am not trying to wake the running fiber,
I
am seeing weird issues. After running several rounds of sleeps and
wakes, the OS just hangs when calling fiber_sleep(). I wonder how to
debug this, any suggestions?

Cheers,
Jukka


On Mon, 2016-02-22 at 18:07 +0000, Mitsis, Peter wrote:

For what it is worth, I am currently tackling this item.

Peter

-----Original Message-----
From: Jukka Rissanen [mailto:jukka.rissanen(a)linux.intel.com]
Sent: February-22-16 2:01 AM
To: Walsh, Benjamin
Cc: devel(a)lists.zephyrproject.org
Subject: [devel] Re: Re: RFC: make _fiber_start() return a handle
on the
fiber

Hi Ben,

On Fri, 2016-02-19 at 10:36 -0500, Benjamin Walsh wrote:

When we start a fiber via the _fiber_start() API family, we
don't
get back a handle on the created fiber. The fiber
identifier
is
actually the start of the fiber's stack. This hasn't been a
problem until now since no API requires a handle on the
fiber,
except one,
fiber_delayed_start_cancel(): that API is part of a pair,
where
the other API, fiber_delayed_start() starts the fiber and
returns
a handle.

However, Jukka asked me an API could be created that
cancels
a
fiber_sleep() call, something like fiber_wakeup(). The
implementation of such an API is very simple, but it
requires
a
handle on the fiber we want to wake up. This in turn
requires
the
signature of the _fiber_start() family to return a handle
to
the
fiber that gets started.

The signature of _fiber_start() et al. would then change
from
a
void return type to a void * return type.

Objections, comments, etc ?

No comments -> no objects -> perhaps we can continue with
this
route
then?

Looks like it. You want to do the implementation yourself Jukka
?

I am a bit busy right now so I am fine if you do it.


Cheers,
Jukka

---------------------------------------------------------------------
Intel Finland Oy
Registered Address: PL 281, 00181 Helsinki
Business Identity Code: 0357606 - 4
Domiciled in Helsinki

This e-mail and any attachments may contain confidential material for
the sole use of the intended recipient(s). Any review or distribution
by others is strictly prohibited. If you are not the intended
recipient, please contact the sender and delete all copies.

Re-sending this using proper mail address.


I managed to get following backtrace when the system is hanging:


_nano_fiber_ready (tcs=tcs(a)entry=0xa800f020 <tx_fiber_stack>)
    at /home/jukka/src/zephyr/kernel/nanokernel/nano_fiber.c:53
53              while (pQ->link && (tcs->prio >= pQ->link->prio)) {
(gdb) bt
#0  _nano_fiber_ready (tcs=tcs(a)entry=0xa800f020 <tx_fiber_stack>)
    at /home/jukka/src/zephyr/kernel/nanokernel/nano_fiber.c:53
#1  0x40033ea9 in _nano_wait_q_remove_no_check (wait_q=<optimized out>)
    at /home/jukka/src/zephyr/kernel/nanokernel/include/wait_q.h:57
#2  _fifo_put_non_preemptible (fifo=<optimized out>, data=0xa8006520
<tx_buffers>)
    at /home/jukka/src/zephyr/kernel/nanokernel/nano_fifo.c:118
#3  0x4003c77b in net_driver_15_4_send (buf=0xa8006520 <tx_buffers>)
    at /home/jukka/src/zephyr/net/ip/net_driver_15_4.c:81
#4  0x400350f3 in net_tcpip_output (buf=0xa8006520 <tx_buffers>,
lladdr=<optimized out>)
    at /home/jukka/src/zephyr/net/ip/net_core.c:801
#5  0x400369e9 in tcpip_ipv6_output (buf=buf(a)entry=0xa8006520
<tx_buffers>)
    at /home/jukka/src/zephyr/net/ip/contiki/ip/tcpip.c:785
#6  0x4003a15f in uip_nd6_rs_output (buf=0xa8006520 <tx_buffers>)
    at /home/jukka/src/zephyr/net/ip/contiki/ipv6/uip-nd6.c:870
#7  0x40038d43 in uip_ds6_send_rs (buf=buf(a)entry=0x0)
    at /home/jukka/src/zephyr/net/ip/contiki/ipv6/uip-ds6.c:708
#8  0x40036b76 in eventhandler (buf=0x0, data=<optimized out>, ev=118
'v')
    at /home/jukka/src/zephyr/net/ip/contiki/ip/tcpip.c:471
#9  process_thread_tcpip_process (process_pt=process_pt(a)entry=0xa80092b
8 <tcpip_process+12>, 
    ev=ev(a)entry=136 '\210', data=0xa800cda0 <uip_ds6_timer_rs>,
buf=0x0)
    at /home/jukka/src/zephyr/net/ip/contiki/ip/tcpip.c:885
#10 0x40036c32 in call_process (p=0xa80092ac <tcpip_process>,
ev=<optimized out>, data=<optimized out>, 
    buf=0x0) at
/home/jukka/src/zephyr/net/ip/contiki/os/sys/process.c:198
#11 0x40036e90 in process_post_synch (p=<optimized out>, ev=<optimized
out>, data=<optimized out>, buf=0x0)
    at /home/jukka/src/zephyr/net/ip/contiki/os/sys/process.c:375
#12 0x400370d7 in process_thread_etimer_process (
    process_pt=process_pt(a)entry=0xa80092c8 <etimer_process+12>, ev=ev(a)e
ntry=130 '\202', 
    data=<optimized out>, buf=0x0) at
/home/jukka/src/zephyr/net/ip/contiki/os/sys/etimer.c:117
#13 0x40036c32 in call_process (p=0xa80092bc <etimer_process>,
ev=<optimized out>, data=<optimized out>, 
    buf=0x0) at
/home/jukka/src/zephyr/net/ip/contiki/os/sys/process.c:198
#14 0x40036e90 in process_post_synch (p=p(a)entry=0xa80092bc
<etimer_process>, ev=ev(a)entry=130 '\202', 
    data=data(a)entry=0x0, buf=0x0) at
/home/jukka/src/zephyr/net/ip/contiki/os/sys/process.c:375
#15 0x400370fb in etimer_request_poll () at
/home/jukka/src/zephyr/net/ip/contiki/os/sys/etimer.c:130
#16 0x40034ac8 in net_timer_fiber () at
/home/jukka/src/zephyr/net/ip/net_core.c:674
#17 0x400340e0 in _thread_entry (pEntry=0x40034a7c <net_timer_fiber>,
parameter1=<optimized out>, 
    parameter2=<optimized out>, parameter3=0x0)

(gdb) p pQ->link
$6 = (struct tcs *) 0xa800e620 <timer_fiber_stack>
(gdb) p tcs->prio
$7 = 7
(gdb) p pQ->link->prio
$8 = 7


Any ideas what is going on?


Cheers,
Jukka

I think I figured this out:

- I was trying to wake up the same fiber I was running
- I was always calling fiber_fiber_wakeup() instead of proper context
depending version

After fixing these two issues, the fiber wake up seems to work now
fine.

I would suggest that if possible, the wake up code could check that we
are not trying to wake ourselves.


Cheers,
Jukka

Hi,

"Kalowsky, Daniel" <daniel.kalowsky(a)intel.com> writes:

In the future, when you're making architectural changes like this, send to the mailing list first. Submitting it to gerrit only is NOT advised, and limits the audience which can view the commentary. This highlights the entire reason why we have an RFC process in the first place.

Thanks for the well thought answer.

-----Original Message-----
From: Vinicius Costa Gomes [mailto:vinicius.gomes(a)intel.com]
Sent: Tuesday, February 23, 2016 10:18 AM
To: devel(a)lists.zephyrproject.org
Subject: [devel] Pinmux driver model: per board vs. unified

Hi,

(Sorry for the click bait-ish subject)

As per Dirk's suggestion moving the discussion on the pinmux model[1][2] to
the mailing list.

Quoting Dirk:

So I like the idea here to move all the code common to manipulating
the pinmux registers in to a single place.

The way this change goes about that is wrong IMHO. Each board should
have its own driver that uses the library code, not a single driver
that picks up the board specific code at link time. This forces the
user to look in their .config to figure out what board specific code
is included in their image.

Makes sense.

This is a re-tread of something we already tried initially. Placing
everything into a library wasn't a bad idea initially, but we did find
a couple of issues with it. For example, it did not scale out cleanly
to other architectures. On the other hand, in some devices we were
being asked to shave out any extra bytes possible, the overhead of
setting up the function call became a little too much. The footprint
tests on this patch confirm an increase in the ROM footprint by an
average of 312 bytes. Oddly it shows a slight decrease in RAM on the
footprint-max tests only (everything else is an increase), which has
an unknown root cause as of yet to me.

I am worried too about the ROM increase. Fair point.

Second this is slow. Calling the _pinmux_dev_set() which
reads+modifies+writes in a non-atomic fashion for two bits to the
hardware repeatedly instead of making a single 32-bit write introduces
a pretty big increase in execution time. As this driver/function is
essential to the board bring up, you are now negatively impacting boot
time.

The impact is negative, I agree, but I would guess that the impact is
minimal, perhaps even inside the error margin of any measurement (to be
fair, I did not do any experiments).

Third, you do reduce LOC, which is a good thing and something I
applaud. This change is really impacting code that is well tested and
extremely static at this point. I'm extremely hesitant to change code
like this for minimal/"no" benefit. Most of the LOCs removed are tied
to specific boards selection for building, not impacting an everyday
build, which is why I say no benefit.

The patch replaces three copies of well tested code by one copy of well
tested code. Specific boards that I am building for and using everyday
:-) I only changed how the code is called, so I guess the effect this
patch could have on weakening the value of previous tests is minor.

Where the library code lands is an open question ATM. This is very
similar to the QMSI stuff where we will be using a library for
accessing the registers in the IP block.

The only thing that may complicate matters a bit is the point that today we
have two ways of interacting with the pinmux registers, one that is used by
the board specific code and one that may be used by applications (disabled
by default).

I'm not sure I follow the complication here. You can enable the
PINMUX_DEV flag via PRJ for any application that needs to control the
pinmux. We have explicitly disabled this by default for very specific
reasons of not wanting to debug/support unknown variations of the
pinmux (we learned from our mistake really quickly), and wanted end
users to actively know they were moving into potentially "untested
functionality" by changing these values. Since any application change
already requires re-compiling the kernel, I'm not sure I see the
concern with having an application enable this feature if needed.

In cases where applications really need to change the pinmux behavior,
I believe any competent system integrator will be making changes
directly to the pinmux.c file. Changing the default values rather
than making them at application run-time provides a single point of
board configuration. I further believe anyone developing a product
using Zephyr will more than likely be creating their own
boards/product-name which should be a self-contained product.

One thing that I was considering was that the existance of the
PINMUX_DEV configuration option could be questioned, as it felt like
protecting against the developer.

But for the sake of discussion, let's assume we move forward with the
idea of making a library routine for everything. What needs to be
done?

This is the most important point. If the feeling is that I am trying to
fix what's not broken, I can abandon this happily.

1) The name needs to be fixed. As noted in the patch already, calling
this the generic Quark SOC pinmux is wrong and mis-leading. This
doesn't support the X10x0 family, is unclear if it supports the D1000
family (I haven't looked), and is really specific only to the x86 CPU
family/model.

Of course. I am still looking for a good name,
PINMUX_QUARK_MCU_EXCEPT_X1000_AND_D1000 doesn't sound good
enough (from a quick look D1000 seems different).

2) Zephyr is multiple architectures. Changing the code-base
architecture for Intel specific boards only, while ignoring the other
architectures, is reason enough to -2 a patch. Please make sure when
you're making changes like this in the future to reflect the change on
all supported boards. If you're moving one, you're moving all of them
to keep consistency. For example, the arduino_due could potentially
have the pinmux moved into the same directory and be renamed to
atmel_sam3x_pinmux.c (or some variation).

I didn't make those changes because I don't have the boards to test.

3) Investigate how to limit the r+m+w overhead of the calls to
_pinmux_dev_set().

Sure.

4) Verify that the Quark D2000 will continue to work when writing out
mistakenly to registers it does not support, but the Quark SE does.
It is a very subtle but important variation. I suspect that this
won't be an issue, but it is one that has not been tested.

Ok.

--
Vinicius

[1] https://gerrit.zephyrproject.org/r/#/c/385

[2] https://gerrit.zephyrproject.org/r/#/c/386

Cheers,
--
Vinicius

On Wed, Feb 24, 2016 at 03:04:41PM +0200, Jukka Rissanen wrote:

I think I figured this out:

- I was trying to wake up the same fiber I was running
- I was always calling fiber_fiber_wakeup() instead of proper context
depending version

Yeah, that would do it: the task has to yield to the fiber somehow,
since it will never pend (in a nanokernel context).

After fixing these two issues, the fiber wake up seems to work now
fine.

I would suggest that if possible, the wake up code could check that we
are not trying to wake ourselves.

Hmm, I would counter this with the argument that passing the current
fiber context is the same as passing any other invalid value. There are
absolutely no checks being done to see if the handle is a pointer to a
valid fiber.

However, I think there is an issue if the caller tries to a wake up a
fiber that was potentially sleeping but that has waken up, and is not
running yet. In that case, that will corrupt the fiber ready queue since
the fiber will be pointing to itself for the next fiber to run.
If a fiber is not waiting, it should not be added to the ready queue
(since it's already in the ready queue). The interesting thing with this
fix is that it would catch a fiber trying to wake itself up, since it is
not sleeping.

On 02/23/2016 02:06 PM, Andre Guedes wrote:

Hi all,

Here is one proposal on how we can deal with pinmux drivers and board-
specific pinmux configurations:

1. All pinmux drivers land in driver/pinmux/ directory and they all
implement the include/pinmux.h API only.

Don't hate it :-)

Although it occurs to me that the pinmux API is not all that useful
and could be considered harmful.

Setting up the pin configuration on an SOC/platform is an init time
only operation and should be by the integrator of the platform
so there is not a good reason to have public API where application
developers could break the rest of the system.

If someone comes up with use case where they need runtime (after init)
control of the platform pin configuration then they can build the
driver/API they need.

2. Board-specific code (e.g. board/quark_d2000_crb/board.c) defines
the pinmux table and uses the pinmux APIs to apply its specific
configurations.
To achieve that, we could define the board_init()
function in board.c which would handle any board-specific initialization,
including pinmux configuration. We could use SYS_INIT() so board_init()
is executed during kernel initialization.

In order to this approach work, we have to ensure the pinmux driver is
initialized before board_init() is called. This can be achieved by setting
pinmux driver initialization to PRIMARY level and board_init() to SECONDARY
level.

We could do this today but board_init() is really just a driver that is
called at the *right* time but does not expose any API.

We had all the init() functions for all driver defined in board.c back
in the day. board.c became a dumping ground so they were moved to the
driver implementations.

We spent a *lot of time and effort getting all the cruft out of
board.{c,h} we should not start putting it back.

AFAICS, this approach would work for all boards, besides Galileo. Pinmux
in Galileo is quite different and it would require a special handling.

Since Galileo pinmux driver depends on others devices (I2C, PCA9535 and
PCAL9685) we cannot init it on PRIMARY level. So the Galileo board_init()
would be set to SECONDARY level and we use the 'prio' argument from
SYS_INIT() to ensure board_init() is executed after galileo pinmux
initialization.

This is why we have 99 sub-levels in each major level so the integrator
has fine grained control over the order of initialization :-).

After writing this mail, looking at the code again I have a alternate
proposal.

1. move the current pinmux drivers back into drivers with reasonable
names.

2. remove the API support from all the drivers and move it to a
quark_pinmux_dev driver that just provides the API if people really
need runtime control of the pin configuration they can build the
driver.

So all the replicated code moves to a single place where it is needed
and the remaining pimux driver only do init() and are done.

The quark_se_devboard.c pinmux driver code becomes:

**** BEGIN ****
/* pinmux.c - general pinmux operation */

/*
* Copyright (c) 2015 Intel Corporation
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include <nanokernel.h>
#include <device.h>
#include <init.h>
#include <pinmux.h>
#include <sys_io.h>
#include "pinmux/pinmux.h"


#ifndef CONFIG_PINMUX_DEV
#define PRINT(...) {; }
#else
#if defined(CONFIG_PRINTK)
#include <misc/printk.h>
#define PRINT printk
#elif defined(CONFIG_STDOUT_CONSOLE)
#define PRINT printf
#endif /* CONFIG_PRINTK */
#endif /*CONFIG_PINMUX_DEV */

#define MASK_2_BITS 0x3
#define PINMUX_PULLUP_OFFSET 0x00
#define PINMUX_SLEW_OFFSET 0x10
#define PINMUX_INPUT_OFFSET 0x20
#define PINMUX_SELECT_OFFSET 0x30

#define PINMUX_SELECT_REGISTER(base, reg_offset) \
(base + PINMUX_SELECT_OFFSET + (reg_offset << 2))

/*
* A little decyphering of what is going on here:
*
* Each pinmux register rperesents a bank of 16 pins, 2 bits per pin
for a total
* of four possible settings per pin.
*
* The first argument to the macro is name of the uint32_t's that is
being used
* to contain the bit patterns for all the configuration registers.
The pin
* number divided by 16 selects the correct register bank based on the pin
* number.
*
* The pin number % 16 * 2 selects the position within the register
bank for the
* bits controlling the pin.
*
* All but the lower two bits of the config values are masked off to ensure
* that we don't inadvertently affect other pins in the register bank.
*/
#define PIN_CONFIG(A, _pin, _func) \
(A[((_pin) / 16)] |= ((0x3 & (_func)) << (((_pin) % 16) * 2)))

/*
* This is the full pinmap that we have available on the board for
configuration
* including the ball position and the various modes that can be set.
In the
* _pinmux_defaults we do not spend any time setting values that are
using mode
* A as the hardware brings up all devices by default in mode A.
*/

/* pin, ball, mode A, mode B, mode C */
/* 0 F02, gpio_0, ain_0, spi_s_cs */
/* 1 G04, gpio_1, ain_1, spi_s_miso */
/* 2 H05, gpio_2, ain_2, spi_s_sck */
/* 3 J06, gpio_3, ain_3, spi_s_mosi */
/* 4 K06, gpio_4, ain_4, NA */ /* 15.4 GPIO */
/* 5 L06, gpio_5, ain_5, NA */ /* 15.4 GPIO */
/* 6 H04, gpio_6, ain_6, NA */ /* 15.4 GPIO */
/* 7 G03, gpio_7, ain_7, NA */
/* 8 L05, gpio_ss_0, ain_8, uart1_cts */ /* UART debug */
/* 9 M05, gpio_ss_1, ain_9, uart1_rts */ /* UART debug */
/* 10 K05, gpio_ss_2, ain_10 */
/* 11 G01, gpio_ss_3, ain_11 */
/* 12 J04, gpio_ss_4, ain_12 */
/* 13 G02, gpio_ss_5, ain_13 */
/* 14 F01, gpio_ss_6, ain_14 */
/* 15 J05, gpio_ss_7, ain_15 */
/* 16 L04, gpio_ss_8, ain_16, uart1_txd */ /* UART debug */
/* 17 M04, gpio_ss_9, ain_17, uart1_rxd */ /* UART debug */
/* 18 K04, uart0_rx, ain_18, NA */ /* BT UART */
/* 19 B02, uart0_tx, gpio_31, NA */ /* BT UART */
/* 20 C01, i2c0_scl, NA, NA */ /* EEPROM, BT, Light Sensor */
/* 21 C02, i2c0_sda, NA, NA */ /* EEPROM, BT, Light Sensor */
/* 22 D01, i2c1_scl, NA, NA */
/* 23 D02, i2c1_sda, NA, NA */
/* 24 E01, i2c0_ss_sda, NA, NA */
/* 25 E02, i2c0_ss_scl, NA, NA */
/* 26 B03, i2c1_ss_sda, NA, NA */ /* IMU */
/* 27 A03, i2c1_ss_scl, NA, NA */ /* IMU */
/* 28 C03, spi0_ss_miso, NA, NA */ /* IMU */
/* 29 E03, spi0_ss_mosi, NA, NA */ /* IMU */
/* 30 D03, spi0_ss_sck, NA, NA */ /* IMU */
/* 31 D04, spi0_ss_cs0, NA, NA */ /* IMU */
/* 32 C04, spi0_ss_cs1, NA, NA */
/* 33 B04, spi0_ss_cs2, gpio_29, NA */ /* 15.4 GPIO */
/* 34 A04, spi0_ss_cs3, gpio_30, NA */
/* 35 B05, spi1_ss_miso, NA, NA */
/* 36 C05, spi1_ss_mosi, NA, NA */
/* 37 D05, spi1_ss_sck, NA, NA */
/* 38 E05, spi1_ss_cs0, NA, NA */
/* 39 E04, spi1_ss_cs1, NA, NA */
/* 40 A06, spi1_ss_cs2, uart0_cts, NA */ /* BT UART */
/* 41 B06, spi1_ss_cs3, uart0_rts, NA */ /* BT UART */
/* 42 C06, gpio_8, spi1_m_sck, NA */ /* 15.4 SPI */
/* 43 D06, gpio_9, spi1_m_miso, NA */ /* 15.4 SPI */
/* 44 E06, gpio_10, spi1_m_mosi, NA */ /* 15.4 SPI */
/* 45 D07, gpio_11, spi1_m_cs0, NA */ /* 15.4 SPI GPIO CS */
/* 46 C07, gpio_12, spi1_m_cs1, NA */
/* 47 B07, gpio_13, spi1_m_cs2, NA */
/* 48 A07, gpio_14, spi1_m_cs3, NA */
/* 49 B08, gpio_15, i2s_rxd, NA */
/* 50 A08, gpio_16, i2s_rscki, NA */
/* 51 B09, gpio_17, i2s_rws, NA */
/* 52 A09, gpio_18, i2s_tsck, NA */
/* 53 C09, gpio_19, i2s_twsi, NA */
/* 54 D09, gpio_20, i2s_txd, NA */
/* 55 D08, gpio_21, spi0_m_sck, NA */ /* SPI Flash */
/* 56 E07, gpio_22, spi0_m_miso, NA */ /* SPI Flash */
/* 57 E09, gpio_23, spi0_m_mosi, NA */ /* SPI Flash */
/* 58 E08, gpio_24, spi0_m_cs0, NA */ /* SPI Flash */
/* 59 A10, gpio_25, spi0_m_cs1, NA */
/* 60 B10, gpio_26, spi0_m_cs2, NA */
/* 61 C10, gpio_27, spi0_m_cs3, NA */
/* 62 D10, gpio_28, NA, NA */
/* 63 E10, gpio_ss_10, pwm_0, NA */
/* 64 D11, gpio_ss_11, pwm_1, NA */
/* 65 C11, gpio_ss_12, pwm_2, NA */
/* 66 B11, gpio_ss_13, pwm_3, NA */
/* 67 D12, gpio_ss_14, clkout_32khz, NA */
/* 68 C12, gpio_ss_15, clkout_16mhz, NA */

/*
* On the QUARK_SE platform there are a minimum of 69 pins that can be
possibly
* set. This would be a total of 5 registers to store the
configuration as per
* the bit description from above
*/
#define PINMUX_MAX_REGISTERS 5
static void _pinmux_defaults(uint32_t base)
{
uint32_t mux_config[PINMUX_MAX_REGISTERS] = { 0, 0, 0, 0, 0};
int i = 0;

PIN_CONFIG(mux_config, 0, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 1, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 2, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 3, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 8, PINMUX_FUNC_C);
PIN_CONFIG(mux_config, 9, PINMUX_FUNC_C);
PIN_CONFIG(mux_config, 16, PINMUX_FUNC_C);
PIN_CONFIG(mux_config, 17, PINMUX_FUNC_C);
PIN_CONFIG(mux_config, 33, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 40, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 41, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 42, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 43, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 44, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 55, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 56, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 57, PINMUX_FUNC_B);
PIN_CONFIG(mux_config, 58, PINMUX_FUNC_B);

for (i = 0; i < PINMUX_MAX_REGISTERS; i++) {
PRINT("PINMUX: configuring register i=%d reg=%x", i,
mux_config[i]);
sys_write32(mux_config[i], PINMUX_SELECT_REGISTER(base, i));
}
}

static inline void _pinmux_pullups(uint32_t base_address) { };

int pinmux_initialize(struct device *port)
{
const struct pinmux_config *pmux = port->config->config_info;

_pinmux_defaults(pmux->base_address);
_pinmux_pullups(pmux->base_address);

return DEV_OK;
}

struct pinmux_config board_pmux = {
.base_address = CONFIG_PINMUX_BASE,
};

DEVICE_INIT(pmux, PINMUX_NAME, &pinmux_initialize,
NULL, &board_pmux,
SECONDARY, CONFIG_KERNEL_INIT_PRIORITY_DEFAULT);

**** END ****

No code duplication, pinumx API only when you ask for it and the drivers
are back in the driver tree :-)

I think this satisfies the goals of the patch set and moves the pinmux
driver to not be a special case any more being off in the boards
directory

--Dirk

Regards,

Andre

Quoting Vinicius Costa Gomes (2016-02-23 15:18:25)

So I like the idea here to move all the code common to manipulating
the pinmux registers in to a single place.

The way this change goes about that is wrong IMHO. Each board should
have its own driver that uses the library code, not a single driver
that picks up the board specific code at link time. This forces the
user to look in their .config to figure out what board specific code
is included in their image.

Makes sense.

Where the library code lands is an open question ATM. This is very
similar to the QMSI stuff where we will be using a library for
accessing the registers in the IP block.

The only thing that may complicate matters a bit is the point that today
we have two ways of interacting with the pinmux registers, one that is
used by the board specific code and one that may be used by applications
(disabled by default).

Or do you mean we continue providing two pinmux APIs?

We need to figure out the correct long term model. This discussion
should happen on the mailing list instead of gerrit so all involved
can see whats going on.

Cheers,
--
Vinicius

[1] https://gerrit.zephyrproject.org/r/#/c/385

[2] https://gerrit.zephyrproject.org/r/#/c/386

On Mon, 2016-02-22 at 07:39 -0800, Dirk Brandewie wrote:

On 02/19/2016 05:31 PM, Thomas, Ramesh wrote:

On Fri, 2016-02-19 at 10:05 -0800, Daniel Leung wrote:

On Fri, Feb 19, 2016 at 08:31:48AM -0800, Dirk Brandewie wrote:

On 02/18/2016 03:04 PM, Daniel Leung wrote:

On Thu, Feb 18, 2016 at 05:54:56PM -0500, Benjamin Walsh wrote:

My take on it is that for Zephyr a failed device initialization
should be considered a fatal event. My expectation is that the
Zephyr user will only be enabling relevant (and important) devices to
their project. If one of these devices should fail, then that is a
serious system error and _NanoFatalErrorHandler() should be invoked.

If this train of thought holds up to scrutiny, and if the aim is to
save a few bytes then I would think that it would be better to have
the device initialization routines return a failure code and have
_sys_device_do_config_level() check for it and invoke the fatal error
handler upon the detection of failure. Otherwise we duplicate the
overhead of calling the fatal error handler in each device
initialization routine.

Sorry for the slow response. I agree with Peter here I think we should
be checking the return value and doing something useful with the
result. Maybe not _NanoFatalErrorHandler() but something notifying
the application that something bad happened. A given device not
initializing may not be fatal to the the whole application, just one
feature is currently unavailable.

For the kind of systems we are targeting, do we really expect the
application to handle devices not initializing correctly, being designed
so that parts are disabled if some parts of the initialization fail
(devices or others), or do we expect applications to require everything
to be present for them to function correctly ? I would have thought the
latter, but I can be convinced.

Delving into the realm of the hypothetical :-)

What about devices that have drivers in the system but are not present
(pluggable) or can't initialize because some resource external to the
device can't be contacted (network server).

The application may be able to still do useful work albeit with reduced
functionality.

Then, if the latter, do we expect the application catching the errors at
runtime when deployed or during development (basically catching software
errors mostly) not malfunctionning hardware. Here, I was thinking the
latter as well, which is why I was proposing __ASSERT() calls catching
initialization errors in debug loads only. And this fits with one of the
core values of the OS, which is small footprint.

Both models are useful for different reasons :-D

Any of those could be a valid approach I think, but we have to decide on
one. And right now, we have the worst since we return those error codes
which are meant for runtime handling, but they just go into the void.

Agreed we need to pick and stay with it for some amount of time until
we see a few real uses/applications/platforms.

OK, following your proposal below, what we could put in place is
standardizing on error codes that init routines must return if they want
the kernel init system to automatically trigger a fatal error.

Then, we could also allow configuring out the error handling if someone
needs to squeeze that last amount of space. One more Kconfig option! :)
The error handling would be enabled by default of course.

For those non-fatal errors, what should we do for runtime driver behaviors?
Should the drivers themselves fail API calls? Or should we let
device_get_binding() return NULL?

How about something like this:

diff --git a/kernel/nanokernel/device.c b/kernel/nanokernel/device.c
index f86f95f..82774c4 100644
--- a/kernel/nanokernel/device.c
+++ b/kernel/nanokernel/device.c
@@ -58,7 +58,7 @@ struct device *device_get_binding(char *name)
struct device *info;

for (info = __device_init_start; info != __device_init_end; info++) {
- if (!strcmp(name, info->config->name)) {
+ if (!strcmp(name, info->config->name) && info->driver_api) {
return info;
}
}

if there is a non-fatal error the driver will not mark itself available
and we can get rid of the null checks in the API headers since the user of the
driver will never get a reference to it if init() did not complete successfully

Why not create a dedicated status field in device object?

It would take more RAM :-) Not sure exactly what you would want to
return in the status? If device init() fails there is nothing the
application code can do about it other that fail gracefully.

I do agree with you that the app cannot do much in failures. But then
kernel need not do even what you propose with failing binding. Let the
app figure out when it tries to use the port. Also drivers can provide
apis for diagnosis if they need e.g. applications that can be remotely
diagnosed and fixed.

Additionally we can provide an API to query status of devices. This
will help query status of devices it does not bind to.

If you are not binding to a device why do you need the status? If
there is a good use case propose the API with the patch ;-)

The API proposal was based on your proposal using get_binding(). Binding
will not work for devices that do not have a name e.g. loapic/ioapic.

But, I guess first we need to see if there is a real need for an error
logging mechanism with kernel involvment :-) It should be noted that
some error logging can be achieved by driver api itself (without kernel
help) if the application needs.

This should work. We need to rework some of the drivers as they make
the driver_api assignment unconditionally.


----------
Daniel Leung

Hi Dirk,

Dirk Brandewie <dirk.j.brandewie(a)intel.com> writes:

[...]

After writing this mail, looking at the code again I have a alternate
proposal.

1. move the current pinmux drivers back into drivers with reasonable
names.

2. remove the API support from all the drivers and move it to a
quark_pinmux_dev driver that just provides the API if people really
need runtime control of the pin configuration they can build the
driver.

So all the replicated code moves to a single place where it is needed
and the remaining pimux driver only do init() and are done.

I like it.

The only thing I am thinking about is polluting the drivers/pinmux/
directory when there are more than a couple of board variants. But this
may not be a problem.

I would only propose to have a different directory for the 'pinmux_dev'
driver. From what I understand, there would be no code shared between
the pinmux "board" driver and the pinmux "dev" driver (the only
information needed seems to be what is already provided by
'include/pinmux.h').

And all concerns that were raised about the increases in ROM size and boot
time overhead seems to be addressed.


Cheers,
--
Vinicius

On Mon, 2016-02-22 at 07:55 -0800, Dirk Brandewie wrote:

On 02/19/2016 05:20 PM, Thomas, Ramesh wrote:

I was considering the possible use case of PM app calling
_sys_device_do_config_level(). In that case a return value of 0 or 1
would help it know some thing went wrong instead of having to query all
devices to find out. But I think this does not impact the main topic of
your RFC and can be addressed separately if necessary.

_sys_device_do_config_level() is *not* a public API and is *not*
guaranteed be stable or even exist from release to release.

AFAIK calling _sys_device_do_config_level() again would not break any of
our current drivers but is the driver is is creating some state in
init() (e.g. security context, network connection) all hell is likely
to break loose. The driver could maintain whether init() has been
called to work around this but at the cost of RAM.

What is the use case? What functionality do you need?

Thanks for pointing out the facts and issues :-) I agree it cannot be
used as a replacement for proper handling of resume() by devices.

--Dirk

Hello, please review this proposal and provide feedback if possible.
This email should be followed by a patch containing a prototype
implementation for reference but not meant to be applied.

Background:
 
Currently several files declare their own logging infrastructure and
sometimes even in the same way, effectively duplicating code, there is
no common logger header or a single interface for logging, this
situation also complicates enhancement of logging functionality.

We want to concentrate logging functionality at a single point to ease
configuration and enhancement while retaining (and reusing) all
existing logging features when decided by developers.

Additional features are proposed anticipating possibly desired
functionality.

Proposal to implement new logging API:

Create a new header file at include directory, remove all logger macro
definition from .c files and have a single, compatible definition on
the new header. On each .c file that requires logging include the new
header and specify feature/file specific values, such as logging domain
(if any) and per-feature logging switch (view number 2.1 below).

The retained features surveyed on existing implementations of logging
are:

1. Make based identification of output appender, these currently being
stdio printf when console is available and printk as fall back.

2. Optional macro expansion, controlled by Kconfig files and make
menuconfig command. Disabling this helps saving memory on production
when logging is not needed.

2.1. Fine grain per-feature log activation. Allows enabling log at
specific parts of the code on menuconfig.

3. Multilevel log formatting.

3.1 Colored log, when console is active it helps differentiate three
existing log levels. currently in use only on Bluetooth files.

4. Caller thread printing, currently Bluetooth files print the current
thread pointer.

5. Caller function printing, some logging macros print the function
that called them.

All above features are kept by this proposal and most become
configurable. The following new ones are added:

6. Labeled log, helps differentiate log levels by using a tag, useful
if color is not available.

7. Incremental per-level log activation. Orthogonal to existing per-
feature filter, this filter allows to set one logging level out of:
INFO, ERROR, WARNING and DEBUG. The higher the level the more verbose
the log becomes. Also as levels are hidden by preprocessor decreasing
level also helps reducing footprint. This is set at menuconfig as well.

Design decisions and rationale:

It was decided to implement this API preferring macros instead of run-
time functions (except for thread retrieval) in an attempt to minimize
overhead introduced by logging.

Also, within this macro implementation, two extreme sides can be
discerned, these are concatenate compile time values with preprocessor
## versus using printf format arguments (%s). Preferring formatting
slightly impacts run-time overhead while preferring preprocessor
concatenation produces longer strings that duplicate substrings. In
this case none of the extremes was reached, instead something closer to
formatting was picked seeking to keep the prototype code simpler. Final
patch can be tuned likewise or one of the two extreme approaches can be
taken.

Implementation details:

The patch following this email is meant as proof-of-concept prototype.
It might compile but has not been thoughtfully tested and it only
covers Bluetooth and lcd_rgb.c files.

In this example path configuration is done through menuconfig, new
options need to be enabled in addition to existing ones, for modified
files CONFIG_BLUETOOTH_CONN, CONFIG_BLUETOOTH_DEBUG,
CONFIG_BLUETOOTH_DEBUG_HCI_CORE and CONFIG_GROVE_DEBUG.

A "logging domain" can be specified, it helps filter a log output in
case several features are enabled, domain is specified by:
LOG_DMN: short for log domain.

Example:
#define LOG_DMN "bt"

The macros at logging.h get enabled by two definitions:
CONFIG_USE_COMPILE_LOG: This is the global Kconfig switch for logging.
LOG_THIS_MODULE: This is an additional switch intended to bridge the
generic definitions on the header to a feature-specific logging switch
from Kconfig.

Example usage of LOG_THIS_MODULE:
#define LOG_THIS_MODULE CONFIG_BLUETOOTH_DEBUG_HCI_CORE
#include <logging.h>

That way logging.h will know that if CONFIG_BLUETOOTH_DEBUG_HCI_CORE
was not set by menuconfig it should not log at all (at current
compilation unit).

This requires an additional line to be included by files that use
logging but could be made optional, doing so requires deciding default
behavior between having unfiltered features (on 2.1 filter mentioned
above) or allowing developer to included logging.h file with no effect.
On current prototype this line requirement is enforced by #error
directive.

Future work:

* Final patch needs to unify system wide the macro naming and such
naming should be less likely to collide.
* An alternative run-time implementation could be later developed to
provide more features.
* Compare footprint between different degrees of ## usage over printf
format.

Example macro expansions:

printf("" "%s%s\t%p: %s" "Grove LCD: background set to white\n" "%s\n",
"DBG ", __func__, sys_thread_self_get(), "", "");
(messages were left unchaged so domain is still repeated as part of the
message)
printf("bt" ":\t" "%s%s\t%p: %s" "Unable to allocate new HCI command"
"%s\n", "", __func__, sys_thread_self_get(), "\x1B[0;31m", "\x1B[0m");
(domain is defined through macro, color and thread are in use)
printf("bt" ":\t" "%s%s\t: %s" "No HCI driver registered" "%s\n", "",
__func__, "\x1B[0;31m", "\x1B[0m");
(same but without thread)

From 9baee79d211bfb94aeed970c55f31cd3c4b2a8ad Mon Sep 17 00:00:00 2001
From: Genaro Saucedo Tejada <genaro.saucedo.tejada(a)intel.com>
Date: Fri, 19 February 2016 23:10:28 +0000
Subject: [PATCH] Log macros unified in a common API

Introduces a header to concentrate logging macro definitions for all
code to
reuse, change aims to provide all currently existing logging
functionality so
every C file can replace it's compile-unit definitions by common code.

Later enhancements to log can now be performed in a single file.

Features:
* Optional printing of thread pointer
* Optional printing of colored messages
* Optional printing of a label to indicate logging level (info, error,
warning, debug)
* Caller function name printing
* Incremental log levels
* One point log disable

Change-Id: Ibe542d69912778703bb43c7afef0889f0591ba6a
Signed-off-by: Genaro Saucedo Tejada <genaro.saucedo.tejada(a)intel.com>
---
 drivers/grove/lcd_rgb.c         |  14 +---
 include/bluetooth/log.h         |  28 +++----
 include/logging.h               | 166
++++++++++++++++++++++++++++++++++++++++
 misc/debug/Kconfig              |  66 ++++++++++++++++
 net/bluetooth/Kconfig           |   3 +-
 net/bluetooth/hci_core.c        |   5 --
 tests/bluetooth/tester/prj.conf |   2 +
 7 files changed, 250 insertions(+), 34 deletions(-)
 create mode 100644 include/logging.h

diff --git a/drivers/grove/lcd_rgb.c b/drivers/grove/lcd_rgb.c
index 58b86c5..7ef6a78 100644
--- a/drivers/grove/lcd_rgb.c
+++ b/drivers/grove/lcd_rgb.c
@@ -29,17 +29,9 @@
 #define GROVE_LCD_DISPLAY_ADDR (0x3E)
 #define GROVE_RGB_BACKLIGHT_ADDR (0x62)
 
-#ifndef CONFIG_GROVE_DEBUG
-#define DBG(...) { ; }
-#else
-#if defined(CONFIG_STDOUT_CONSOLE)
-#include <stdio.h>
-#define DBG printf
-#else
-#include <misc/printk.h>
-#define DBG printk
-#endif /* CONFIG_STDOUT_CONSOLE */
-#endif /* CONFIG_GROVE_DEBUG */
+/* module specific logging check */
+#define LOG_THIS_MODULE CONFIG_GROVE_DEBUG
+#include <logging.h>
 
 struct command {
  uint8_t control;
diff --git a/include/bluetooth/log.h b/include/bluetooth/log.h
index e47453a..e5abbab 100644
--- a/include/bluetooth/log.h
+++ b/include/bluetooth/log.h
@@ -26,25 +26,19 @@
 extern "C" {
 #endif
 
-#if defined(CONFIG_BLUETOOTH_DEBUG_COLOR)
-#define BT_COLOR_OFF     "\x1B[0m"
-#define BT_COLOR_RED     "\x1B[0;31m"
-#define BT_COLOR_YELLOW  "\x1B[0;33m"
-#else
-#define BT_COLOR_OFF     ""
-#define BT_COLOR_RED     ""
-#define BT_COLOR_YELLOW  ""
-#endif
-
 #if defined(CONFIG_BLUETOOTH_DEBUG)
+
+/* module specific logging check */
+#define LOG_THIS_MODULE CONFIG_BLUETOOTH_DEBUG_HCI_CORE
+/* specify logging domain */
+#define LOG_DMN "bt"
+#include <logging.h>
+
 #include <nanokernel.h>
-#define BT_DBG(fmt, ...) printf("bt: %s (%p): " fmt "\n", __func__, \
- sys_thread_self_get(), ##__VA_ARGS__)
-#define BT_ERR(fmt, ...) printf("bt: %s: %s" fmt "%s\n", __func__, \
- BT_COLOR_RED, ##__VA_ARGS__,
BT_COLOR_OFF)
-#define BT_WARN(fmt, ...) printf("bt: %s: %s" fmt "%s\n", __func__, \
-  BT_COLOR_YELLOW, ##__VA_ARGS__,
BT_COLOR_OFF)
-#define BT_INFO(fmt, ...) printf("bt: " fmt "\n", ##__VA_ARGS__)
+#define BT_DBG(fmt, ...) DBG(fmt, ##__VA_ARGS__)
+#define BT_ERR(fmt, ...) ERR(fmt, ##__VA_ARGS__)
+#define BT_WARN(fmt, ...) WRN(fmt, ##__VA_ARGS__)
+#define BT_INFO(fmt, ...) INF(fmt, ##__VA_ARGS__)
 #define BT_ASSERT(cond) if (!(cond)) { \
  BT_ERR("assert: '" #cond "' failed");
\
  }
diff --git a/include/logging.h b/include/logging.h
new file mode 100644
index 0000000..d778da9
--- /dev/null
+++ b/include/logging.h
@@ -0,0 +1,166 @@
+/*
+ * Copyright (c) 2015 Intel Corporation
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or
implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+/** @file logging.h
+ *  @brief Logging macros.
+ */
+#ifndef __LOGGING_H
+#define __LOGGING_H
+
+#if !defined LOG_THIS_MODULE
+#error DO NOT include this header without defining LOG_THIS_MODULE
+#endif
+
+#if defined CONFIG_USE_COMPILE_LOG && (1 == LOG_THIS_MODULE)
+
+#define IS_LOGGING_ACTIVE 1
+#define THREAD_FN_CALL sys_thread_self_get()
+
+/* decide print func */
+#if defined(CONFIG_STDOUT_CONSOLE)
+#include <stdio.h>
+#define LOG_FN printf
+#else
+#include <misc/printk.h>
+#define LOG_FN printk
+#endif /* CONFIG_STDOUT_CONSOLE */
+
+/* Should use color? */
+#if defined(CONFIG_USE_LOG_COLOR)
+#define LOG_COLOR_OFF     "\x1B[0m"
+#define LOG_COLOR_RED     "\x1B[0;31m"
+#define LOG_COLOR_YELLOW  "\x1B[0;33m"
+#else
+#define LOG_COLOR_OFF     ""
+#define LOG_COLOR_RED     ""
+#define LOG_COLOR_YELLOW  ""
+#endif /* CONFIG_BLUETOOTH_DEBUG_COLOR */
+
+/* Should use log lv labels? */
+#if defined(CONFIG_USE_LOG_LV_TAGS)
+#define LOG_LV_ERR "ERR "
+#define LOG_LV_WRN "WRN "
+#define LOG_LV_INF "INF "
+#define LOG_LV_DBG "DBG "
+#else
+#define LOG_LV_ERR ""
+#define LOG_LV_WRN ""
+#define LOG_LV_INF ""
+#define LOG_LV_DBG ""
+#endif /* CONFIG_USE_LOG_LV_TAGS */
+
+/* Log domain name */
+#if defined LOG_DMN
+#define LOG_DMN_TAG LOG_DMN ":\t"
+#else
+#define LOG_DMN_TAG ""
+#endif /* LOG_DMN */
+
+/* Should thread be printed on log? */
+#if defined CONFIG_PRINT_THREAD_LOG
+#define LOG_LAYOUT LOG_DMN_TAG "%s%s\t%p: %s" /* label func thread */
+#define LOG_FN_CALL(log_lv, log_color, log_format, color_off, ...)
\
+ LOG_FN(LOG_LAYOUT log_format "%s\n",
\
+ log_lv, __func__, THREAD_FN_CALL, log_color, ##__VA_ARGS__,
color_off)
+#else
+#define LOG_LAYOUT LOG_DMN_TAG "%s%s\t: %s" /* label func */
+#define LOG_FN_CALL(log_lv, log_color, log_format, color_off, ...)
\
+ LOG_FN(LOG_LAYOUT log_format "%s\n",
\
+ log_lv, __func__, log_color, ##__VA_ARGS__, color_off)
+#endif /* CONFIG_PRINT_THREAD_LOG */
+
+#define LOG_NO_COLOR(log_lv, log_format, ...)
\
+ LOG_FN_CALL(log_lv, "", log_format, "", ##__VA_ARGS__)
+#define LOG_COLOR(log_lv, log_color, log_format, ...)
\
+ LOG_FN_CALL(log_lv, log_color, log_format, LOG_COLOR_OFF,
\
+ ##__VA_ARGS__)
+
+/**
+ * @def INF
+ *
+ * @brief Writes information to log
+ *
+ * @details Lowest logging lv, these messages are not disabled unless
whole
+ * logging gets disabled.
+ *
+ * @param A kprint valid format string and optinally, kprint
formateable
+ * arguments.
+ */
+#define INF(...) LOG_NO_COLOR(LOG_LV_INF, ##__VA_ARGS__)
+
+#if defined(CONFIG_LOG_LV_ERR) || defined(CONFIG_LOG_LV_WRN) \
+ || defined(CONFIG_LOG_LV_DBG)
+/**
+ * @def ERR
+ *
+ * @brief Writes Errors to log
+ *
+ * @details available if CONFIG_USE_COMPILE_LOG is CONFIG_LOG_LV_ERR
or higiher,
+ * it's meant to report fatal errors that can't be recovered from.
+ *
+ * @param A kprint valid format string and optinally, kprint
formateable
+ * arguments.
+ */
+#define ERR(...) LOG_COLOR(LOG_LV_ERR, LOG_COLOR_RED, ##__VA_ARGS__)
+#else
+#define ERR(...) { ; }
+#endif
+
+#if defined(CONFIG_LOG_LV_WRN) || defined(CONFIG_LOG_LV_DBG)
+/**
+ * @def WRN
+ *
+ * @brief Writes warnings to log
+ *
+ * @details available if CONFIG_USE_COMPILE_LOG is CONFIG_LOG_LV_WRN
or higiher,
+ * it's meant to print unexpedted situations that are not necesarily
an error.
+ *
+ * @param A kprint valid format string and optinally, kprint
formateable
+ * arguments.
+ */
+#define WRN(...) LOG_COLOR(LOG_LV_WRN, LOG_COLOR_YELLOW,
##__VA_ARGS__)
+#else
+#define WRN(...) { ; }
+#endif
+
+#if defined(CONFIG_LOG_LV_DBG)
+/**
+ * @def DBG
+ *
+ * @brief Writes debugging information to log
+ *
+ * @details highest logging level, available if CONFIG_USE_COMPILE_LOG
is
+ * CONFIG_LOG_LV_DBG, it's meant to print developer information.
+ *
+ * @param A kprint valid format string and optinally, kprint
formateable
+ * arguments.
+ */
+#define DBG(...) LOG_NO_COLOR(LOG_LV_DBG, ##__VA_ARGS__)
+#else
+#define DBG(...) { ; }
+#endif
+
+#else
+#define IS_LOGGING_ACTIVE 0
+/* create dummy macros */
+#define DBG(...) { ; }
+#define ERR(...) { ; }
+#define WRN(...) { ; }
+#define INF(...) { ; }
+
+#endif /*USE_COMPILE_LOG*/
+
+#endif /* __LOGGING_H */
diff --git a/misc/debug/Kconfig b/misc/debug/Kconfig
index 51a3d3f..716a361 100644
--- a/misc/debug/Kconfig
+++ b/misc/debug/Kconfig
@@ -16,6 +16,72 @@
 # limitations under the License.
 #
 
+config USE_COMPILE_LOG
+ bool
+ prompt "Enable Logging"
+ default n
+ help
+   Global switch for logging.
+
+config USE_LOG_LV_TAGS
+ bool
+ prompt "Prepend level tags to logs"
+ depends on USE_COMPILE_LOG
+ default y
+ help
+   Log lines will beging with one of INF, ERR, WRN or DBG,
depending on the
+   macro used at C code.
+
+config USE_LOG_COLOR
+ bool
+ prompt "Use colored logs"
+ depends on USE_COMPILE_LOG
+ default n
+ help
+   Use color in the logs. This requires an ANSI capable
terminal.
+
+config PRINT_THREAD_LOG
+ bool
+ prompt "Include thread on log messages"
+ depends on USE_COMPILE_LOG
+ default n
+ help
+   Each log line will include the pointer of the thread that
printed it
+
+choice
+depends on USE_COMPILE_LOG
+prompt "Log level"
+
+config LOG_LV_INF
+ bool
+ prompt "Info"
+ help
+   Print just unfiltered logging.
+
+config LOG_LV_ERR
+ bool
+ prompt "Error"
+ help
+   Do not filter printing of ERR logging macro, it is meant to
report fatal
+   errors.
+
+config LOG_LV_WRN
+ bool
+ prompt "Warning"
+ help
+   Do not filter printing of WRN and above logging macros, WRN
marcro is
+   meant to print messages generated under unexpedted
circumstances, not
+   necesarily errors.
+
+config LOG_LV_DBG
+ bool
+ prompt "Debug"
+ help
+   Enable printing of all logging macros, DBG is meant to print
developer
+   information.
+
+endchoice
+
 
 menu "Safe memory access"
 
diff --git a/net/bluetooth/Kconfig b/net/bluetooth/Kconfig
index 8dcbbcf..222199d 100644
--- a/net/bluetooth/Kconfig
+++ b/net/bluetooth/Kconfig
@@ -218,7 +218,8 @@ config BLUETOOTH_DEBUG
    serial console.
 
 if BLUETOOTH_DEBUG
-config  BLUETOOTH_DEBUG_COLOR
+config BLUETOOTH_DEBUG_COLOR
+ select USE_LOG_COLOR
  bool "Use colored logs"
  default y
  help
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index d5b6d24..00ad8d2 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -50,11 +50,6 @@
 #include "smp.h"
 #endif /* CONFIG_BLUETOOTH_SMP */
 
-#if !defined(CONFIG_BLUETOOTH_DEBUG_HCI_CORE)
-#undef BT_DBG
-#define BT_DBG(fmt, ...)
-#endif
-
 /* Stacks for the fibers */
 static BT_STACK_NOINIT(rx_fiber_stack,
CONFIG_BLUETOOTH_RX_STACK_SIZE);
 static BT_STACK_NOINIT(rx_prio_fiber_stack, 256);
diff --git a/tests/bluetooth/tester/prj.conf
b/tests/bluetooth/tester/prj.conf
index 617e07c..af53ace 100644
--- a/tests/bluetooth/tester/prj.conf
+++ b/tests/bluetooth/tester/prj.conf
@@ -1,5 +1,7 @@
 CONFIG_UART_PIPE=y
 CONFIG_CONSOLE_HANDLER=y
+CONFIG_USE_COMPILE_LOG=y
+CONFIG_LOG_LV_DBG=y
 CONFIG_BLUETOOTH=y
 CONFIG_BLUETOOTH_LE=y
 CONFIG_BLUETOOTH_CENTRAL=y
-- 
2.5.0

Hi Genaro,

On Thu, Feb 25, 2016 at 12:13 AM, Saucedo Tejada, Genaro
<genaro.saucedo.tejada(a)intel.com> wrote:

From 9baee79d211bfb94aeed970c55f31cd3c4b2a8ad Mon Sep 17 00:00:00 2001
From: Genaro Saucedo Tejada <genaro.saucedo.tejada(a)intel.com>
Date: Fri, 19 Feb 2016 17:10:28 -0600
Subject: [PATCH] Log macros unified in a common API

Introduces a header to concentrate logging macro definitions for all
code to
reuse, change aims to provide all currently existing logging
functionality so
every C file can replace it's compile-unit definitions by common code.

Later enhancements to log can now be performed in a single file.

Features:
* Optional printing of thread pointer
* Optional printing of colored messages
* Optional printing of a label to indicate logging level (info, error,
warning, debug)
* Caller function name printing
* Incremental log levels
* One point log disable

I welcome these changes but Im not so sure logging levels are actually
necessary if one can define different domains, at least in case of
Bluetooth when you turn on debug for one particular domain you just
get everything, if that is too much perhaps the domain needs to be
split in sub-domains, anyway since your changes was based in Bluetooth
and we did not have levels in the first place I assume it is no needed
right now and can be added later provided someone make a case.