Bug: non-UTF-8 characters kill syscheckd silently

[zbalkan]

Wazuh version	Component	Install type	Install method	Platform
4.7.4	Wazuh agent	Agent	N/A	N/A

Problem

We detected that the FIM logs were not being generated for a long while. Since other logs were being forwarded we could not detect this in time. After some troubleshooting, we found out that syscheckd process dies in a couple of second after it is started. The logs do not include any error message.

Root Cause Analysis

We checked that the problem occurred after updating the agent to v4.6.0. But there was no anomaly on any other agents.

We then tried to check ossec.log of the agent but it was hopeless.

Next step was to manually run the syscheckd, yet it failed in less than a minute. No logs and traces around.

We checked if the agent hits the inotify limit, but it was being killed when the inotify watcher number was around 12.000. The limit of the computer is set to 3.000.000, and enough memory was allocated for this change. The inotify instance number was just 1, so it was not about inotify. There were no logs regarding the issue within /var/log/dmesg as well.

We then observed the CPU and memory usage to see if it was killed by OOM Killer or any other reason. There was low resource usage. We omitted this scenario.

We enabled debug log in agent by setting the syscheck.debug value to 2 var/ossec/etc/internal_options.conf. No issues were detected in the logs: while the daemon was running normally, it just stops without any trace.

We utilized strace for detailed investigation. The last message we saw in the strace was [json.exception.type_error.316] invalid UTF-8 byte at index <some number>, triggered by nlohmann.json library. What caused the parsing error was some filed with weird names.

We discovered that some time ago, some old files had an error during file compression, and the output of the compression operation became weird named directories and files scattered around. The names are actually excerpts from the binary compression data, therefore some of them are accepted as valid file and directory names. The text representation of the binary-like paths were human readable but eventually they are binary representation of compressed data, which are not in the range of printable UTF-8 characters.

When the syscheckd daemon calculated the checksum successfully, it tries to create the json message from the collected data. When the directory names are byte-like char sequences, the json dump function tries to resolve them into UTF-8 characters and fail, instead of writing them to stream as is. It is by design as the dump() function requires the strings as UTF-8, as mentioned here. See the issue on the library's repository. And that function is used in syscheckd:

• wazuh/src/syscheckd/src/db/src/db.cpp

  Line 169 in 1e51c2d

  sync_callback(FIM_COMPONENT_FILE, json.dump().c_str());

• wazuh/src/syscheckd/src/db/src/db.cpp

  Line 221 in 1e51c2d

  sync_callback(component.c_str(), json.dump().c_str());

• wazuh/src/syscheckd/src/db/src/db.cpp

  Line 352 in 1e51c2d

  cJSON_Parse((*syncItem->toJSON()).dump().c_str())

Expected behavior

When the underlying dependency raises an error, it is expected for syscheckd to catch the error, either log and continue or resolve it in the business logic instead of killing the process with SIGABRT silently.

Hints

1. We also discovered that the problematic files were already on the server earlier. The error occurred as a regression after updating the agent from v4.5.2 to v4.6.0. Therefore, we can assume that a change in between these versions was creating this issue. Since the nlohmann json library strictly requires UTF-8 for a long while, it is safe to assume that it is Wazuh code that broke the process and created this regression.
2. It very unlikely that someone else would hit a similar error, though lack of proper error handling, debug and error logging is problematic. We expect Wazuh to provide better handling of the processes in case of errors. This is a reliability issue and important point is the lack of a process to find out the error in SDLC.

[vikman90]

@zbalkan Thank you for reporting this issue.

We have successfully reproduced the problem and are currently working on a fix.

Backtrace

#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=140737332213632) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=6, threadid=140737332213632) at ./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=140737332213632, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
#3  0x00007ffff6e91476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#4  0x00007ffff6e777f3 in __GI_abort () at ./stdlib/abort.c:79
#5  0x00007ffff6cc5b9e in ?? () from /var/ossec/bin/../lib/libstdc++.so.6
#6  0x00007ffff6cd120c in ?? () from /var/ossec/bin/../lib/libstdc++.so.6
#7  0x00007ffff6cd1277 in std::terminate() () from /var/ossec/bin/../lib/libstdc++.so.6
#8  0x00007ffff6cd14d8 in __cxa_throw () from /var/ossec/bin/../lib/libstdc++.so.6
#9  0x00007ffff7ee9b02 in nlohmann::json_abi_v3_11_2::detail::serializer<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> > > >::dump_escaped (this=0x7fffffffa280, s=..., ensure_ascii=false) at /root/wazuh-4.7.5/src/external/nlohmann/json.hpp:18397
#10 0x00007ffff7ee1605 in nlohmann::json_abi_v3_11_2::detail::serializer<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> > > >::dump (this=0x7fffffffa280, val=..., pretty_print=false, ensure_ascii=false, indent_step=0, current_indent=0) at /root/wazuh-4.7.5/src/external/nlohmann/json.hpp:18134
#11 0x00007ffff7ee0fa9 in nlohmann::json_abi_v3_11_2::detail::serializer<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> > > >::dump (this=0x7fffffffa280, val=..., pretty_print=false, ensure_ascii=false, indent_step=0, current_indent=0) at /root/wazuh-4.7.5/src/external/nlohmann/json.hpp:18054
#12 0x00007ffff7ee15ad in nlohmann::json_abi_v3_11_2::detail::serializer<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> > > >::dump (this=0x7fffffffa280, val=..., pretty_print=false, ensure_ascii=false, indent_step=0, current_indent=0) at /root/wazuh-4.7.5/src/external/nlohmann/json.hpp:18123
#13 0x00007ffff7ee0fa9 in nlohmann::json_abi_v3_11_2::detail::serializer<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> > > >::dump (this=0x7fffffffa280, val=..., pretty_print=false, ensure_ascii=false, indent_step=0, current_indent=0) at /root/wazuh-4.7.5/src/external/nlohmann/json.hpp:18054
#14 0x00007ffff7edb359 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> > >::dump (this=0x555555aeb4f0, indent=-1,
    indent_char=32 ' ', ensure_ascii=false, error_handler=nlohmann::json_abi_v3_11_2::detail::error_handler_t::strict) at /root/wazuh-4.7.5/src/external/nlohmann/json.hpp:20451
#15 0x00007ffff7ecda99 in fim_db_transaction_sync_row (txn_handler=0x5555557dd790, entry=0x7fffffffa620) at /root/wazuh-4.7.5/src/syscheckd/src/db/src/db.cpp:352
#16 0x0000555555578a6e in fim_file (path=0x5555557f8e40 "/root/test/tir\355ti\361i%", configuration=0x555555854e80, evt_data=0x7fffffffa880, txn_handle=0x5555557dd790,
    txn_context=0x7fffffffa870) at /root/wazuh-4.7.5/src/syscheckd/src/create_db.c:892
#17 0x0000555555578042 in fim_checker (path=0x5555557f8e40 "/root/test/tir\355ti\361i%", evt_data=0x7fffffffa880, parent_configuration=0x555555854e80, dbsync_txn=0x5555557dd790,
    ctx=0x7fffffffa870) at /root/wazuh-4.7.5/src/syscheckd/src/create_db.c:730
#18 0x00005555555784a6 in fim_directory (dir=0x55555581bec0 "/root/test", evt_data=0x7fffffffa880, configuration=0x555555854e80, dbsync_txn=0x5555557dd790, ctx=0x7fffffffa870)
    at /root/wazuh-4.7.5/src/syscheckd/src/create_db.c:809
#19 0x00005555555780fa in fim_checker (path=0x55555581bec0 "/root/test", evt_data=0x7fffffffa880, parent_configuration=0x555555854e80, dbsync_txn=0x5555557dd790, ctx=0x7fffffffa870)
    at /root/wazuh-4.7.5/src/syscheckd/src/create_db.c:738
#20 0x00005555555771b5 in fim_scan () at /root/wazuh-4.7.5/src/syscheckd/src/create_db.c:522
#21 0x0000555555584564 in start_daemon () at /root/wazuh-4.7.5/src/syscheckd/src/run_check.c:285
#22 0x0000555555582d52 in main (argc=2, argv=0x7fffffffe038) at /root/wazuh-4.7.5/src/syscheckd/src/main.c:333

We will keep you posted.
Best regards.

[zbalkan]

Hi @vikman90, thanks for the update.

[vikman90]

I have uploaded a preliminary attempt at a fix, and at least I have managed to replace the crash with this log:

2024/05/20 16:30:14 wazuh-syscheckd: ERROR: [json.exception.type_error.316] invalid UTF-8 byte at index 13: 0x63

Next steps

• Validate that the fix is correct.
• Unit tests.
• Integration tests.
• Study the possibility, cost and impact of cleaning the extraneous byte instead of discarding the file.

[zbalkan]

Hi @vikman90, logging properly is better. It would have saved our logs and troubleshooting efforts.

Here, the question is, would converting byte sequence to an array of UTF-8 chars be worth spending time if the files are most probably unreadable chunks? In my case, they are useless. Our solution was removing them all. But if there are valid cases, then it may be worth.

[vikman90]

@zbalkan, if I understood you correctly, this is what I was referring to in the fourth point. Currently, the code introduces some non-UTF8 data into the JSON structure (in this case, the file name). When printing that JSON as a string, the error occurs.

It would be worth doing a sanitization prior to ingesting the data into the structure, as well as improving the logging, as you mention. However, our highest priority is to avoid a crash in the next version of the product.

[vikman90]

New error condition

Configuration

<syscheck>
  <directories realtime="yes" report_changes="yes">/root/test/fim</directories>
  <synchronization>
    <interval>10s</interval>
  </synchronization>
</syscheck>

Steps

1. Create a file with non-UTF8 name:

   touch $(echo -n "Víctor" | iconv -f UTF-8 -t ISO-8859-1)

2. Run wazuh-syscheckd.
   This will let the program traverse the critical path.
3. Touch the file again.
   This will produce the error log:

   2024/05/21 10:10:08 wazuh-syscheckd: ERROR: [json.exception.type_error.316] invalid UTF-8 byte at index 17: 0x63

4. Wait ~5 seconds.
   A new crash happens.

Backtrace

#0  __GI_abort () at ./stdlib/abort.c:49
#1  0x00007ffff6cc5b9e in ?? () from /var/ossec/bin/../lib/libstdc++.so.6
#2  0x00007ffff6cd120c in ?? () from /var/ossec/bin/../lib/libstdc++.so.6
#3  0x00007ffff6cd1277 in std::terminate() () from /var/ossec/bin/../lib/libstdc++.so.6
#4  0x00007ffff6cd14d8 in __cxa_throw () from /var/ossec/bin/../lib/libstdc++.so.6
#5  0x00007ffff7ee9b3e in nlohmann::json_abi_v3_11_2::detail::serializer<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> > > >::dump_escaped (this=0x7ffff530f070, s=..., ensure_ascii=false)
    at /root/wazuh-4.7.5/src/external/nlohmann/json.hpp:18397
#6  0x00007ffff7ee1641 in nlohmann::json_abi_v3_11_2::detail::serializer<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> > > >::dump (this=0x7ffff530f070, val=..., pretty_print=false, ensure_ascii=false,
    indent_step=0, current_indent=0)
    at /root/wazuh-4.7.5/src/external/nlohmann/json.hpp:18134
#7  0x00007ffff7ee0fe5 in nlohmann::json_abi_v3_11_2::detail::serializer<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> > > >::dump (this=0x7ffff530f070, val=..., pretty_print=false, ensure_ascii=false,
    indent_step=0, current_indent=0)
    at /root/wazuh-4.7.5/src/external/nlohmann/json.hpp:18054
#8  0x00007ffff7ee0fe5 in nlohmann::json_abi_v3_11_2::detail::serializer<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> > > >::dump (this=0x7ffff530f070, val=..., pretty_print=false, ensure_ascii=false,
    indent_step=0, current_indent=0)
    at /root/wazuh-4.7.5/src/external/nlohmann/json.hpp:18054
#9  0x00007ffff7edb395 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> > >::dump (this=0x7ffff530f350,
    indent=-1, indent_char=32 ' ', ensure_ascii=false,
    error_handler=nlohmann::json_abi_v3_11_2::detail::error_handler_t::strict)
    at /root/wazuh-4.7.5/src/external/nlohmann/json.hpp:20451
#10 0x00007ffff71fc0a9 in RSync::MessageChecksum<RSync::SplitContext>::send(std::function<void (std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)>, 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> > > const&, RSync::SplitContext const&) (this=0x7ffff0002f20,
    callback=..., config=..., data=...)
    at /root/wazuh-4.7.5/src/shared_modules/rsync/src/messageChecksum.h:66
#11 0x00007ffff71f1646 in RSync::RSyncImplementation::startRSync(void*, std::shared_ptr<RSync::DBSyncWrapper> const&, 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> > > const&, std::function<void (std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)>) (
    this=0x7ffff7287aa0 <RSync::RSyncImplementation::instance()::s_instance>,
    handle=0x5555558385e0, spDBSyncWrapper=..., startConfiguration=...,
    callbackWrapper=...)
    at /root/wazuh-4.7.5/src/shared_modules/rsync/src/rsyncImplementation.cpp:118
#12 0x00007ffff71c47e4 in RemoteSync::startSync(void*, 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> > > const&, std::function<void (std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)>) (this=0x5555557d7eb0, dbsyncHandle=0x555555819970,
    startConfiguration=..., callbackData=...)
    at /root/wazuh-4.7.5/src/shared_modules/rsync/src/rsync.cpp:275
#13 0x00007ffff7f4708e in FIMDBCreator<(OSType)0>::sync(std::shared_ptr<RemoteSync>, void* const&, std::function<void (std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)>, std::function<void (std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)>, bool) (RSyncHandler=...,
--Type <RET> for more, q to quit, c to continue without paging--c
    handle=@0x7ffff530f7d8: 0x555555819970, syncFileMessageFunction=..., syncRegistryMessageFunction=..., syncRegistryEnabled=false) at /root/wazuh-4.7.5/src/syscheckd/src/db/src/fimDBSpecialization.h:370
#14 0x00007ffff7f41366 in FIMDB::sync (this=0x7ffff7fb87e0 <FIMDB::instance()::s_instance>) at /root/wazuh-4.7.5/src/syscheckd/src/db/src/fimDB.cpp:39
#15 0x00007ffff7f41637 in FIMDB::syncAlgorithm (this=0x7ffff7fb87e0 <FIMDB::instance()::s_instance>) at /root/wazuh-4.7.5/src/syscheckd/src/db/src/fimDB.cpp:64
#16 0x00007ffff7f41d09 in operator() (__closure=0x55555583a7f8) at /root/wazuh-4.7.5/src/syscheckd/src/db/src/fimDB.cpp:161
#17 0x00007ffff7f465e2 in std::__invoke_impl<void, FIMDB::runIntegrity()::<lambda()> >(std::__invoke_other, struct {...} &&) (__f=...) at /usr/include/c++/11/bits/invoke.h:61
#18 0x00007ffff7f465a5 in std::__invoke<FIMDB::runIntegrity()::<lambda()> >(struct {...} &&) (__fn=...) at /usr/include/c++/11/bits/invoke.h:96
#19 0x00007ffff7f46552 in std::thread::_Invoker<std::tuple<FIMDB::runIntegrity()::<lambda()> > >::_M_invoke<0>(std::_Index_tuple<0>) (this=0x55555583a7f8) at /usr/include/c++/11/bits/std_thread.h:259
#20 0x00007ffff7f46526 in std::thread::_Invoker<std::tuple<FIMDB::runIntegrity()::<lambda()> > >::operator()(void) (this=0x55555583a7f8) at /usr/include/c++/11/bits/std_thread.h:266
#21 0x00007ffff7f4650a in std::thread::_State_impl<std::thread::_Invoker<std::tuple<FIMDB::runIntegrity()::<lambda()> > > >::_M_run(void) (this=0x55555583a7f0) at /usr/include/c++/11/bits/std_thread.h:211
#22 0x00007ffff6cff253 in ?? () from /var/ossec/bin/../lib/libstdc++.so.6
#23 0x00007ffff6ee3ac3 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#24 0x00007ffff6f75850 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

[jotacarma90]

Proposed solution for crashes

Hello team,

This last error found does not occur in syscheck but in rsync, this is because during the callback fim_db_file_update, the dump error is controlled, but just before in updateFile, the sync data has been sent to rsync, and we have the same behavior in the src/shared_modules/rsync/src/messageChecksum.h line:

callback(outputMessage.dump());

So we should add error handling here as well.

After introducing these changes in the fix branch: 4.7.5...fix/23354-fim-crash

I have been analyzing all the behavior of syscheck, (whodata, realtime and scheduled), the event with invalid characters is lost, and an error appears in the log, but at least syscheck does not crash:

2024/05/21 14:50:36 wazuh-syscheckd[408072] logging_helper.c:50 at loggingFunction(): ERROR: [json.exception.type_error.316] invalid UTF-8 byte at index 8: 0x63

I have also checked that the realtime mode can work correctly with content with invalid characters, and there is no problem:

(6321): Sending FIM event: {"data":{"attributes":{"checksum":"32dcbd46d5fe59a02ff8867577aae0c46a9db516","gid":"0","group_name":"root","hash_md5":"7ecc2dee85aa76885454e0e4e82ef585","hash_sha1":"d934f2ecd7c64e015a7740c7bd51ad8884b1ac74","hash_sha256":"9f009a93194a88487e7066fc0cb3b320871e1a656885fa798193ef9cdac111ac","inode":3801092,"mtime":1716303037,"perm":"rw-r--r--","size":12,"type":"file","uid":"0","user_name":"root"},"changed_attributes":["size","mtime","md5","sha1","sha256"],"mode":"whodata","old_attributes":{"checksum":"0383fc9edde47c329256e0b43b60dabe20df52a3","gid":"0","group_name":"root","hash_md5":"831ab1436667790d3a5576f964037805","hash_sha1":"deaf46e118c633947bfd65a1d8975be422d4786c","hash_sha256":"6895510df2c7cd34bff5cc49fc699264269bd643e084bd13dc80473da22c26e2","inode":3801092,"mtime":1716303034,"perm":"rw-r--r--","size":6,"type":"file","uid":"0","user_name":"root"},"path":"/test/file","timestamp":1716303037,"type":"modified","version":"2.0","content_changes":"1c1\n< V�ctor\n\\ No newline at end of file\n---\n> V�ctorV�ctor\n\\ No newline at end of file\n","audit":{"user_id":"0","user_name":"root","process_name":"/usr/bin/bash","process_id":408578,"cwd":"/test","group_id":"0","group_name":"root","audit_uid":"1000","audit_name":"vagrant","effective_uid":"0","effective_name":"root","parent_name":"/usr/bin/bash","parent_cwd":"/test","ppid":395370}},"type":"event"}

Issue to analyze the problem in depth

#23545

[vikman90]

Dear @zbalkan,

We have just applied the fix for the issue you reported. As of the next patch version, the agent will print a log like this when trying to monitor a file whose name is unsupported (non-UTF8):

wazuh-syscheckd: WARNING: (6955): Ignoring file '/root/test/fim/D�emo' due to unsupported name (non-UTF8).

This way, there is a double layer:

1. Data sanitization:
   Do not allow file names that we know that are not supported.
2. Handle exceptions:
   Should the JSON parser raise an exception for any other problem, the program will catch that.

On the other hand, we will extend the support for this kind of files:

• Syscheckd cannot process paths with non-UTF-8 characters #23545

Thank you very much for bringing this to our attention.

Best regards!