jsonpatch_error() shutdown crash

[andysCaplin]

Hi. I'm getting a weird error trying to catch a jsonpatch_error(). My code is quite simple -

        try {
                    jsoncons::jsonpatch::apply_patch(jsonob->json, delta);
...
            } catch ( std::exception& e ) {
...

I'm assuming that std::exception is ok here - is that correct ?

This code works fine normally but sometimes I'm getting this crash during shutdown.

#0  0x0000003ae9a325e5 in raise () from /lib64/libc.so.6
#1  0x0000003ae9a33dc5 in abort () from /lib64/libc.so.6
#2  0x0000000000af6e75 in __gnu_cxx::__verbose_terminate_handler () at ../../../../libstdc++-v3/libsupc++/vterminate.cc:95
#3  0x0000000000af6a26 in __cxxabiv1::__terminate (handler=<optimized out>) at ../../../../libstdc++-v3/libsupc++/eh_terminate.cc:38
#4  0x0000000000af6a53 in std::terminate () at ../../../../libstdc++-v3/libsupc++/eh_terminate.cc:48
#5  0x0000000000af6bcf in __cxxabiv1::__cxa_pure_virtual () at ../../../../libstdc++-v3/libsupc++/pure.cc:50
#6  0x00000000006a4971 in message (this=<synthetic pointer>) at /usr/include/c++/4.8.5/system_error:158
#7  std::system_error::system_error (this=this@entry=0x7f7e78de5f80, __ec=...) at /usr/include/c++/4.8.5/system_error:316
#8  0x00000000006b431e in jsonpatch_error (ec=..., this=0x7f7e78de5f80, __in_chrg=<optimized out>, __vtt_parm=<optimized out>)
    at ../../libs/jsoncons/include/jsoncons_ext/jsonpatch/jsonpatch_error.hpp:19
#9  jsoncons::jsonpatch::apply_patch<jsoncons::basic_json<char, jsoncons::sorted_policy, std::allocator<char> > > (target=...,
    patch=...) at ../../libs/jsoncons/include/jsoncons_ext/jsonpatch/jsonpatch.hpp:487

i.e. It's saying a pure virtual method is being called when the patch errror message is being accessed.

Also, the patch message being processed is not invalid but is being interpreted as invalid.

This seems to happen only when we're shutting down the application.

I noticed that I can call the patch method and pass an errorcode ref and that won't throw an error so I could avoid the crash that way.

[danielaparker]

Catching a reference to a std::exception is fine.

Updating my earlier reply.

From the error message, it appears that you are using gcc 4.8.5. I think this error on termination is related to the fact that the std::error_category default constructor is not marked constexpr in libstdc++ in gcc 4.8, as it should have been, and which was fixed in 4.9. What this means is that we are not guaranteed that the initialization of our global object jsonpath_error_category_impl in

inline
const std::error_category& jsonpatch_error_category()
{
  static jsonpatch_error_category_impl instance;
  return instance;
}

is performed during constant initialization, which can lead to a static deinitialization issue, and which you would most likely observe when using shared libraries. I don't think you would see this error on termination with gcc 4.9 or later. If it's possible for you to check with 4.9, that would be much appreciated.

In any case, I'll implement a work around that should work with 4.8.

Daniel

[andysCaplin]

Thank your for replying so quickly.

All our build and development machines are on version 4.8.5 - but I'll try to get a machine with 4.9 and update here when I do that.

The issue we have is repeatable so I'll be able to verify any fix. I noticed that you created an error_category branch. I'll try testing that today.

In response to your earlier question the value of ec at frame 8 ( jsonpatch_error ) is

$1 = (const std::error_code &) @0x7fb96bffc8d0: {_M_value = 1,
  _M_cat = 0xfe6640 <jsoncons::jsonpatch::jsonpatch_error_category()::instance>}

One more question about this. Do you think that this issue could also have caused the messages to have been misdiagnosed as invalid in the 1st place ?
Because the other issue is that just before shutdown I get several logs indicating that I got invalid patch messages which aren't actually invalid. ( In the code extract above we log the exception message in the catch ).
In each of those cases the code has hit the catch successfully and the message has been extracted and logged.

[andysCaplin]

Ok - looks like I jumped the gun. I got this compile error using gcc 4.8.5 when I built the new branch you created.

../../libs/jsoncons/include/jsoncons_ext/jsonpatch/jsonpatch_error.hpp: In constructor ‘constexpr jsoncons::jsonpatch::jsonpatch_error_category_impl::jsonpatch_error_category_impl()’:
../../libs/jsoncons/include/jsoncons_ext/jsonpatch/jsonpatch_error.hpp:65:5: error: call to non-constexpr function ‘std::error_category::error_category()’
     {}


 60 class jsonpatch_error_category_impl
 61    : public std::error_category
 62 {
 63 public:
 64     constexpr jsonpatch_error_category_impl() noexcept
 65     {}

[danielaparker]

Too soon to try error_categry branch :-)

[andysCaplin]

Yeah -sorry. Got excited. Will try 4.9 if I can get a machine with it installed.

[danielaparker]

While comparing json_error.hpp and jsonpatch_error.hpp, which are otherwise similar, I noticed there was a difference in the order in which the error category class and exception class are defined. I changed jsonpatch_error.hpp to accord with json_error.hpp on master. Before proceeding further, could you download master and see if that changes anything?

Thanks,
Daniel

[andysCaplin]

Yes. I'll test today and get back as soon as I have a result. Thanks.

[andysCaplin]

Sorry, I just found out that we won't be able to test this til next week. As soon as we have tested it - I'll let you know the results. Thanks again for the quick response.

[andysCaplin]

Sorry but the crash still happens. I double checked the code to make sure that I had the latest changes. I printed the version string in the binary but it's 144 and that hasn't changed for a while.

I pulled the latest code today and noticed there are more changes but they don't seem related to the error message issue. I'll test with that as well though and add another note for those results.

Here's the stack trace info

#0  0x0000003ae9a325e5 in raise () from /lib64/libc.so.6
#1  0x0000003ae9a33dc5 in abort () from /lib64/libc.so.6
#2  0x0000000000b38f65 in __gnu_cxx::__verbose_terminate_handler () at ../../../../libstdc++-v3/libsupc++/vterminate.cc:95
#3  0x0000000000b38a76 in __cxxabiv1::__terminate (handler=<optimized out>) at ../../../../libstdc++-v3/libsupc++/eh_terminate.cc:38
#4  0x0000000000b38aa3 in std::terminate () at ../../../../libstdc++-v3/libsupc++/eh_terminate.cc:48
#5  0x0000000000b38cbf in __cxxabiv1::__cxa_pure_virtual () at ../../../../libstdc++-v3/libsupc++/pure.cc:50
#6  0x00000000006c3301 in message (this=<synthetic pointer>) at /usr/include/c++/4.8.5/system_error:158
#7  std::system_error::system_error (this=this@entry=0x7fb7be60a6a0, __ec=...) at /usr/include/c++/4.8.5/system_error:316
#8  0x00000000006e15fe in jsonpatch_error (ec=..., this=0x7fb7be60a6a0, __in_chrg=<optimized out>, __vtt_parm=<optimized out>)
    at ../../libs/jsoncons/include/jsoncons_ext/jsonpatch/jsonpatch_error.hpp:89
#9  jsoncons::jsonpatch::apply_patch<jsoncons::basic_json<char, jsoncons::sorted_policy, std::allocator<char> > > (target=...,
    patch=...) at ../../libs/jsoncons/include/jsoncons_ext/jsonpatch/jsonpatch.hpp:487

#8  0x00000000006e15fe in jsonpatch_error (ec=..., this=0x7fb7be60a6a0, __in_chrg=<optimized out>, __vtt_parm=<optimized out>)
    at ../../libs/jsoncons/include/jsoncons_ext/jsonpatch/jsonpatch_error.hpp:89
89                  : std::system_error(ec)
(gdb) p ec
$2 = (const std::error_code &) @0x7fb7d3ffc870: {_M_value = 1,
  _M_cat = 0xfe3210 <jsoncons::jsonpatch::jsonpatch_error_category()::instance>}

[andysCaplin]

Finally got a build on Red Hat 6 with a later tool chain containing GCC 8.3.1 and it fixes one of the 2 problems - i.e. the crash. This was with a binary with the original jsoncons i.e. without the fixes you implemented.

We still get deltas being misinterpreted as incorrect after shutdown but this is not an issue as we're shutting down anyway so we don't need to process these updates.

[danielaparker]

I don't understand what you mean by "We still get deltas being misinterpreted as incorrect after shutdown". I understand that the line

jsoncons::jsonpatch::apply_patch(jsonob->json, delta);

is throwing an exception. But that line has to be executed in order for the exception to be thrown, why is it being executed during shutdown? In what context is this happening? Can you provide an example?

Daniel

[andysCaplin]

Sure.

We have various threads processing incoming messages. These messages are

• an initial JSON object message ( which we cache ) followed by
• multiple JSON delta messages ( which we apply to the cached object )

These delta messages are all pretty much identically generated from a bench tool and just the values inside are changing - i.e. the deltas we're receiving are always going to be valid.

Up to the point that I shut down no delta messages are logged as being invalid.

When I shut down the binary I can see the log for the shutdown and it's immediately followed by multiple logs saying some received deltas are invalid. There is obviously a period after shutdown when the threads processing the incoming messages are still running, the bench tool is still running and pumping deltas up to the binary and we're still receiving messages and processing them before we completely shut down.

I can see the content of the "invalid" delta messages in the log and they're definitely valid.

For us this isn't such a big issue because it just means we don't process some messages we receive during shutdown and that's not a problem because we're shutting down.

The only minor thing is we have to log the error when it occurs but these deltas aren't invalid so it's a little misleading. But we can tell customers to ignore any of these invalid messages if they occur after the shutdown message.

The other thing is that since the tool upgrade solved the crash I thought it would solve this as well but like I say it's something we can live with.

[andysCaplin]

With the latest code from master ( i.e. with the shutdown fix code ) there is a new memory issue. We're catching and logging the JSON patch error and we get this invalid read issue memory issue. Looks like jsoncons::jsonpatch::jsonpatch_error::what() is being deleted as we access it.

==49586== Invalid read of size 1
==49586==    at 0x4A0BDA0: mempcpy (vg_replace_strmem.c:1517)
==49586==    by 0x315C07453D: _IO_default_xsputn (genops.c:468)
==49586==    by 0x315C04806F: vfprintf (vfprintf.c:1641)
==49586==    by 0x315C06F631: vsnprintf (vsnprintf.c:120)
==49586==    by 0x76D33D: ds_printf_time_ap (log.c:1024)
==49586==    by 0x76E545: ds_log (log.c:1908)
==49586==    by 0x6BC88A: jsonob_process_update(_object*, _ds_data*, update_type_t) (jsonob.cpp:771)


==49586==  Address 0x11b16208 is 24 bytes inside a block of size 59 free'd
==49586==    at 0x4A0660E: operator delete(void*) (vg_replace_malloc.c:576)
==49586==    by 0x6BF0E9: ~basic_string (basic_string.h:539)
==49586==    by 0x6BF0E9: jsoncons::jsonpatch::jsonpatch_error::what() const (jsonpatch_error.hpp:99)
==49586==    by 0x6BC862: jsonob_process_update(_object*, _ds_data*, update_type_t) (jsonob.cpp:771)


==49586==  Block was alloc'd at
==49586==    at 0x4A07BA7: operator new(unsigned long) (vg_replace_malloc.c:334)
==49586==    by 0xB821A8: allocate (new_allocator.h:104)
==49586==    by 0xB821A8: std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (basic_string.tcc:607)
==49586==    by 0x6D08D0: char* std::string::_S_construct<char const*>(char const*, char const*, std::allocator<char> const&, std::forward_iterator_tag) (basic_string.tcc:138)
==49586==    by 0xB83AB7: _S_construct_aux<char const*> (basic_string.h:1725)
==49586==    by 0xB83AB7: _S_construct<char const*> (basic_string.h:1746)
==49586==    by 0xB83AB7: std::basic_string<char, std::char_traits<char>, std::allocator<char> >::basic_string(char const*, std::allocator<char> const&) (basic_string.tcc:215)
==49586==    by 0x6BFF6E: jsoncons::jsonpatch::jsonpatch_error_category_impl::message(int) const (jsonpatch_error.hpp:47)
==49586==    by 0x6BF0D6: message (system_error:158)
==49586==    by 0x6BF0D6: jsoncons::jsonpatch::jsonpatch_error::what() const (jsonpatch_error.hpp:99)
==49586==    by 0x6BC862: jsonob_process_update(_object*, _ds_data*, update_type_t) (jsonob.cpp:771)

The error is all happening on the same line where we log the what() i.e. the ds_log() line of code below

            try {
                jsoncons::jsonpatch::apply_patch(jsonob->json, delta);
...
            } catch (const jsoncons::jsonpatch::jsonpatch_error& e) {
                ds_log(event_log, DS_LOG_NOTIFY, "JSON: <%s> couldn't apply patches from delta <%s> error <%s>\n", obj->name, pkt->fields[0].value, e.what());

This doesn't happen with the 0.144.0 release.

Looks like the message is being deleted before we can use it.

[danielaparker]

This is with gcc 4.8, right? And happening during the shutdown process?

My first suggestion would be to change the code so that the threads are allowed to stop before the shutdown process begins. That would fix everything.

But without that, could you do an experiment? When compiling with gcc 4.8, replace the lines in jsoncons_ext/jsonpatch/json_error.hpp (lines 60-65 in master, or 92-97 in 0.144.0)?

inline
const std::error_category& jmespath_error_category()
{
  static jmespath_error_category_impl instance;
  return instance;
}

to

inline
const std::error_category& jmespath_error_category()
{
  static jmespath_error_category_impl* instance = nullptr;
  if (instance == nullptr)
  {
      instance = new jmespath_error_category_impl();
  }
  return *instance;
}

Thanks,
Daniel

[andysCaplin]

It's RedHat Developer tool set 8.1, gcc version 8.3.1. I'll try that - cheers.

[andysCaplin]

Ok, so that didn't fix the invalid read. I changed this code ( couldn't find jmespath_error_category )

jsonpatch_error.hpp

 60     inline
 61     const std::error_category& jsonpatch_error_category()
 62     {
 63       static jsonpatch_error_category_impl *instance = NULL;
 64       if ( instance == NULL ) {
 65           instance =  new jsonpatch_error_category_impl();
 66       }
 67       return *instance;
 68     }

jsonpath_error.hpp

117     inline
118     const std::error_category& jsonpath_error_category()
119     {
120       static jsonpath_error_category_impl* instance = NULL;
121       if (instance == NULL)
122       {
123           instance = new jsonpath_error_category_impl();
124       }
125       return *instance;
126     }

This issue doesn't happen with 0.144.0

[danielaparker]

Okay, I've reverted the jsonpatch_error.hpp change on master, so it's back to 0.144.0.

The experiment I suggested was only for 4.8. It should have worked around the crash you observed with that compiler during shutdown.

[andysCaplin]

ohh - sorry. I though that was for the invalid read.
0.144.0 doesn't have the invalid read and doesn't have the crash when we build with the newer tools so we're going with that.

[danielaparker]

Fair enough.

We don't currently have test coverage for the situation where threads continue after exiting the main thread, which leads to the possibility of issues with order of de-initialization of static data. I think that the crash you observed was the result of gcc 4.8 std::error_category default constructor not being marked constexpr, and I don't think that you'll see that with gcc 4.9 or later. But there could be other issues. On the one hand, I still suggest that you change your code so that the threads are allowed to stop before exiting the main thread. But on the other hand, we'll continue to look into making the library as robust as possible, and expand test coverage accordingly.