Error loading cache with more than ~600 entries with non-C locale

[berarma]

Performous & operating system versions

Performous 1.3.0-45-gcb10e1c6 (latest master) OS: Debian 12.2

What is the problem?

First run without cache files goes well. Next time Performous is run and tries to load the cache Json file it aborts. Running with command LC_ALL=C ./performous loads the cache file correctly.

I've tried to analyze the issue and it's an assert related to the parsing of float values. Float values are written with dots but for some reason the json parser has issues parsing the dots.

What's weird is that it only happens when there's a certain amount of entries in the cache file. It seems to fail always when parsing around the 600-900th entry. I've checked it's not related to any particular entry. It seems to be related to the position of the entry in the cache file.

Steps to reproduce

1. Run Performous with LC_ALL=es_ES.utf8 ./performous over a large directory of songs.
2. Wait for all the songs to be loaded.
3. Exit Performous.
4. Run Performous again with LC_ALL=es_ES.utf8 ./performous.

Additional context

Backtrace:

Thread 24 "performous" received signal SIGABRT, Aborted.
[Switching to Thread 0x7fff825f06c0 (LWP 305345)]
__pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at ./nptl/pthread_kill.c:44
Download failed: Argumento inválido.  Continuing without source file ./nptl/./nptl/pthread_kill.c.                                                                                                                                                                                                                            
44  ./nptl/pthread_kill.c: No existe el fichero o el directorio.
(gdb) bt
#0  __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at ./nptl/pthread_kill.c:44
#1  0x00007ffff39cad9f in __pthread_kill_internal (signo=6, threadid=<optimized out>) at ./nptl/pthread_kill.c:78
#2  0x00007ffff397bf32 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#3  0x00007ffff3966472 in __GI_abort () at ./stdlib/abort.c:79
#4  0x00007ffff3966395 in __assert_fail_base
    (fmt=0x7fff81aac6d2 "%s%s%s:%u: %s%sLa declaración `%s' no se cumple.\n%n", assertion=assertion@entry=0x5555558a8208 "endptr == token_buffer.data() + token_buffer.size()", file=file@entry=0x5555558a6f78 "/usr/include/nlohmann/detail/input/lexer.hpp", line=line@entry=1289, function=function@entry=0x5555558a7f78 "nlohmann::json_abi_v3_11_2::detail::lexer<BasicJsonType, InputAdapterType>::token_type nlohmann::json_abi_v3_11_2::detail::lexer<BasicJsonType, InputAdapterType>::scan_number() [with BasicJsonType = n"...) at ./assert/assert.c:92
#5  0x00007ffff3974e32 in __GI___assert_fail
    (assertion=0x5555558a8208 "endptr == token_buffer.data() + token_buffer.size()", file=0x5555558a6f78 "/usr/include/nlohmann/detail/input/lexer.hpp", line=1289, function=0x5555558a7f78 "nlohmann::json_abi_v3_11_2::detail::lexer<BasicJsonType, InputAdapterType>::token_type nlohmann::json_abi_v3_11_2::detail::lexer<BasicJsonType, InputAdapterType>::scan_number() [with BasicJsonType = n"...) at ./assert/assert.c:101
#6  0x00005555556ec19b in nlohmann::json_abi_v3_11_2::detail::lexer<nlohmann::json_abi_v3_11_2::basic_json<std::map, std::vector, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool, long, unsigned long, double, std::allocator, nlohmann::json_abi_v3_11_2::adl_serializer, std::vector<unsigned char, std::allocator<unsigned char> > >, nlohmann::json_abi_v3_11_2::detail::input_stream_adapter>::scan_number() (this=0x7fff825dec38) at /usr/include/nlohmann/detail/input/lexer.hpp:1289
#7  0x00005555556e3e6e in nlohmann::json_abi_v3_11_2::detail::lexer<nlohmann::json_abi_v3_11_2::basic_json<std::map, std::vector, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool, long, unsigned long, double, std::allocator, nlohmann::json_abi_v3_11_2::adl_serializer, std::vector<unsigned char, std::allocator<unsigned char> > >, nlohmann::json_abi_v3_11_2::detail::input_stream_adapter>::scan() (this=0x7fff825dec38) at /usr/include/nlohmann/detail/input/lexer.hpp:1582
#8  0x00005555556dd404 in nlohmann::json_abi_v3_11_2::detail::parser<nlohmann::json_abi_v3_11_2::basic_json<std::map, std::vector, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool, long, unsigned long, double, std::allocator, nlohmann::json_abi_v3_11_2::adl_serializer, std::vector<unsigned char, std::allocator<unsigned char> > >, nlohmann::json_abi_v3_11_2::detail::input_stream_adapter>::get_token() (this=0x7fff825dec10) at /usr/include/nlohmann/detail/input/parser.hpp:463
#9  0x00005555556de8f7 in nlohmann::json_abi_v3_11_2::detail::parser<nlohmann::json_abi_v3_11_2::basic_json<std::map, std::vector, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool, long, unsigned long, double, std::allocator, nlohmann::json_abi_v3_11_2::adl_serializer, std::vector<unsigned char, std::allocator<unsigned char> > >, nlohmann::json_abi_v3_11_2::detail::input_stream_adapter>::sax_parse_internal<nlohmann::json_abi_v3_11_2::detail::json_sax_dom_parser<nlohmann::json_abi_v3_11_2::basic_json<std::map, std::vector, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool, long, unsigned long, double, std::allocator, nlohmann::json_abi_v3_11_2::adl_serializer, std::vector<unsigned char, std::allocator<unsigned char> > > > >(nlohmann::json_abi_v3_11_2::detail::json_sax_dom_parser<nlohmann::json_abi_v3_11_2::basic_json<std::map, std::vector, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool, long, unsigned long, double, std::allocator, nlohmann::json_abi_v3_11_2::adl_serializer, std::vector<unsigned char, std::allocator<unsigned char> > > >*) (this=0x7fff825dec10, sax=0x7fff825de900) at /usr/include/nlohmann/detail/input/parser.hpp:432
#10 0x00005555556d883c in nlohmann::json_abi_v3_11_2::detail::parser<nlohmann::json_abi_v3_11_2::basic_json<std::map, std::vector, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool, long, unsigned long, double, std::allocator, nlohmann::json_abi_v3_11_2::adl_serializer, std::vector<unsigned char, std::allocator<unsigned char> > >, nlohmann::json_abi_v3_11_2::detail::input_stream_adapter>::parse(bool, nlohmann::json_abi_v3_11_2::basic_json<std::map, std::vector, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool, long, unsigned long, double, std::allocator, nlohmann::json_abi_v3_11_2::adl_serializer, std::vector<unsigned char, std::allocator<unsigned char> > >&) (this=0x7fff825dec10, strict=true, result=...) at /usr/include/nlohmann/detail/input/parser.hpp:126
#11 0x00005555556d716c in nlohmann::json_abi_v3_11_2::basic_json<std::map, std::vector, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool, long, unsigned long, double, std::allocator, nlohmann::json_abi_v3_11_2::adl_serializer, std::vector<unsigned char, std::allocator<unsigned char> > >::parse<std::basic_ifstream<char, std::char_traits<char> >&>(std::basic_ifstream<char, std::char_traits<char> >&, std::function<bool (int, nlohmann::json_abi_v3_11_2::detail::parse_event_t, nlohmann::json_abi_v3_11_2::basic_json<std::map, std::vector, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool, long, unsigned long, double, std::allocator, nlohmann::json_abi_v3_11_2::adl_serializer, std::vector<unsigned char, std::allocator<unsigned char> > >&)>, bool, bool) (i=..., cb=..., allow_exceptions=true, ignore_comments=false) at /usr/include/nlohmann/json.hpp:4014
#12 0x00005555556d4482 in readJSON(std::filesystem::__cxx11::path const&) (filename=filesystem::path "/home/berarma/.cache/performous/songs.json" = {...}) at /home/berarma/Descargas/performous/game/json.cc:13
#13 0x000055555583e8d7 in Songs::LoadCache() (this=0x7fffffffc420) at /home/berarma/Descargas/performous/game/songs.cc:124
#14 0x000055555583e0bd in Songs::reload_internal() (this=0x7fffffffc420) at /home/berarma/Descargas/performous/game/songs.cc:87
#15 0x000055555583df1d in operator()() const (__closure=0x5555564747c8) at /home/berarma/Descargas/performous/game/songs.cc:77
#16 0x00005555558484a6 in std::__invoke_impl<void, Songs::reload()::<lambda()> >(std::__invoke_other, struct {...} &&) (__f=...) at /usr/include/c++/12/bits/invoke.h:61
#17 0x0000555555848469 in std::__invoke<Songs::reload()::<lambda()> >(struct {...} &&) (__fn=...) at /usr/include/c++/12/bits/invoke.h:96
#18 0x0000555555848416 in std::thread::_Invoker<std::tuple<Songs::reload()::<lambda()> > >::_M_invoke<0>(std::_Index_tuple<0>) (this=0x5555564747c8) at /usr/include/c++/12/bits/std_thread.h:252
#19 0x00005555558483ea in std::thread::_Invoker<std::tuple<Songs::reload()::<lambda()> > >::operator()(void) (this=0x5555564747c8) at /usr/include/c++/12/bits/std_thread.h:259
#20 0x00005555558483ce in std::thread::_State_impl<std::thread::_Invoker<std::tuple<Songs::reload()::<lambda()> > > >::_M_run(void) (this=0x5555564747c0) at /usr/include/c++/12/bits/std_thread.h:210
#21 0x00007ffff3cd44a3 in std::execute_native_thread_routine(void*) (__p=0x5555564747c0) at ../../../../../src/libstdc++-v3/src/c++11/thread.cc:82
#22 0x00007ffff39c9044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#23 0x00007ffff3a4961c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Log(s) & preferences file(s)

No response

[Baklap4]

Does this also happen when you run performous with the spanish language set within the settings? (you can change this setting runtime since 1.2.0 so there's no need to override LC_ALL anymore

[berarma]

Does this also happen when you run performous with the spanish language set within the settings? (you can change this setting runtime since 1.2.0 so there's no need to override LC_ALL anymore

Yes, it's the same.

I'm only overriding LC_ALL to test with C locale. My default locale is es_ES. I just wrote the steps to reproduce that way so that it could be reproduced in systems with English locales.

[Baklap4]

Thanks for the quick response, could you share your song.json file? Then we can take a look at it 👍

[berarma]

Of course. songs.json.gz

[Baklap4]

Thanks a lot! Since you mentioned the float with period and you're using the spanish locale... What happens if you replace all the periods with a comma?

It seems to me a problem on globalization.. We write with a period, but when reading we expect a comma (since that's how decimal values are written in spanish: 3,5 instead of 3.5

[berarma]

If I replace periods with commas then it works. I've also quoted the numbers to avoid issues with the Json format.

Then I've tried only adding the quotes to see which change worked and it was the quotes. Simply quoting (") the float numbers makes it work.

Then I tried just replacing periods with commas even though the resulting Json is invalid, and it works too.

And to add to the weirdness. it works when the cache file is less than ~500 entries long.

[Baklap4]

Hmmm then it's probably the comma/period thing combined with locale settings.

@HetorusNL last time you fixed UTF8 problem in master. Any idea how to write and read the json with the current locale?

[berarma]

A little more. I'm suspecting about some race condition so I've put a delay just before creating the Window object in the mainloop. With that delay there it can load the cache file. If I put the delay after the window creation it fails again. So it seems the window object is doing something that the Json code doesn't like.

[berarma]

I think I know what's happening. The initialization of the SDL video subsystem sets the locale using setlocale and since it's running in parallel to the Json code it messes the parsing which uses strtof. I've tested it without initializing the video subsystem, only the joystick, and it works. I've also found the code where the locale is set inside SDL: https://github.com/libsdl-org/SDL/blob/1b284cd4153d967f17cad9535cf00c153dd62570/src/video/x11/SDL_x11keyboard.c#L203

I don't know what's the best way to fix it. Could we make the loading of songs to run synchronously at least on Linux?

[berarma]

Really, it's only the loading of the Json which should be synchronous. That's really fast. I think it would be no problem.

[Baklap4]

Hmmm how about setting the locale before anything happens?, that's a best practice anyway this should fix the problem i guess?

[berarma]

Hmmm how about setting the locale before anything happens?, that's a best practice anyway this should fix the problem i guess?

We could set the locale ourselves before loading the file but this would only make the issue permanent, it would still have to be fixed. And I'm not sure there's a need to set the locale.

Maybe the root of the issue is outside this project, because why the Json library isn't locale independent when parsing and SDL needs to play with the locale in this way?

I've tried making the loading of the Json synchronous. It's only moving a few lines of code and it works well. I can make a PR.

[berarma]

Investigating a bit more, the json library depends on a non-changing locale for correctly parsing. A locale change while it's parsing will make it fail.

SDL needs to change temporarily the locale before calling a X11 function. The call will probably produce a context switch.

Thus, parsing a json file concurrently while initializing SDL isn't safe.