USB performance regression of mainline from the USB development branch

[Jakub Jermář]

After having been merged to HelenOS in mainline,1006, the USB subsystem seems to have much larger latency than it had in the USB development branch.

The cause may be related to reversion of the change in cacheablitity of address space areas which was made as part of the mainline,1006:

sys_as_create_area() now creates cacheable areas by default 

Note that this is no change against mainline, but a change against the USB development branch, where cacheability is not explicitly enforced on address space areas.

If this hypothesis is correct, we should cautiously merge even that aspect of the USB development branch. Caution is due as I remember some architectures (e.g. sparc64) are rather sensitive to changes in cacheability.

[Jiri Svoboda]

Investigated this with Vhostpur. Found out that the slowdown is due to rather verbose logging, which works rather faster in the USB branch than in the mainline.

Several USB log messages are produced per every event. These are not written to system log, but they are written to USB log files. The difference from the USB branch is that in mainline devman is started before console, so it does not receive standard files 0, 1, 2. The same goes for the USB drivers, which inherit from devman.

When USB drivers start they have no open file descriptors. When a USB driver opens a log file for writing, file descriptor 0 is allocated. fopen() calls _setvbuf() which looks at the file descriptor number and for 0 it sets _IONBUF.

The log is written with no buffering. The logging function uses fprintf() and so many IPC calls are made for each line of output.

[Jakub Jermář]

For the USB subsystem, this should be fixed in mainline,1047. I am closing the ticket with the acknowledgement that the problem is still there on the generic level. The problem can be summarized as:

_setvbuf() should not set buffering options based on the descriptor value