ES-5x : JsonGenerationException in slow logs

Hi,
As part of slow query investigation, we enabled search slow logs in our production environment[ES version - 5.4.1]. In few cases, i do see the original slow query getting logged. But there were many occurrences of JsonGenerationException as seen below. Could someone help understand the cases when we would encounter this?

[2017-11-20T11:35:32,917][WARN ][index.search.slowlog.query] [es-d11-rm] [sharedindex][10] took[12.5s], took_millis[12544], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:35:42,521][WARN ][index.search.slowlog.query] [es-d11-rm] [sharedindex][3] took[22.1s], took_millis[22158], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:47:26,846][INFO ][index.search.slowlog.query] [es-d11-rm] [sharedindex][3] took[6.3s], took_millis[6330], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:48:27,842][INFO ][index.search.slowlog.query] [es-d11-rm] [sharedindex][3] took[6.9s], took_millis[6932], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:48:45,656][INFO ][index.search.slowlog.query] [es-d11-rm] [sharedindex][6] took[9.1s], took_millis[9168], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:48:57,620][WARN ][index.search.slowlog.query] [es-d11-rm] [sharedindex][9] took[21.1s], took_millis[21121], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:49:08,569][WARN ][index.search.slowlog.query] [es-d11-rm] [sharedindex][2] took[32s], took_millis[32080], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:50:59,729][INFO ][index.search.slowlog.query] [es-d11-rm] [sharedindex][3] took[6.8s], took_millis[6898], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:56:02,530][WARN ][index.search.slowlog.query] [es-d11-rm] [sharedindex][9] took[10.1s], took_millis[10146], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:56:05,265][WARN ][index.search.slowlog.query] [es-d11-rm] [sharedindex][2] took[12.8s], took_millis[12872], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:56:17,629][WARN ][index.search.slowlog.query] [es-d11-rm] [sharedindex][3] took[25.2s], took_millis[25239], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:56:17,629][WARN ][index.search.slowlog.query] [es-d11-rm] [sharedindex][3] took[10.7s], took_millis[10724], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T11:56:25,755][INFO ][index.search.slowlog.query] [es-d11-rm] [sharedindex][10] took[5.3s], took_millis[5360], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T12:08:41,808][WARN ][index.search.slowlog.query] [es-d11-rm] [sharedindex][2] took[16.2s], took_millis[16216], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T12:08:47,168][WARN ][index.search.slowlog.query] [es-d11-rm] [sharedindex][9] took[21.5s], took_millis[21578], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}],
[2017-11-20T12:08:58,130][INFO ][index.search.slowlog.query] [es-d11-rm] [sharedindex][3] took[5.3s], took_millis[5330], types[documentcontract], stats[], search_type[QUERY_THEN_FETCH], total_shards[6], source[{ "error" : "JsonGenerationException[Can not start an object, expecting field name (context: Object)]"}]

Thanks,
Divya Malini

This looks like a bug. By any chance, would you be able to find one query that triggers this bug? It would help identify it and then fix it.

I enabled the logs to get the actual query. Anyway i ll try to get the query and share, even otherwise could you please take a look ?

Hi Adrien,
I am unable to get the original query yet. Could the number of chars in the request contribute to this exception? Our request would easily exceed 32767 in some cases, if this would help you narrow to the bug causing this exception.

Thanks,
Divya

Any help here? I was expecting to get the original query by enabling the slow logs. But I am constantly getting this exception.
To add details - we are in NEST 2.x and ES 5.4.1

I did the following to reproduce the exception locally.

Had the search slow logs settings as follows

PUT _all/_settings
{
"index.search.slowlog.threshold.query.warn": "1ms",
"index.search.slowlog.threshold.query.info": "1ms",
"index.search.slowlog.threshold.fetch.warn": "1ms",
"index.search.slowlog.threshold.fetch.info": "1ms"
}

And executed a sample query that mimics our actual query. Please find the query below

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.