Mashape Analytics refused the batch

[vmercierfr]

We have an issue with Kong 0.4.2 and Mashape Analytics plugin.
When we enable the Mashape Analytics plugin, there is lots of errors in Kong error log file:

2015/08/19 23:10:05 [error] 5078#0: [lua] buffer.lua:164: [mashape-analytics] socket server refused the batch. Status: (503) Error: (), context: ngx.timer, client: ######, server: 0.0.0.0:80

We have some data in Mashape Analytics website but i don't if all request was logged.
We disabled the Mashape Analytics plugin to avoid problems, what can we do to debug it?

Thanks.

Full logs:

2015/08/19 22:53:34 [notice] 5044#0: signal process started
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:74: init_plugins(): Discovering used plugins
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: ssl
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: keyauth
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: basicauth
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: oauth2
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: ratelimiting
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: tcplog
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: udplog
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: filelog
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: httplog
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: cors
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: request_transformer
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: response_transformer
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: requestsizelimiting
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: ip_restriction
2015/08/19 22:53:34 [notice] 5076#0: [lua] kong.lua:94: init_plugins(): Loading plugin: mashape-analytics
2015/08/19 23:10:05 [error] 5078#0: [lua] buffer.lua:164: send_batch(): [mashape-analytics] socket server refused the batch. Status: (504) Error: (), context: ngx.timer, client: ######, server: 0.0.0.0:80
2015/08/19 23:10:05 [error] 5078#0: [lua] buffer.lua:164: [mashape-analytics] socket server refused the batch. Status: (503) Error: (), context: ngx.timer, client: ######, server: 0.0.0.0:80
2015/08/19 23:10:05 [error] 5078#0: [lua] buffer.lua:164: [mashape-analytics] socket server refused the batch. Status: (503) Error: (), context: ngx.timer, client: ######, server: 0.0.0.0:80
[...]

[vmercierfr]

We also have this message in Kong error log file:

2015/08/19 23:10:09 [error] 5078#0: 665 failed to run log_by_lua: ...local/share/lua/5.1/kong/plugins/log_serializers/alf.lua:131: requesty body in temp file not supported
stack traceback:
[C]: in function 'get_post_args'
...local/share/lua/5.1/kong/plugins/log_serializers/alf.lua:131: in function 'serialize_entry'
...local/share/lua/5.1/kong/plugins/log_serializers/alf.lua:170: in function 'new_alf'
...share/lua/5.1/kong/plugins/mashape-analytics/handler.lua:71: in function 'log'
/usr/local/share/lua/5.1/kong.lua:247: in function 'exec_plugins_log'
log_by_lua(nginx.conf:106):1: in function <log_by_lua(nginx.conf:106):1> while logging request, client: #####, server: _, request: "POST ##### HTTP/1.1", upstream: "http://#####", host: "#####"

[samek]

We have many of those..
2015/08/20 14:07:07 [error] 52#0: [lua] buffer.lua:164: [mashape-analytics] socket server refused the batch. Status: (504) Error: (), context: ngx.timer, client: 91.185.xxx.xxx, server: 0.0.0.0:8000

[thibaultcha]

All those have been fixed in #471, but we're still waiting for it to be released...

[thibaultcha]

(Oh, on a side note, 5xx errors would be caused by the analytics server)

[thibaultcha]

Sorry I was on my phone earlier. At this point I feel like I should describe how the plugin works, because you seem to worry about losing some data.

If the plugin receives a 5xx error from mashape analytics (in this case, the socket server needs to scale up and it is apparently taking some time), the batch is not discarded, and will be tried again later. The plugin only logs errors by default. If you want to see the successes (including how many requests were sent to mashape analytics) you'll have to change the nginx log level to debug.

@vmercierfr You are experiencing the other error because that request's body was bigger than the configured client_body_buffer_size. Hence the body is written to a temporary file and the plugin cannot access it. #471 catches this error and explains why it is happening (yet to be released).

[vmercierfr]

Thanks for your help.

[thibaultcha]

I will close this if you don't mind, keeping in mind that batches are not lost and once mashape analytics has scaled up, the batch will be processed. As well as #471 soon bringing a stronger buffer.