Http: Add verbose option to http() destination #1526

mitzkia · 2017-06-11T13:46:48Z

verbose() option:

default value: no

Without this option syslog-ng can not log verbose logs of libcurl module which can be very useful sometimes.
Let see some syslog-ng console examples

http connection with verbose(no):

[2017-06-11T15:34:02.049183] Syslog connection accepted; fd='15', client='AF_INET(127.0.0.1:57090)', local='AF_INET(127.0.0.1:10001)'
[2017-06-11T15:34:02.050122] Incoming log entry; line='<38>2017-06-11T15:34:02 localhost prg00000[1234]: seq: 0000000000, thread: 0000, runid: 1497188042, stamp: 2017-06-11T15:34:02 PADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADD'
[2017-06-11T15:34:02.050427] Setting value; msg='0x7f773c014600', name='HOST_FROM', value='localhost'
[2017-06-11T15:34:02.050466] Setting value; msg='0x7f773c014600', name='HOST', value='localhost'
[2017-06-11T15:34:02.050497] Setting value; msg='0x7f773c014600', name='SOURCE', value='s_network'
[2017-06-11T15:34:02.050591] EOF occurred while reading; fd='15'
[2017-06-11T15:34:02.051316] Syslog connection closed; fd='15', client='AF_INET(127.0.0.1:57090)', local='AF_INET(127.0.0.1:10001)'
[2017-06-11T15:34:02.051524] Closing log transport fd; fd='15'

http connection with verbose(yes):

[2017-06-11T15:35:28.431368] Syslog connection accepted; fd='14', client='AF_INET(127.0.0.1:57106)', local='AF_INET(127.0.0.1:10001)'
[2017-06-11T15:35:28.431629] Incoming log entry; line='<38>2017-06-11T15:35:28 localhost prg00000[1234]: seq: 0000000000, thread: 0000, runid: 1497188128, stamp: 2017-06-11T15:35:28 PADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADD'
[2017-06-11T15:35:28.431799] Setting value; msg='0x7f713c014600', name='HOST_FROM', value='localhost'
[2017-06-11T15:35:28.431820] Setting value; msg='0x7f713c014600', name='HOST', value='localhost'
[2017-06-11T15:35:28.431845] Setting value; msg='0x7f713c014600', name='SOURCE', value='s_network'
[2017-06-11T15:35:28.431883] EOF occurred while reading; fd='14'
[2017-06-11T15:35:28.431954] Syslog connection closed; fd='14', client='AF_INET(127.0.0.1:57106)', local='AF_INET(127.0.0.1:10001)'
[2017-06-11T15:35:28.432070] Closing log transport fd; fd='14'
* Rebuilt URL to: http://127.0.0.1:8080/
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0)
> PUT / HTTP/1.1
Host: 127.0.0.1:8080
User-Agent: syslog-ng 3.9.1/libcurl 7.52.1
Accept: */*
X-Syslog-Host: localhost
X-Syslog-Program: prg00000
X-Syslog-Facility: auth
X-Syslog-Level: info
Content-Length: 205
Content-Type: application/x-www-form-urlencoded

* upload completely sent off: 205 out of 205 bytes
< HTTP/1.1 200 OK
< Date: Sun, 11 Jun 2017 13:35:28 GMT
< Connection: keep-alive
< Content-Length: 21
< 
* Curl_http_done: called premature == 0
* Connection #0 to host 127.0.0.1 left intact

https connection with verbose(no), where connection not established:

[2017-06-11T15:42:19.994985] Syslog connection accepted; fd='15', client='AF_INET(127.0.0.1:57176)', local='AF_INET(127.0.0.1:10001)'
[2017-06-11T15:42:19.995393] Incoming log entry; line='<38>2017-06-11T15:42:19 localhost prg00000[1234]: seq: 0000000000, thread: 0000, runid: 1497188539, stamp: 2017-06-11T15:42:19 PADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADD'
[2017-06-11T15:42:19.995691] Setting value; msg='0x7f86a4014600', name='HOST_FROM', value='localhost'
[2017-06-11T15:42:19.995730] Setting value; msg='0x7f86a4014600', name='HOST', value='localhost'
[2017-06-11T15:42:19.995767] Setting value; msg='0x7f86a4014600', name='SOURCE', value='s_network'
[2017-06-11T15:42:19.995832] EOF occurred while reading; fd='15'
[2017-06-11T15:42:19.995986] Syslog connection closed; fd='15', client='AF_INET(127.0.0.1:57176)', local='AF_INET(127.0.0.1:10001)'
[2017-06-11T15:42:19.996103] Closing log transport fd; fd='15'
[2017-06-11T15:42:20.036565] curl: error sending HTTP request; error='SSL peer certificate or SSH remote key was not OK'

https connection with verbose(yes), where connection not established:

[2017-06-11T15:42:53.138827] Syslog connection accepted; fd='15', client='AF_INET(127.0.0.1:57182)', local='AF_INET(127.0.0.1:10001)'
[2017-06-11T15:42:53.139332] Incoming log entry; line='<38>2017-06-11T15:42:53 localhost prg00000[1234]: seq: 0000000000, thread: 0000, runid: 1497188573, stamp: 2017-06-11T15:42:53 PADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADDPADD'
[2017-06-11T15:42:53.139628] Setting value; msg='0x7f2cb4014600', name='HOST_FROM', value='localhost'
[2017-06-11T15:42:53.139667] Setting value; msg='0x7f2cb4014600', name='HOST', value='localhost'
[2017-06-11T15:42:53.139703] Setting value; msg='0x7f2cb4014600', name='SOURCE', value='s_network'
[2017-06-11T15:42:53.139766] EOF occurred while reading; fd='15'
[2017-06-11T15:42:53.139932] Syslog connection closed; fd='15', client='AF_INET(127.0.0.1:57182)', local='AF_INET(127.0.0.1:10001)'
* Rebuilt URL to: https://127.0.0.1:4433/
[2017-06-11T15:42:53.140073] Closing log transport fd; fd='15'
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to 127.0.0.1 (127.0.0.1) port 4433 (#0)
* found 1 certificates in /home/micek/original_ssl_copied_dir/nodejs_http_server2/ca-crt.pem
* found 2 certificates in /home/micek/original_ssl_copied_dir/nodejs_http_server2/
* ALPN, offering http/1.1
* SSL connection using TLS1.2 / ECDHE_RSA_AES_128_GCM_SHA256
* 	 server certificate verification OK
* 	 server certificate status verification SKIPPED
* SSL: certificate subject name (server) does not match target host name '127.0.0.1'
* Curl_http_done: called premature == 1
* Closing connection 0
[2017-06-11T15:42:53.181338] curl: error sending HTTP request; error='SSL peer certificate or SSH remote key was not OK'

kira-syslogng · 2017-06-11T13:57:21Z

Build SUCCESS, the tests were executed on test branch: master and test suite: functions

bazsi · 2017-06-12T04:38:35Z

This is useful indeed, however it'd be great if

it'd be controlled by syslog-ng's own debug switch and not by an explicit option
it could be integrated into syslog-ng's own message handling

The first should be easy, the 2nd us only possible if libcurl has an API for it.

Bazsi

mitzkia · 2017-06-12T07:04:44Z

@bazsi Thank you for your comment.
For the 1st I would need some existing example from code base (if there is). Or some hint what should I check.
For the 2nd I would ask some help what kind of API should we need from libcurl.

furiel · 2017-06-13T06:15:21Z

@bazsi I am a bit afraid that when verbose is on, this would generate too much logs. Those large chunks are printed per message. We might link this to trace level, else I would leave the possibility to overwrite verbosity per destination. What do you think?

@mitzkia It seems libcurl supports some way to provide of own debug log implementation. You can find an example here:
https://curl.haxx.se/libcurl/c/http2-download.html
Though me seems very challenging to use. Maybe there is a hint in libcurl implementation how to assemble the same verbose logs that we can see above.

bazsi · 2017-06-13T06:20:38Z

debug is debug, and it emits a lots of details already. If it doesn't have too much overhead on production (e.g. debug disabled, I'd let it flow :) for example, we now emit a debug level message for every name-value pair that is changed. THAT generates huge amounts of messages.

…

-- Bazsi

On Tue, Jun 13, 2017 at 8:15 AM, furiel ***@***.***> wrote: @bazsi <https://github.com/bazsi> I am a bit afraid that when verbose is on, this would generate too much logs. Those large chunks are printed per message. We might link this to trace level, else I would leave the possibility to overwrite verbosity per destination. What do you think? @mitzkia <https://github.com/mitzkia> It seems libcurl supports some way to provide of own debug log implementation. You can find an example here: https://curl.haxx.se/libcurl/c/http2-download.html Though me seems very challenging to use. Maybe there is a hint in libcurl implementation how to assemble the same verbose logs that we can see above. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#1526 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AArldvuoz1vVkP21VNdqJgMqvnh26as9ks5sDij5gaJpZM4N2ZgX> .

bazsi

we should not use destination specific options, as discused in the comments.

kira-syslogng · 2017-08-18T14:47:57Z

Build SUCCESS, the tests were executed on test branch: master and test suite: functions

kira-syslogng · 2017-08-21T07:25:13Z

Build SUCCESS, the tests were executed on test branch: master and test suite: functions

furiel · 2017-08-30T09:09:35Z

modules/http/http.c

+  if (!G_UNLIKELY(debug_flag))
+    return 0;
+
+  if (type >= sizeof(curl_infotype_to_text)/sizeof(curl_infotype_to_text[0]))


Please change this to an assert.

Thanks for the note. Fixed

furiel · 2017-08-30T09:10:45Z

modules/http/http.c

+      sanitized[i] = g_ascii_isprint(data[i]) ? data[i] : '.';
+    }
+  sanitized[i] = 0;
+  msg_debug(text, evt_tag_str("data", sanitized));


Please change the first parameter of msg_debug to something literal instead of a variable. Something like curl_debug.
The text should go into evt_tag_str.

Thanks for the note. Fixed.

kira-syslogng · 2017-09-05T11:17:27Z

Build FAILURE, the tests were executed on test branch: master and test suite: functions

kira-syslogng · 2017-09-05T14:28:42Z

Build SUCCESS, the tests were executed on test branch: master and test suite: functions

MrAnno · 2017-09-06T09:04:48Z

modules/http/http.c

+    }
+  sanitized[i] = 0;
+  msg_debug("curl trace log",
+            evt_tag_str("curl info type", text),


Please use underscores here.

Thanks for the note, I have fixed it.

kira-syslogng · 2017-09-07T04:44:20Z

Build SUCCESS, the tests were executed on test branch: master and test suite: functions

* using --debug on sbin/syslog-ng or debug --set=on on sbin/syslog-ng-ctl libcurl will display verbose logs Signed-off-by: Antal Nemes <antal.nemes@balabit.com> Signed-off-by: Andras Mitzki <andras.mitzki@balabit.com>

kira-syslogng · 2017-09-12T13:31:30Z

Build SUCCESS, the tests were executed on test branch: master and test suite: functions

mitzkia added the in progress label Jun 11, 2017

mitzkia requested review from bazsi and removed request for bazsi June 11, 2017 13:50

furiel approved these changes Jun 11, 2017

View reviewed changes

bazsi suggested changes Jun 21, 2017

View reviewed changes

presidento added the enhancement label Jul 25, 2017

mitzkia force-pushed the verbose-option-for-http branch from 03d7c84 to efc87b3 Compare August 18, 2017 14:31

mitzkia force-pushed the verbose-option-for-http branch from efc87b3 to 5a0e09b Compare August 21, 2017 07:09

furiel reviewed Sep 4, 2017

View reviewed changes

mitzkia force-pushed the verbose-option-for-http branch from 5a0e09b to 764dc74 Compare September 5, 2017 11:04

mitzkia force-pushed the verbose-option-for-http branch from 764dc74 to d932f1c Compare September 5, 2017 14:14

MrAnno reviewed Sep 6, 2017

View reviewed changes

mitzkia force-pushed the verbose-option-for-http branch from d932f1c to f7305d2 Compare September 7, 2017 04:31

mitzkia force-pushed the verbose-option-for-http branch from f7305d2 to 2f8008d Compare September 12, 2017 13:18

furiel merged commit 8aabf43 into syslog-ng:master Sep 13, 2017

lbudai removed the in progress label Sep 13, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Http: Add verbose option to http() destination #1526

Http: Add verbose option to http() destination #1526

mitzkia commented Jun 11, 2017

kira-syslogng commented Jun 11, 2017

bazsi commented Jun 12, 2017

mitzkia commented Jun 12, 2017

furiel commented Jun 13, 2017

bazsi commented Jun 13, 2017 via email

bazsi left a comment

kira-syslogng commented Aug 18, 2017

kira-syslogng commented Aug 21, 2017

furiel Aug 30, 2017

mitzkia Sep 5, 2017

furiel Aug 30, 2017

mitzkia Sep 5, 2017

kira-syslogng commented Sep 5, 2017

kira-syslogng commented Sep 5, 2017

MrAnno Sep 6, 2017

mitzkia Sep 7, 2017

kira-syslogng commented Sep 7, 2017

kira-syslogng commented Sep 12, 2017

Http: Add verbose option to http() destination #1526

Http: Add verbose option to http() destination #1526

Conversation

mitzkia commented Jun 11, 2017

kira-syslogng commented Jun 11, 2017

bazsi commented Jun 12, 2017

mitzkia commented Jun 12, 2017

furiel commented Jun 13, 2017

bazsi commented Jun 13, 2017 via email

bazsi left a comment

Choose a reason for hiding this comment

kira-syslogng commented Aug 18, 2017

kira-syslogng commented Aug 21, 2017

furiel Aug 30, 2017

Choose a reason for hiding this comment

mitzkia Sep 5, 2017

Choose a reason for hiding this comment

furiel Aug 30, 2017

Choose a reason for hiding this comment

mitzkia Sep 5, 2017

Choose a reason for hiding this comment

kira-syslogng commented Sep 5, 2017

kira-syslogng commented Sep 5, 2017

MrAnno Sep 6, 2017

Choose a reason for hiding this comment

mitzkia Sep 7, 2017

Choose a reason for hiding this comment

kira-syslogng commented Sep 7, 2017

kira-syslogng commented Sep 12, 2017