Very slow IO since newlib commit 33507633

[Ghabry]

Since the mentioned commit (which is from September 2016) operations on file descriptors are extremely slow. This gives a significant slowdown e.g. in EasyRPG Player which was running 60 FPS before and regressed to 0-15 FPS depending on the game. (we noticed this two months ago because that was the time when we recompiled the SDK, we were on August 2016 before).

My bisect says that the first bad/slow commit is
fa92db8
The previous one didn't compile, which is very likely the real bad commit:
3350763
(And the last good/fast commit is 6a4dc0f)

Test case (thanks to @Rinnegatamante because I don't have a Vita)

You have to create a 100 kbyte file under "/data/test.bin". The content doesn't matter.
The test program does lots of 1byte fread calls. I have no idea what the real cause is, but the IO is slow ;).
In the end the program will tell you how long the newlib IO took. On newer (since that commit) newlib versions the result is around 2 seconds and on older version around 80 ms. This is a significant regression:

#include <stdlib.h>
#include <string.h>
#include <unistd.h>
#include <stdio.h>
#include <vitasdk.h>
#include <vita2d.h> 

#define FILENAME "ux0:/data/test.bin"

vita2d_pgf* debug_font;
void drawText(uint32_t y, char* text, uint32_t color){
	int i;
	for (i=0;i<3;i++){
		vita2d_start_drawing();
		vita2d_pgf_draw_text(debug_font, 2, y, color, 1.0, text	);
		vita2d_end_drawing();

		vita2d_wait_rendering_done();
		vita2d_swap_buffers();
	}
}

void drawLoopText(uint32_t y, char* text, uint32_t color){
	vita2d_pgf_draw_text(debug_font, 2, y, color, 1.0, text	);
}

int main(int argc, char** argp){
	char res[256];
	uint64_t tick1, tick2;

	vita2d_init();
	vita2d_set_clear_color(RGBA8(0x00, 0x00, 0x00, 0xFF));
	debug_font = vita2d_load_default_pgf();
	uint32_t white = RGBA8(0xFF, 0xFF, 0xFF, 0xFF);

	drawText(25, "Starting SceIo test, please wait...", white);
	tick1 = sceKernelGetProcessTimeWide();
	SceUID fh = sceIoOpen(FILENAME, SCE_O_RDONLY, 0777);
	SceOff size = sceIoLseek(fh, 0, SEEK_END);
	sceIoLseek(fh, 0, SEEK_SET);

	uint8_t dummy;
	int i;
	for (i = 0; i < size; i++){
		sceIoRead(fh, &dummy, 1);
	}
	sceIoClose(fh);

	tick2 = sceKernelGetProcessTimeWide();
	sprintf(res, "Test took %lldms to finish.", (tick2 - tick1) / 1000);
	drawText(45, res, white);
	drawText(65, "Starting newlib io test, please wait...", white);

	tick1 = sceKernelGetProcessTimeWide();
	FILE* fd = fopen(FILENAME, "rb");
	for (i = 0; i < size; i++){
		fread(&dummy, 1, 1, fd);
	}
	fclose(fd);

	tick2 = sceKernelGetProcessTimeWide();
	sprintf(res, "Test took %lldms to finish.", (tick2 - tick1) / 1000);
	drawText(85, res, white);

	for (;;){}
}

Makefile, put main.c in "source":

TARGET		:= Testcase
TITLE		:= TESTCASE1
SOURCES		:= source
INCLUDES	:= include

LIBS = -lvita2d -lSceLibKernel_stub \
	-lSceSysmodule_stub -lSceCtrl_stub \
	-lm -lSceAppUtil_stub -lScePgf_stub -lfreetype \
	-lc -lScePower_stub -lSceCommonDialog_stub -lpng16 -lz \
	-lSceGxm_stub -lSceDisplay_stub 

CFILES   := $(foreach dir,$(SOURCES), $(wildcard $(dir)/*.c))
CPPFILES   := $(foreach dir,$(SOURCES), $(wildcard $(dir)/*.cpp))
BINFILES := $(foreach dir,$(DATA), $(wildcard $(dir)/*.bin))
OBJS     := $(addsuffix .o,$(BINFILES)) $(CFILES:.c=.o) $(CPPFILES:.cpp=.o) 

PREFIX  = arm-vita-eabi
CC      = $(PREFIX)-gcc
CXX      = $(PREFIX)-g++
CFLAGS  = -Wl,-q -O3 -Wall
CXXFLAGS  = $(CFLAGS) -fno-exceptions -std=gnu++11
ASFLAGS = $(CFLAGS)

all: $(TARGET).vpk

$(TARGET).vpk: $(TARGET).velf
	vita-make-fself $< .\build\eboot.bin
	vita-mksfoex -s TITLE_ID=$(TITLE) "$(TARGET)" param.sfo
	cp -f param.sfo ./build/sce_sys/param.sfo

%.velf: %.elf
	$(PREFIX)-strip -g $<
	vita-elf-create $< $@
	vita-make-fself $@ eboot.bin

$(TARGET).elf: $(OBJS)
	$(CC) $(CFLAGS) $^ $(LIBS) -o $@

clean:
	@rm -rf $(TARGET).velf $(TARGET).elf $(OBJS)