Re: truncated request in log lines

[Willy Tarreau]

On Thu, May 18, 2017 at 08:58:41AM +0200, Stéphane Cottin wrote:
> commit 7fb383cbfb42e58dc7764425bc5b1c3c11a111dc
> Author: Stephane Cottin 
> Date:   Thu May 18 08:41:06 2017 +0200
> 
> MINOR: Add logurilen tunable.
(...)

Now merged, thank you Stéphane.

Willy

Re: truncated request in log lines

[Willy Tarreau]

On Thu, May 18, 2017 at 08:58:41AM +0200, Stéphane Cottin wrote:
> > Nice, that was fast :-)
> 
> Nobody have time, I just take care of things as they flow :)

you're right!

> Sorry, I didn't read the CONTRIBUTING, RTFM me.

no pb.

> Hope this one is better.

Definitely. The most suitable form is the git-format-patch, which we
can easily apply using git-am. But this one has everything I need so
I'll apply it.

Thank you!
Willy

Re: truncated request in log lines

[Stéphane Cottin]

On 18 May 2017, at 6:36, Willy Tarreau wrote:

> Hi Stéphane,
>
> On Thu, May 18, 2017 at 02:31:07AM +0200, Stéphane Cottin wrote:
>> patch attached.
>
> Nice, that was fast :-)

Nobody have time, I just take care of things as they flow :)

>
> The patch looks pretty good. Just two things :
>   - please provide the commit message with your patch ; please have a
> look at CONTRIBUTING, we have a few rules on the formating that
> help with maintenance ;
>
>   - no need to touch the CHANGELOG, it will be automatically updated
> on next release (I should add this to the CONTRIBUTING doc); but
> don't worry I can drop it when applying, no need to re-spin it
> just for this.

Sorry, I didn't read the CONTRIBUTING, RTFM me.

Hope this one is better.

Stéphane

>
> Thanks!
> Willy
commit 7fb383cbfb42e58dc7764425bc5b1c3c11a111dc
Author: Stéphane Cottin 
Date:   Thu May 18 08:41:06 2017 +0200

MINOR: Add logurilen tunable.

The default len of request uri in log messages is 1024. In some
use cases, you need to keep the long trail of GET parameters.
The only way to increase this len is to recompile with
DEFINE=-DREQURI_LEN=2048
This commit introduce a tune.http.logurilen configuration
directive, allowing to tune this at runtime.

diff --git a/doc/configuration.txt b/doc/configuration.txt
index edd9e79b..cff91c59 100644
--- a/doc/configuration.txt
+++ b/doc/configuration.txt
@@ -597,6 +597,7 @@ The following keywords are supported in the "global" 
section :
- tune.chksize
- tune.comp.maxlevel
- tune.http.cookielen
+   - tune.http.logurilen
- tune.http.maxhdr
- tune.idletimer
- tune.lua.forced-yield
@@ -758,7 +759,8 @@ log  [len ] [format ]  
[max level [min level]
truncate them before sending them. Accepted values are 80 to 65535
inclusive. The default value of 1024 is generally fine for all
standard usages. Some specific cases of long captures or
-   JSON-formated logs may require larger values.
+   JSON-formated logs may require larger values. You may also need to
+   increase "tune.http.logurilen" if your request uris are truncated.
 
is the log format used when generating syslog messages. It may be
one of the following :
@@ -1324,6 +1326,14 @@ tune.http.cookielen 
   When not specified, the limit is set to 63 characters. It is recommended not
   to change this value.
 
+tune.http.logurilen 
+  Sets the maximum length of request uri in logs. This prevent to truncate long
+  requests uris with valuable query strings in log lines. This is not related
+  to syslog limits. If you increase this limit, you may also increase the
+  'log ... len ' parameter. Your syslog deamon may also need specific
+  configuration directives too.
+  The default value is 1024.
+
 tune.http.maxhdr 
   Sets the maximum number of headers in a request. When a request comes with a
   number of headers greater than this value (including the first line), it is
diff --git a/include/common/defaults.h b/include/common/defaults.h
index 81dc3b16..f53c611e 100644
--- a/include/common/defaults.h
+++ b/include/common/defaults.h
@@ -273,7 +273,7 @@
 #define STREAM_MAX_COST (sizeof(struct stream) + \
   2 * sizeof(struct channel) + \
   2 * sizeof(struct connection) + \
-  REQURI_LEN + \
+  global.tune.requri_len + \
   2 * global.tune.cookie_len)
 #endif
 
diff --git a/include/types/global.h b/include/types/global.h
index 57b969dd..b35b4f1f 100644
--- a/include/types/global.h
+++ b/include/types/global.h
@@ -139,6 +139,7 @@ struct global {
int chksize;   /* check buffer size in bytes, defaults to 
BUFSIZE */
int pipesize;  /* pipe size in bytes, system defaults if 
zero */
int max_http_hdr;  /* max number of HTTP headers, use 
MAX_HTTP_HDR if zero */
+   int requri_len;/* max len of request URI, use REQURI_LEN if 
zero */
int cookie_len;/* max length of cookie captures */
int pattern_cache; /* max number of entries in the pattern 
cache. */
int sslcachesize;  /* SSL cache size in session, defaults to 
2 */
diff --git a/src/cfgparse.c b/src/cfgparse.c
index f1673219..40cd606d 100644
--- a/src/cfgparse.c
+++ b/src/cfgparse.c
@@ -888,6 +888,16 @@ int cfg_parse_global(const char *file, int linenum, char 
**args, int kwm)
}
global.tune.cookie_len = atol(args[1]) + 1;
}
+   else if (!strcmp(args[0], "tune.http.logurilen")) {
+   if (alertif_too_many_args(1, file, linenum, args, _code))
+   goto out;
+   if (*(args[1]) == 0) {
+   Alert("parsing [%s:%d] : '%s' expects an integer 
argument.\n", file, linenum, args[0]);
+ 

Re: truncated request in log lines

[Willy Tarreau]

Hi Stéphane,

On Thu, May 18, 2017 at 02:31:07AM +0200, Stéphane Cottin wrote:
> patch attached.

Nice, that was fast :-)

The patch looks pretty good. Just two things :
  - please provide the commit message with your patch ; please have a
look at CONTRIBUTING, we have a few rules on the formating that
help with maintenance ;

  - no need to touch the CHANGELOG, it will be automatically updated
on next release (I should add this to the CONTRIBUTING doc); but
don't worry I can drop it when applying, no need to re-spin it
just for this.

Thanks!
Willy

Re: truncated request in log lines

[Stéphane Cottin]

Hi Willy,

On 17 May 2017, at 20:54, Willy Tarreau wrote:


Hi Stéphane,

On Wed, May 17, 2017 at 02:03:26AM +0200, Stéphane Cottin wrote:
Thanks, this is the right answer, recompile with 
DEFINE=-DREQURI_LEN=4096

fixes this issue.


that's what I was going to say :-)

This limit should be raised at runtime according to the log "len" 
option, if

you want long log lines, you want them complete :)


In fact no, but we should have a global tunable for it now. The reason 
why
we recommend to always keep the URI last is to ensure logs can safely 
be
truncated at the least interesting place, because for most users, the 
long
trail of query string arguments are mostly useless, while for 
captures,

states and timers there is no compromise.

If you have the time to provide a patch doing this, that's clearly 
something
we could merge. It's not too hard, REQURI_LEN is used at only a few 
places.
You could have global.requri_len which would be set using 
tune.http.log_uri_len

for example.

Best regards,
Willy


patch attached.

Stéphanediff --git a/CHANGELOG b/CHANGELOG
index 40d24d44..0db5e7ae 100644
--- a/CHANGELOG
+++ b/CHANGELOG
@@ -2,6 +2,7 @@ ChangeLog :
 ===
 
 2017/04/03 : 1.8-dev1
+- MINOR: Add tune.http.logurilen
 - BUG/MEDIUM: proxy: return "none" and "unknown" for unknown LB algos
 - BUG/MINOR: stats: make field_str() return an empty string on NULL
 - DOC: Spelling fixes
diff --git a/doc/configuration.txt b/doc/configuration.txt
index edd9e79b..cff91c59 100644
--- a/doc/configuration.txt
+++ b/doc/configuration.txt
@@ -597,6 +597,7 @@ The following keywords are supported in the "global" 
section :
- tune.chksize
- tune.comp.maxlevel
- tune.http.cookielen
+   - tune.http.logurilen
- tune.http.maxhdr
- tune.idletimer
- tune.lua.forced-yield
@@ -758,7 +759,8 @@ log  [len ] [format ]  
[max level [min level]
truncate them before sending them. Accepted values are 80 to 65535
inclusive. The default value of 1024 is generally fine for all
standard usages. Some specific cases of long captures or
-   JSON-formated logs may require larger values.
+   JSON-formated logs may require larger values. You may also need to
+   increase "tune.http.logurilen" if your request uris are truncated.
 
is the log format used when generating syslog messages. It may be
one of the following :
@@ -1324,6 +1326,14 @@ tune.http.cookielen 
   When not specified, the limit is set to 63 characters. It is recommended not
   to change this value.
 
+tune.http.logurilen 
+  Sets the maximum length of request uri in logs. This prevent to truncate long
+  requests uris with valuable query strings in log lines. This is not related
+  to syslog limits. If you increase this limit, you may also increase the
+  'log ... len ' parameter. Your syslog deamon may also need specific
+  configuration directives too.
+  The default value is 1024.
+
 tune.http.maxhdr 
   Sets the maximum number of headers in a request. When a request comes with a
   number of headers greater than this value (including the first line), it is
diff --git a/include/common/defaults.h b/include/common/defaults.h
index 81dc3b16..f53c611e 100644
--- a/include/common/defaults.h
+++ b/include/common/defaults.h
@@ -273,7 +273,7 @@
 #define STREAM_MAX_COST (sizeof(struct stream) + \
   2 * sizeof(struct channel) + \
   2 * sizeof(struct connection) + \
-  REQURI_LEN + \
+  global.tune.requri_len + \
   2 * global.tune.cookie_len)
 #endif
 
diff --git a/include/types/global.h b/include/types/global.h
index 57b969dd..b35b4f1f 100644
--- a/include/types/global.h
+++ b/include/types/global.h
@@ -139,6 +139,7 @@ struct global {
int chksize;   /* check buffer size in bytes, defaults to 
BUFSIZE */
int pipesize;  /* pipe size in bytes, system defaults if 
zero */
int max_http_hdr;  /* max number of HTTP headers, use 
MAX_HTTP_HDR if zero */
+   int requri_len;/* max len of request URI, use REQURI_LEN if 
zero */
int cookie_len;/* max length of cookie captures */
int pattern_cache; /* max number of entries in the pattern 
cache. */
int sslcachesize;  /* SSL cache size in session, defaults to 
2 */
diff --git a/src/cfgparse.c b/src/cfgparse.c
index f1673219..40cd606d 100644
--- a/src/cfgparse.c
+++ b/src/cfgparse.c
@@ -888,6 +888,16 @@ int cfg_parse_global(const char *file, int linenum, char 
**args, int kwm)
}
global.tune.cookie_len = atol(args[1]) + 1;
}
+   else if (!strcmp(args[0], "tune.http.logurilen")) {
+   if (alertif_too_many_args(1, file, linenum, args, _code))
+   goto out;
+   if (*(args[1]) == 0) {
+ 

Re: truncated request in log lines

[Willy Tarreau]

Hi Stéphane,

On Wed, May 17, 2017 at 02:03:26AM +0200, Stéphane Cottin wrote:
> Thanks, this is the right answer, recompile with DEFINE=-DREQURI_LEN=4096
> fixes this issue.

that's what I was going to say :-)

> This limit should be raised at runtime according to the log "len" option, if
> you want long log lines, you want them complete :)

In fact no, but we should have a global tunable for it now. The reason why
we recommend to always keep the URI last is to ensure logs can safely be
truncated at the least interesting place, because for most users, the long
trail of query string arguments are mostly useless, while for captures,
states and timers there is no compromise.

If you have the time to provide a patch doing this, that's clearly something
we could merge. It's not too hard, REQURI_LEN is used at only a few places.
You could have global.requri_len which would be set using tune.http.log_uri_len
for example.

Best regards,
Willy

Re: truncated request in log lines

[Stéphane Cottin]

Thanks, this is the right answer, recompile with 
DEFINE=-DREQURI_LEN=4096 fixes this issue.
This limit should be raised at runtime according to the log "len" 
option, if you want long log lines, you want them complete :)


Thanks again.
Stéphane


On 16 May 2017, at 19:29, J. Kendzorra wrote:


On 16.05.2017 19:23, J. Kendzorra wrote:

On 16.05.2017 15:58, Stéphane Cottin wrote:

Only the content of "GET /?test=my_very_long_request_truncated" is
truncated to 1024 characters, not the whole line.
The end quote is still present, it does not seems related to syslog
daemon limitations.


I think you're looking for this thread:
http://marc.info/?t=14033356971=1=2


... and pro'ly this one, too :)
http://marc.info/?t=14333217201=1=2

Regards,
J.

Re: truncated request in log lines

[J. Kendzorra]

On 16.05.2017 19:23, J. Kendzorra wrote:
> On 16.05.2017 15:58, Stéphane Cottin wrote:
>> Only the content of "GET /?test=my_very_long_request_truncated" is
>> truncated to 1024 characters, not the whole line.
>> The end quote is still present, it does not seems related to syslog
>> daemon limitations.
> 
> I think you're looking for this thread:
> http://marc.info/?t=14033356971=1=2

... and pro'ly this one, too :)
http://marc.info/?t=14333217201=1=2

Regards,
J.

Re: truncated request in log lines

[J. Kendzorra]

On 16.05.2017 15:58, Stéphane Cottin wrote:
> Only the content of "GET /?test=my_very_long_request_truncated" is
> truncated to 1024 characters, not the whole line.
> The end quote is still present, it does not seems related to syslog
> daemon limitations.

I think you're looking for this thread:
http://marc.info/?t=14033356971=1=2

Regards,
J.

Re: truncated request in log lines

[Stéphane Cottin]

Hi mark,

Thanks for this link, but I guess this is not related to this issue.

Let's use an example.

A log line with method+request+protocol < 1024 characters and a very 
long captured header is ok :


172.17.0.1:38318 [16/May/2017:08:00:31.266] abcde fghij 0/0/106/139/268 
200 9 - -  1/1/0/0/0 0/0 
{ONE_CAPURED_HEADER|ANOTHER_HEADER|A_2048_CHAR_LONG_HEADER} "GET / 
HTTP/1.1"


when method+request+protocol > 1024 characters the log line is still 
valid, but the request is truncated:


172.17.0.1:38318 [16/May/2017:08:00:31.266] abcde fghij 0/0/106/139/268 
200 9 - -  1/1/0/0/0 0/0 {ONE_CAPURED_HEADER|ANOTHER_HEADER| 
A_2048_CHAR_LONG_HEADER} "GET /?test=my_very_long_request_truncated"


Only the content of "GET /?test=my_very_long_request_truncated" is 
truncated to 1024 characters, not the whole line.
The end quote is still present, it does not seems related to syslog 
daemon limitations.


Stéphane


On 16 May 2017, at 14:16, Mark Staudinger wrote:


Hi Stéphane,

On some OSes, including FreeBSD, the syslogd daemon has a hard-coded 
line length of 1024 characters.


Your log daemon may support run-time or configuration options to 
extend this limit.  So you can either use another log daemon, or 
re-compile syslogd with a higher limit, here's one example:


http://bsdpants.blogspot.com/2010/08/truncated-syslog-messages.html

Cheers,
-Mark


On Tue, 16 May 2017 07:28:30 -0400, Stéphane Cottin 
 wrote:



Hi,

Version: haproxy 1.7.2

I'm logging to a unix socket, allowing long lines.

   log /dev/log len 8192 local0
[...]
   option dontlognull
   option log-separate-errors
   option httplog

I'm also capturing the referer header.

   capture request header Referer len 4096

When using large strings (length > 1024 ) the request is truncated to 
1024 characters in the log line, the captured header is not.
The log line is still valid, quotes are present, only the end of the 
request string is missing.


Do I miss some config parameter ? setting the len in the log 
configuration directive shouldn't prevent this ?



Stéphane

Re: truncated request in log lines

[Daniel Schneller]

This is a limitation of the syslog protocol, IIRC.

-- 
Daniel Schneller
Principal Cloud Engineer
 
CenterDevice GmbH  | Hochstraße 11
   | 42697 Solingen
tel: +49 1754155711| Deutschland
daniel.schnel...@centerdevice.de   | www.centerdevice.de

Geschäftsführung: Dr. Patrick Peschlow, Dr. Lukas Pustina,
Michael Rosbach, Handelsregister-Nr.: HRB 18655,
HR-Gericht: Bonn, USt-IdNr.: DE-815299431


> On 16. May. 2017, at 13:28, Stéphane Cottin  wrote:
> 
> Hi,
> 
> Version: haproxy 1.7.2
> 
> I'm logging to a unix socket, allowing long lines.
> 
>  log /dev/log len 8192 local0
> [...]
>  option dontlognull
>  option log-separate-errors
>  option httplog
> 
> I'm also capturing the referer header.
> 
>  capture request header Referer len 4096
> 
> When using large strings (length > 1024 ) the request is truncated to 1024 
> characters in the log line, the captured header is not.
> The log line is still valid, quotes are present, only the end of the request 
> string is missing.
> 
> Do I miss some config parameter ? setting the len in the log configuration 
> directive shouldn't prevent this ?
> 
> 
> Stéphane
>