Newlib: inconsistent usage of write() vs _write() in builds for different architectures to dump error messages to console

[pfalcon]

Newlib build included with x86 toolchain calls write() in [TBF], while e.g. arm - _write(). This is inconsistent and causes confusion. x86 way of calling write() also requires it to be defined, but default implementation (without POSIX subsystem enabled) is able to write only to a console. But people don't know that, and call it e.g. on sockets, with output dumped to console. All these problems could be avoided in x86 build also used _write() (the whole idea of underscore-prefixed function is that "it works kind like posix, but doesn't support full posix functionality").

[pfalcon]

This is submitted as offshot of zephyrproject-rtos/zephyr#25443 (comment) . cc @cfriedt .

More information is expected to follow.

[galak]

Can you clarify, when you say the toolchain calls write(), what do you mean? Trying to understand what the function call chain you are seeing on x86 that differs from arm.

[pfalcon]

Not toolchain, but pre-built Newlib static lib as included with the Zephyr SDK toolchains. I'll post steps to reproduce a bit later.

[galak]

Sure, I guess having a backtrace comparison between x86 and arm would be useful to see the difference.

[pfalcon]

Well, I'm not sure about backtrace, the best way to expose an issue is link-time error. So, let's comment definitions of both write() and _write() in https://github.com/zephyrproject-rtos/zephyr/blob/master/lib/libc/newlib/libc-hooks.c#L183 . The diff is in top commit of https://github.com/pfalcon/zephyr/commits/newlib-write-vs-_write (pfalcon/zephyr@65dafeb as of now, may be rebased).

Then let's build samples/net/sockets/big_http_download (choice is arbitrary, it just well exposed issue, based on initial CI failures in zephyrproject-rtos/zephyr#25443).

$ west build -b qemu_x86
...
/mnt/hdd/opt/zephyr-sdk-0.11.2/x86_64-zephyr-elf/bin/../lib/gcc/x86_64-zephyr-elf/9.2.0/../../../../x86_64-zephyr-elf/bin/ld: zephyr/lib/libc/newlib/liblib__libc__newlib.a(libc-hooks.c.obj): in function `_exit':
/home/pfalcon/projects-3rdparty/Embedded/Zephyr/zephyr/lib/libc/newlib/libc-hooks.c:242: undefined reference to `_write'
/mnt/hdd/opt/zephyr-sdk-0.11.2/x86_64-zephyr-elf/bin/../lib/gcc/x86_64-zephyr-elf/9.2.0/../../../../x86_64-zephyr-elf/bin/ld: /home/pfalcon/opt/zephyr-sdk-0.11.2/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/libc.a(lib_a-chk_fail.o): in function `__chk_fail':
chk_fail.c:(.text.__chk_fail+0x73): undefined reference to `write'
/mnt/hdd/opt/zephyr-sdk-0.11.2/x86_64-zephyr-elf/bin/../lib/gcc/x86_64-zephyr-elf/9.2.0/../../../../x86_64-zephyr-elf/bin/ld: /home/pfalcon/opt/zephyr-sdk-0.11.2/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/libc.a(lib_a-writer.o): in function `_write_r':
writer.c:(.text._write_r+0x1d): undefined reference to `write'

So, what we see here is that write() (without underscore) gets called (among Zephyr in-tree cases) from:

• zephyr-sdk-0.11.2/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/libc.a(lib_a-chk_fail.o): in function `__chk_fail'
• zephyr-sdk-0.11.2/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/libc.a(lib_a-writer.o): in function `_write_r'

Which is Newlib prebuilt libc.a as shipped with Zephyr SDK (0.11.2, as can be see).

Let's compare with errors for an Arm board:

$ west build -b frdm_k64f
...
/mnt/hdd/opt/zephyr-sdk-0.11.2/arm-zephyr-eabi/bin/../lib/gcc/arm-zephyr-eabi/9.2.0/../../../../arm-zephyr-eabi/bin/ld: zephyr/lib/libc/newlib/liblib__libc__newlib.a(libc-hooks.c.obj): in function `_exit':
/home/pfalcon/projects-3rdparty/Embedded/Zephyr/zephyr/lib/libc/newlib/libc-hooks.c:242: undefined reference to `_write'
/mnt/hdd/opt/zephyr-sdk-0.11.2/arm-zephyr-eabi/bin/../lib/gcc/arm-zephyr-eabi/9.2.0/../../../../arm-zephyr-eabi/bin/ld: /home/pfalcon/opt/zephyr-sdk-0.11.2/arm-zephyr-eabi/arm-zephyr-eabi/lib/thumb/v7e-m/nofp/libc_nano.a(lib_a-writer.o): in function `_write_r':
writer.c:(.text._write_r+0x10): undefined reference to `_write'

So, we now see that prebuilt Newlib tries to call _write() (with underscore), specifically from:

• zephyr-sdk-0.11.2/arm-zephyr-eabi/arm-zephyr-eabi/lib/thumb/v7e-m/nofp/libc_nano.a(lib_a-writer.o): in function `_write_r'

That pinpoints the issue reported: when built for different architectures, the same module within Newlib (specifically, lib_a-writer.o: _write_r) calls either write or _write, depending on the architecture. Again, this leads to the necessity to define both on Zephyr side, and defining write leads to the user confusion (for the case of CONFIG_POSIX_API=n, which is the default, and the focus of our discussion here).

But looking closer, we see that the situation is even more tangled: for different architectures (or straight, boards), different Newlib variants are used, e.g. for qemu_x86 "full" Newlib is used by default, while for frdm_k64f - "nano".

It's easy to imagine that such a difference in Newlib variants was done as a "feature" and with the best intention, but it ends up just another inconsistency among platforms/boards.

[pfalcon]

Ok, so given that we spotted "full" vs "nano" Newlib discrepancy, let's check whether write vs _write discrepancy is actually caused by it:

--- a/samples/net/sockets/big_http_download/prj.conf
+++ b/samples/net/sockets/big_http_download/prj.conf
@@ -1,5 +1,6 @@
 # General config
 CONFIG_NEWLIB_LIBC=y
+CONFIG_NEWLIB_LIBC_NANO=n

/mnt/hdd/opt/zephyr-sdk-0.11.2/arm-zephyr-eabi/bin/../lib/gcc/arm-zephyr-eabi/9.2.0/../../../../arm-zephyr-eabi/bin/ld: /home/pfalcon/opt/zephyr-sdk-0.11.2/arm-zephyr-eabi/arm-zephyr-eabi/lib/thumb/v7e-m/nofp/libc.a(lib_a-writer.o): in function `_write_r':
writer.c:(.text._write_r+0x1a): undefined reference to `_write'

So, nope, the original hypothesis appear to hold - the discrepancy is per-architecture, not per-Newlib-variant.

[pfalcon]

To elaborate on the choices we have, until we have this fixed, we have to apply pretty ugly workarounds like zephyrproject-rtos/zephyr#25479 (where we effectively say "we can't get it right, so d'oh, it's your problem"). Another alternative is to keep good people like @cfriedt confused (which is the current situation).

[cfriedt]

From the prebuilt toolchain (version 0.11.2):

~/zephyr-sdk-0.11.2/aarch64-zephyr-elf$ nm $(find . -name '*.a') | grep "\( write\| _write\| _write_r\)$" | grep -v
 "_ZN\|_ZZ\|_ZS\|_ZT\|_ZG\|_IT" | grep -v "^  " | grep -v ":" | sort -u
0000000000000000 T write
0000000000000000 T _write
0000000000000000 T _write_r
00000000 T write
00000000 T _write
00000000 T _write_r

~/zephyr-sdk-0.11.2/arc-zephyr-elf$ nm $(find . -name '*.a') | grep "\( write\| _write\| _write_r\)$" | grep -v "_ZN\|_ZZ\|_ZS\|_ZT\|_ZG\|_IT" | grep -v "^  " | grep -v ":" | sort -u
00000000 T write
00000000 T _write
00000000 T _write_r

~/zephyr-sdk-0.11.2/arm-zephyr-elf$  nm $(find . -name '*.a') | grep "\( write\| _write\| _write_r\)$" | grep -v "_ZN\|_ZZ\|_ZS\|_ZT\|_ZG\|_IT" | grep -v "^  " | grep -v ":" | sort -u
00000000 T write
00000000 T _write
00000000 T _write_r
00000000 W _write
00000001 T write
00000001 T _write
00000001 T _write_r
00000001 W _write
000000f5 T _write
000001e8 T _write

~/zephyr-sdk-0.11.2/nios2-zephyr-elf$ nm $(find . -name '*.a') | grep "\( write\| _write\| _write_r\)$" | grep -v "_ZN\|_ZZ\|_ZS\|_ZT\|_ZG\|_IT" | grep -v "^  " | grep -v ":" | sort -u
00000000 T write
00000000 T _write_r

~/zephyr-sdk-0.11.2/riscv64-zephyr-elf$ nm $(find . -name '*.a') | grep "\( write\| _write\| _write_r\)$" | grep -v "_ZN\|_ZZ\|_ZS\|_ZT\|_ZG\|_IT" | grep -v "^  " | grep -v ":" | sort -u
0000000000000000 T write
0000000000000000 T _write
0000000000000000 T _write_r
00000000 T write
00000000 T _write
00000000 T _write_r

~/zephyr-sdk-0.11.2/sparc-zephyr-elf$ nm $(find . -name '*.a') | grep "\( write\| _write\| _write_r\)$" | grep -v "_ZN\|_ZZ\|_ZS\|_ZT\|_ZG\|_IT" | grep -v "^  " | grep -v ":" | sort -u
00000000 T write
00000000 T _write_r

~/zephyr-sdk-0.11.2/x86_64-zephyr-elf$ nm $(find . -name '*.a') | grep "\( write\| _write\| _write_r\)$" | grep -v "_ZN\|_ZZ\|_ZS\|_ZT\|_ZG\|_IT" | grep -v "^  " | grep -v ":" | sort -u
0000000000000000 T write
0000000000000000 T _write_r
00000000 T write
00000000 T _write_r

~/zephyr-sdk-0.11.2/xtensa$ nm $(find . -name '*.a') | grep "\( write\| _write\| _write_r\)$" | grep -v "_ZN\|_ZZ\|_ZS\|_ZT\|_ZG\|_IT" | grep -v "^  " | grep -v ":" | sort -u
00000000 T write

[pfalcon]

@cfriedt: Yep. Maybe if you're on it, you could grep libs for other archs.

[pfalcon]

Maybe if you're on it, you could grep libs for other archs.

@cfriedt, thanks! Mind that when you post a new comment, people involved a ticket get notification (and that's how most follow multitude of their tickets, I guess), but when you edit, they don't. It's certainly not a problem here, thanks for finding time to do that. Just e.g. in PR reviews, it makes sense to post new info as a new comment (or if it makes more sense to edit existing, to post a short notice that previous info was udpated). Thanks.

Anyway, looking at the details above, it's clear that x86 is not the only arch which calls write(). As far as I can tell, it's roughly 50/50 among archs.

Ok, when other tasks permit, I'll have a look at Newlib source to figure out if something can be done about it.

[galak]

@pfalcon can you test builds.zephyrproject.org/zephyrproject-rtos/sdk-ng/223/zephyr-sdk-0.11.3-pr-223-setup.run -- this seems to address the issue.

[pfalcon]

@galak: Will do, thanks!

[cfriedt]

@galak - Hopefully you caught it too, but it seemed to be a similar case for _read, _close and a bunch of other system calls.

[galak]

@galak - Hopefully you caught it too, but it seemed to be a similar case for _read, _close and a bunch of other system calls.

the fix should match behavior for all the syscalls. Try out builds.zephyrproject.org/zephyrproject-rtos/sdk-ng/223/zephyr-sdk-0.11.3-pr-223-setup.run and let me know if that fixes the issue.

[pfalcon]

Ok, to test this, we'd once again need to specify what's the desired, and thus expected, behavior. In my list it's:

1. Internally, Newlib calls only _write().
2. Then, we stop defining write() on our side if CONFIG_POSIX_API=n, and users get link error if they used write() in their app.

And the methodology to test will be:

1. Remove __weak FUNC_ALIAS(_write, write, int); and friends from lib/libc/newlib/libc-hooks.c, and link any non-trivial Newlib app. If it links without errors, we'd theorize that condition 1 above is satisfied.
2. Then take the same (or any other) app, and add call to write() - the link should fail.

[pfalcon]

Sadly, the testing fails even on p.1. Actually, doing black-box testing everything seems to be ok: after removal of all aliases, samples/net/sockets/big_http_download links (it didn't before). But as soon as we peek what's inside, we see:

0011d50b <__chk_fail>:
  11d50b:       55                      push   %ebp
  11d50c:       89 e5                   mov    %esp,%ebp
  11d50e:       83 ec 38                sub    $0x38,%esp
  11d511:       c7 45 ca 2a 2a 2a 20    movl   $0x202a2a2a,-0x36(%ebp)
  11d518:       c7 45 ce 62 75 66 66    movl   $0x66667562,-0x32(%ebp)
  11d51f:       c7 45 d2 65 72 20 6f    movl   $0x6f207265,-0x2e(%ebp)
...
  11d57a:       50                      push   %eax
  11d57b:       6a 02                   push   $0x2
  11d57d:       e8 a8 3c 00 00          call   12122a <write>

So, the usual suspect from the bloatland, __chk_fail, calls write() directly. And look at the message - it's not declared as static const array, so constructed on the stack at runtime. That's awful.

And where that write() comes from, given that we no longer define it? Well:

zephyr-sdk-0.11.3-pr-223/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/libc.a(lib_a-syswrite.o)
                              zephyr-sdk-0.11.3-pr-223/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/libc.a(lib_a-chk_fail.o) (write)

So well, now Newlib defines it itself with a callchain of write() -> _write_r() -> _write().

And of course, if we try to call write() from the app side, it will just dump to stdout.

So, the issue is not resolved.

[galak]

Odd, when I build qemu_x86 I get:

0011d50b <__chk_fail>:
  11d50b:       55                      push   %ebp
  11d50c:       89 e5                   mov    %esp,%ebp
  11d50e:       83 ec 38                sub    $0x38,%esp
...
  11d57d:       e8 d0 83 fe ff          call   105952 <_write>
  11d582:       83 c4 10                add    $0x10,%esp
  11d585:       83 ec 0c                sub    $0xc,%esp
  11d588:       6a 06                   push   $0x6
  11d58a:       e8 1b 3b 00 00          call   1210aa <raise>
  11d58f:       83 c4 10                add    $0x10,%esp
  11d592:       83 ec 0c                sub    $0xc,%esp
  11d595:       6a 7f                   push   $0x7f
  11d597:       e8 ef 83 fe ff          call   10598b <_exit>

[galak]

@pfalcon can you do a shasum on zephyr-sdk-0.11.3-pr-223/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/libc.a

[galak]

@pfalcon can you do a shasum on zephyr-sdk-0.11.3-pr-223/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/libc.a

Nevermind, if I remove the ALIAS I get the same behavior as you

1. Internally, Newlib calls only _write().

Are saying that is how newlib works, or how it should work?

https://sourceware.org/git/?p=newlib-cygwin.git;a=blob;f=newlib/libc/ssp/chk_fail.c;h=b1f8e42a693accf158d584d2fb058a59a4cf6999;hb=HEAD

Has __chk_fail calling write.

So now I'm not sure what behavior you are wanting out of newlib?

[pfalcon]

@galak: So, it's tricky. If I use zephyr-sdk-0.11.3-pr-223 with pristine master d8560f698b5d9aae25ad1ba8ff1ac84e2cc38ab8, I also get

  11d57d:       e8 d0 83 fe ff          call   105952 <_write>

But that's go to be the effect of __weak FUNC_ALIAS(_write, write, int);. The crux would be building with that line removed, and that's when I get call write. The specific patch is pfalcon/zephyr@93f4709

[pfalcon]

I'm ready to look at Newlib source to confirm.

[pfalcon]

Are saying that is how newlib works, or how it should work?

That's we want it to do, to resolve the write() problem for users.

[pfalcon]

https://sourceware.org/git/?p=newlib-cygwin.git;a=blob;f=newlib/libc/ssp/chk_fail.c;h=b1f8e42a693accf158d584d2fb058a59a4cf6999;hb=HEAD

Has __chk_fail calling write.

Then we're hosed and zephyrproject-rtos/zephyr#25479 is the only way.

Well, we can also build our stuff with -U _FORTIFY_SOURCE, because that's where that __chk_fail comes from, at least on Linux. Let me know if you like it. (I'd consider it funny to have it enabled in an embedded project, because projects which want to know what bytes they get in their binaries, disable it even on Linux. But as it's "sekuritee" feature, I just mention that option, don't propose to do it per se.)

[pfalcon]

/home/pfalcon/opt/zephyr-sdk-0.11.3-pr-223/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/libc.a(lib_a-chk_fail.o)
                              /home/pfalcon/opt/zephyr-sdk-0.11.3-pr-223/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/libc.a(lib_a-memcpy_chk.o) (__chk_fail)

Here's where it comes from in big_http_download. Sure, for embedded project, we may assume that developers can call their memcpy() right? (But then to be fair, a usual case for __chk_fail() is something like sprintf(), that's where people love to overflow their buffers, but then we wouldn't use it, would we?)

[pfalcon]

Has __chk_fail calling write.

Comes from: https://sourceware.org/git/?p=newlib-cygwin.git;a=commitdiff;h=3e8fc7d9f21329d5a98ec3cf6de138bce9bc2c05

So, a software developer said "While GCC also provides an implementation in libssp, it is completely broken (CVE-2016-4973, RHBZ#1324759) and seemingly unfixable", and well, made their turn on adding an implementation suitable for embedded libc. Actually wait, the repo is called "newlib-cygwin", so it's Cygwin libc, and nobody advertises embedded-suitability, and if the world uses it as such, that's world's problem ;-). Bottom line: we of course can try to fix the issue in upstream ;-).

[pfalcon]

Well, we can also build our stuff with -U _FORTIFY_SOURCE, because that's where that __chk_fail comes from, at least on Linux.

So, as can be seen from the full patch link posted in the previous comment, here it would be:

+#if __SSP_FORTIFY_LEVEL == 0
+#define __ssp_real_(fun)       fun
+#else

(Though it may be defined depending on _FORTIFY_SOURCE which is kinda "public" interface to that feature (at least AFAIK)).

[pfalcon]

But, obvious eureka: we can define __chk_fail on our side, problem solved. (Maybe).

Will try.

[pfalcon]

But, obvious eureka: we can define __chk_fail on our side, problem solved.

Seems to work, top commit of https://github.com/pfalcon/zephyr/commits/mo-more-write-alias .

So, now I would need to test it with just 0.11.3, and see if there's value in #223 .

[galak]

Seems to work, top commit of https://github.com/pfalcon/zephyr/commits/mo-more-write-alias .

So, now I would need to test it with just 0.11.3, and see if there's value in #223 .

Ok, I think there's still value in #223 as it makes all the newlib's consistent across all the arch's we have in the sdk.

[pfalcon]

Ok, I think there's still value in #223 as it makes all the newlib's consistent across all the arch's we have in the sdk.

Ack. Let me still play with (and ponder about) it, to see whether we could get an ideal behavior of write() not being defined at all by newlib.

[stephanosio]

Ack. Let me still play with (and ponder about) it, to see whether we could get an ideal behavior of write() not being defined at all by newlib.

We should really have a Zephyr fork of newlib (and upstream them once it is mature enough) so that we can address these types of issues:
https://sourcegraph.com/github.com/bminor/newlib@master/-/blob/libgloss/write.c#L25:1&tab=def

This also came up a while back when we were looking into the thread safety and re-entrancy issues.

[pfalcon]

We should really have a Zephyr fork of newlib

If there's someone who's going to maintain it - why not.

This also came up a while back

There were a few ideas, like moving Newlib on the Zephyr source tree side. All such ideas are bound by balance of the actual benefits achieved (vs overheads), practicality, and effort required (and available).

[pfalcon]

Cleaned-up __chk_fail() implementation as produced here was submitted as zephyrproject-rtos/zephyr#26135.