Discussion:
Xoscope nuisance console messages on Pi4 running -current
bob prohaska
2021-05-03 06:37:01 UTC
Permalink
After a successful compile of audio/xoscope on a Pi4 running current a
stream of messages appeared on the console and in the security log
while xoscope was running:


+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045006
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045005
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045002
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045006
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045005
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045002

They seem to come at a fairly high rate and clutter the logfiles, but
apart from that nuisance nothing else seemed visibly amiss.

Are they of any significance?

Thanks for reading,

bob prohaska
Mark Millard via freebsd-arm
2021-05-03 08:00:03 UTC
Permalink
Post by bob prohaska
After a successful compile of audio/xoscope on a Pi4 running current a
stream of messages appeared on the console and in the security log
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045006
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045005
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045002
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045006
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045005
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045002
They seem to come at a fairly high rate and clutter the logfiles, but
apart from that nuisance nothing else seemed visibly amiss.
Are they of any significance?
The code from a mid 2021-Mar vintage of main [so: 14]
looks like:

/* ARGSUSED */
int
sys_ioctl(struct thread *td, struct ioctl_args *uap)
{
u_char smalldata[SYS_IOCTL_SMALL_SIZE] __aligned(SYS_IOCTL_SMALL_ALIGN);
uint32_t com;
int arg, error;
u_int size;
caddr_t data;

#ifdef INVARIANTS
if (uap->com > 0xffffffff) {
printf(
"WARNING pid %d (%s): ioctl sign-extension ioctl %lx\n",
td->td_proc->p_pid, td->td_name, uap->com);
}
#endif
com = (uint32_t)uap->com;
. . .

where sys/sys/sysproto.h shows:

struct ioctl_args {
char fd_l_[PADL_(int)]; int fd; char fd_r_[PADR_(int)];
char com_l_[PADL_(u_long)]; u_long com; char com_r_[PADR_(u_long)];
char data_l_[PADL_(char *)]; char * data; char data_r_[PADR_(char *)];
};

So, uap->com is unsigned with 64 bits for aarch64 and the
0xffffffff is converted to match that for the > test (C
rules).

The assignment to uint32_t com would end up with a
truncated value recorded whenever the warning is
produced.

Thus a value like 0xffffffffc0045006ul ends up with
com == 0xc0045006u instead.

Then looking at the usage of com leads to sys/sys/ioccom.h :

. . .
/*
* Ioctl's have the command encoded in the lower word, and the size of
* any in or out parameters in the upper word. The high 3 bits of the
* upper word are used to encode the in/out status of the parameter.
*
* 31 29 28 16 15 8 7 0
* +---------------------------------------------------------------+
* | I/O | Parameter Length | Command Group | Command |
* +---------------------------------------------------------------+
*/
#define IOCPARM_SHIFT 13 /* number of bits for ioctl size */
#define IOCPARM_MASK ((1 << IOCPARM_SHIFT) - 1) /* parameter length mask */
#define IOCPARM_LEN(x) (((x) >> 16) & IOCPARM_MASK)
#define IOCBASECMD(x) ((x) & ~(IOCPARM_MASK << 16))
#define IOCGROUP(x) (((x) >> 8) & 0xff)

#define IOCPARM_MAX (1 << IOCPARM_SHIFT) /* max size of ioctl */

#define IOC_VOID 0x20000000UL /* no parameters */
#define IOC_OUT 0x40000000UL /* copy out parameters */
#define IOC_IN 0x80000000UL /* copy in parameters */
#define IOC_INOUT (IOC_IN|IOC_OUT)/* copy parameters in and out */
#define IOC_DIRMASK (IOC_VOID|IOC_OUT|IOC_IN)/* mask for IN/OUT/VOID */
. . .

So, com == 0xc0045006u ends up with:

I/O matching: : IOC_IN | IOC_OUT
Command matching (byte): 0x06u
Command Group matching (byte): 0x50u
Parameter Length matching : 0x0004u

While I do not know the specifics for the command
and command group encoding, the truncated value
seems coherent with the code that is using it.

My guess would be xoscope used a signed 32-bit type
that got a value with sign extension to 64 bits
before the value started being treated as unsigned.
If it had used an unsigned type instead, the padding
would have been a zero fill instead (presuming that
I've guessed right).

===
Mark Millard
marklmi at yahoo.com
( dsl-only.net went
away in early 2018-Mar)
bob prohaska
2021-05-03 15:23:39 UTC
Permalink
On Mon, May 03, 2021 at 01:00:03AM -0700, Mark Millard via freebsd-ports wrote:
[detailed code tour omitted]
Post by Mark Millard via freebsd-arm
My guess would be xoscope used a signed 32-bit type
that got a value with sign extension to 64 bits
before the value started being treated as unsigned.
If it had used an unsigned type instead, the padding
would have been a zero fill instead (presuming that
I've guessed right).
So this was an artifact of compiling a 32 program on a 64 bit machine?
And, perhaps unnecessary use of signed versus unsigned integers?

This begs two more questions: It is harmless (seemingly not always),
and would it go away if compiled and run on a 32 bit machine, say armv7?

Many thanks for the detailed explanation, but I'll admit not understanding
much more than the quoted part above 8-(

bob prohaska
Mark Millard via freebsd-arm
2021-05-03 18:08:45 UTC
Permalink
Post by bob prohaska
[detailed code tour omitted]
Post by Mark Millard via freebsd-arm
My guess would be xoscope used a signed 32-bit type
that got a value with sign extension to 64 bits
before the value started being treated as unsigned.
If it had used an unsigned type instead, the padding
would have been a zero fill instead (presuming that
I've guessed right).
So this was an artifact of compiling a 32 program on a 64 bit machine?
I've no evidence that you were building the port for armv7
instead of aarch64. If you were, it would be good to report
that.

Otherwise, I expect the code produced was 64-bit (aarch64)
and the rest is just how the program's source code is set
up.
Post by bob prohaska
And, perhaps unnecessary use of signed versus unsigned integers?
That is what I expect is going on in the xoscope source code.
(I've not looked.)
Post by bob prohaska
This begs two more questions: It is harmless (seemingly not always),
I doubt that it is a problem (other than the messages). As I
wrote:

QUOTE
While I do not know the specifics for the command
and command group encoding, the truncated value
seems coherent with the code that is using it.
END QUOTE
Post by bob prohaska
and would it go away if compiled and run on a 32 bit machine, say armv7?
"long int" and "int" are both 32-bits on armv7 (unsigned
or signed) so no extra 1-bits would be produced by sign
extension.

So I do not expect the messages would be generated when
executed via armv7 code.

As far as I can tell, the program likely works (ignoring
the messages) for aarch64. The messages are from the
FreeBSD you are using being a debug build with INVARIANTS
enabled. A non-debug FreeBSD build would not report the
messages.

(It is possible to buildworld for armv7 and install it
into a directory tree and use chroot into that directory
tree to run armv7 code on the RPi4's. This should not
produce the messages --and if it did then there would
be FreeBSD code to change for that kind of context.)
Post by bob prohaska
Many thanks for the detailed explanation, but I'll admit not understanding
much more than the quoted part above 8-(
===
Mark Millard
marklmi at yahoo.com
( dsl-only.net went
away in early 2018-Mar)
Warner Losh
2021-05-04 18:11:17 UTC
Permalink
Post by bob prohaska
After a successful compile of audio/xoscope on a Pi4 running current a
stream of messages appeared on the console and in the security log
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045006
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045005
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045002
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045006
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045005
+WARNING pid 26370 (xoscope): ioctl sign-extension ioctl ffffffffc0045002
They seem to come at a fairly high rate and clutter the logfiles, but
apart from that nuisance nothing else seemed visibly amiss.
Are they of any significance?
I fixed this a while ago, but some people copied our definitions which
weren't sufficiently careful in using unsigned in places to avoid sign
extension....

Warner

Loading...