Lots of "error:transaction-end-before-headers" in my log

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Lots of "error:transaction-end-before-headers" in my log

Ralf Hildebrandt
I'm getting quite a bit of "transaction-end-before-headers" errors in
my access.log.

Example:
========

1502192404.344 000000 141.42.194.147 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.344 000000 141.42.194.147 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.344 000000 141.42.194.147 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.344 000000 141.42.194.147 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.345 000000 141.42.194.147 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.345 000000 141.42.194.147 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.345 000000 141.42.194.147 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.652 000000 10.43.96.234 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.652 000000 10.43.96.234 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.652 000000 10.43.96.234 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.653 000000 10.43.96.234 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.653 000000 10.43.96.234 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.653 000000 10.43.96.234 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
1502192404.759 000000 10.43.25.85 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -

Some statistics:
================

File                error  total lines
access.log-20170716  49627 2211867
access.log-20170717 359333 8314838
access.log-20170718 395747 8805268
access.log-20170719 371742 9443484
access.log-20170720 365298 9095541
access.log-20170721 325402 7264478
access.log-20170722  79154 2188264
access.log-20170723  56376 2540638
access.log-20170724 337140 8791890
access.log-20170725 349014 8540723
access.log-20170726 329261 8341711
access.log-20170727 355226 8780064
access.log-20170728 293500 8062144 3.6%
access.log-20170729  46597 2233428 2.1%
access.log-20170730  60287 2318682 2.6%
access.log-20170731 330181 8568843 3.8%
access.log-20170801 260704 7855986 3.3%
access.log-20170802 295127 7099761 4.1%
access.log-20170803 330608 8036505 4.1%
access.log-20170804 234662 7040284 3.3%
access.log-20170805  42260 1987658 2.1%
access.log-20170806  36579 1931714 1.9%
access.log-20170807 303962 7472408 4%

I'm using squid-5.0.0-20170709-r15238. Is there any way of finding out
what kind of queries cause this?

--
Ralf Hildebrandt                   Charite Universitätsmedizin Berlin
[hidden email]        Campus Benjamin Franklin
https://www.charite.de             Hindenburgdamm 30, 12203 Berlin
Geschäftsbereich IT, Abt. Netzwerk fon: +49-30-450.570.155
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Lots of "error:transaction-end-before-headers" in my log

Alex Rousskov
On 08/08/2017 06:00 AM, Ralf Hildebrandt wrote:
> I'm getting quite a bit of "transaction-end-before-headers" errors in
> my access.log.
>
> 1502192404.759 000000 10.43.25.85 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -

> Some statistics:
> ================
>
> File                error  total lines
> access.log-20170716  49627 2211867
> access.log-20170717 359333 8314838
> access.log-20170718 395747 8805268
> access.log-20170719 371742 9443484
> access.log-20170720 365298 9095541
> access.log-20170721 325402 7264478
> access.log-20170722  79154 2188264
> access.log-20170723  56376 2540638
> access.log-20170724 337140 8791890
> access.log-20170725 349014 8540723
> access.log-20170726 329261 8341711
> access.log-20170727 355226 8780064
> access.log-20170728 293500 8062144 3.6%
> access.log-20170729  46597 2233428 2.1%
> access.log-20170730  60287 2318682 2.6%
> access.log-20170731 330181 8568843 3.8%
> access.log-20170801 260704 7855986 3.3%
> access.log-20170802 295127 7099761 4.1%
> access.log-20170803 330608 8036505 4.1%
> access.log-20170804 234662 7040284 3.3%
> access.log-20170805  42260 1987658 2.1%
> access.log-20170806  36579 1931714 1.9%
> access.log-20170807 303962 7472408 4%

Interesting: Higher traffic volumes result in a higher portion of
"empty" connections. Do you know what changed on 20170728? A Squid
upgrade or a perhaps configuration change?


> I'm using squid-5.0.0-20170709-r15238. Is there any way of finding out
> what kind of queries cause this?

I would not call these connections without any headers/bytes "queries",
but if you want to learn more about them and/or to check Squid's
classification, consider collecting a packet capture (and access-log
client ports so that it is easier to find the matching packets in the
capture).


HTH,

Alex.
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Lots of "error:transaction-end-before-headers" in my log

Ralf Hildebrandt
* Alex Rousskov <[hidden email]>:

> > 1502192404.759 000000 10.43.25.85 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - accessRule=- -
>
> > Some statistics:
> > ================
> >
> > File                error  total lines
> > access.log-20170716  49627 2211867
> > access.log-20170717 359333 8314838
> > access.log-20170718 395747 8805268
> > access.log-20170719 371742 9443484
> > access.log-20170720 365298 9095541
> > access.log-20170721 325402 7264478
> > access.log-20170722  79154 2188264
> > access.log-20170723  56376 2540638
> > access.log-20170724 337140 8791890
> > access.log-20170725 349014 8540723
> > access.log-20170726 329261 8341711
> > access.log-20170727 355226 8780064
> > access.log-20170728 293500 8062144 3.6%
> > access.log-20170729  46597 2233428 2.1%
> > access.log-20170730  60287 2318682 2.6%
> > access.log-20170731 330181 8568843 3.8%
> > access.log-20170801 260704 7855986 3.3%
> > access.log-20170802 295127 7099761 4.1%
> > access.log-20170803 330608 8036505 4.1%
> > access.log-20170804 234662 7040284 3.3%
> > access.log-20170805  42260 1987658 2.1%
> > access.log-20170806  36579 1931714 1.9%
> > access.log-20170807 303962 7472408 4%
>
> Interesting: Higher traffic volumes result in a higher portion of
> "empty" connections. Do you know what changed on 20170728? A Squid
> upgrade or a perhaps configuration change?

Uhh, unsure.
 
> > I'm using squid-5.0.0-20170709-r15238. Is there any way of finding out
> > what kind of queries cause this?
>
> I would not call these connections without any headers/bytes "queries",
> but if you want to learn more about them and/or to check Squid's
> classification, consider collecting a packet capture (and access-log
> client ports so that it is easier to find the matching packets in the
> capture).

I found that some portion is caused by "ldirectord" probing if the
proxy service on port 8080 is still active & working.

But that's not the bulk of the connections.

I'll try making some packet dumps.

--
Ralf Hildebrandt                   Charite Universitätsmedizin Berlin
[hidden email]        Campus Benjamin Franklin
https://www.charite.de             Hindenburgdamm 30, 12203 Berlin
Geschäftsbereich IT, Abt. Netzwerk fon: +49-30-450.570.155
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Lots of "error:transaction-end-before-headers" in my log

Alex Rousskov
On 08/09/2017 02:21 AM, Ralf Hildebrandt wrote:

> I found that some portion is caused by "ldirectord" probing if the
> proxy service on port 8080 is still active & working.

"active" -- maybe, but "working" -- hardly. To probe that the proxy
service is "working" one should send that service at least one HTTP
request and, bugs notwithstanding, these connections had no requests.


> I'll try making some packet dumps.

For the record, if there are no related Squid bugs, then these packet
dumps should not have much more information than a properly configured
access.log because there is no payload on these connections. Collecting
packets _is_ useful to confirm that Squid classifies these connections
correctly, but such collection should not be needed long-term.

Alex.
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Lots of "error:transaction-end-before-headers" in my log

Ralf Hildebrandt
* Alex Rousskov <[hidden email]>:
> On 08/09/2017 02:21 AM, Ralf Hildebrandt wrote:
>
> > I found that some portion is caused by "ldirectord" probing if the
> > proxy service on port 8080 is still active & working.
>
> "active" -- maybe, but "working" -- hardly.

I had to checks, one "simple" connect check (probably causing the
transaction-end-before-headers" and one elaborate check which sends an
HTTP request and checks the data returned.

> > I'll try making some packet dumps.
>
> For the record, if there are no related Squid bugs, then these packet
> dumps should not have much more information than a properly configured
> access.log because there is no payload on these connections. Collecting
> packets _is_ useful to confirm that Squid classifies these connections
> correctly, but such collection should not be needed long-term.


--
Ralf Hildebrandt                   Charite Universitätsmedizin Berlin
[hidden email]        Campus Benjamin Franklin
https://www.charite.de             Hindenburgdamm 30, 12203 Berlin
Geschäftsbereich IT, Abt. Netzwerk fon: +49-30-450.570.155
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Loading...