Goaccess: ELB logs problem with empty status code -

Created on 23 Nov 2017 · 20Comments · Source: allinurl/goaccess

Hi.
I have a problem with ELB log.
Until today, I could read ELB log, today log I have this error:
_Token '-' doesn't match specifier '%s'_

This is my logs:

2017-11-23T01:24:08.529348Z ELB-DOMAIN 66.249.66.206:34140 192.168.1.48:443 0.000744 0.000009 0.000012 - - 710 31845 "- - - " "-" - -
2017-11-23T01:25:15.198480Z ELB-DOMAIN 66.249.66.202:57383 192.168.1.48:80 0.00004 0.000869 0.000021 301 301 0 0 "GET http://www.DOMAIN.it:80/es/ropa/pants/ela038059712247007.html?Country=ES HTTP/1.1" "Mozilla/5.0 (compatible; Googlebot/2.1; +http://www.google.com/bot.html)" - -
2017-11-23T01:22:14.697402Z ELB-DOMAIN 37.10.149.133:23315 192.168.1.48:443 0.000783 0.000009 0.000014 - - 22764 169121 "- - - " "-" - -

I use:
Log Format: %dT%t.%^ %^ %h:%^ %^ %T %^ %^ %^ %s %^ %b "%r" "%u"
Date Format %Y-%m-%d
Time Format %H:%M:%S

Thanks.
Regards.

log-processing lodattime format

Source

lupoalberto12

Most helpful comment

@Jamie-BitFlight GoAccess requires at least a valid IPv4/6, date/time and the request. It seems like the request is the only missing part from your access log, so you could use a different field for %U in the absence of it. e.g.,

goaccess access.log --log-format='%dT%t.%^ %U %h:%^ %^ %L %^' --date-format=%Y-%m-%d --time-format=%T

However, note that you will certainly be missing a lot of metrics that you could get from an HTTP log.

allinurl on 8 Jan 2018

👍2

All 20 comments

Can you please describe each field in your access log? Thanks

allinurl on 23 Nov 2017

Thank yoy for the quick response.
It is the same of the default ELB format of GoAccess:
timestamp elb client:port backend:port request_processing_time backend_processing_time response_processing_time elb_status_code backend_status_code received_bytes sent_bytes request user_agent ssl_cipher ssl_protocol

http://docs.aws.amazon.com/elasticloadbalancing/latest/classic/access-log-collection.html

Thanks.

lupoalberto12 on 23 Nov 2017

Using v1.2, I'm able to run it as:

goaccess access.log --log-format=AWSELB

allinurl on 23 Nov 2017

Unfortunately, I've already tried and it isn't work:
https://www.dropbox.com/s/lc6k8w5yne3lidj/Go.PNG?dl=0
Thanks.

lupoalberto12 on 24 Nov 2017

Can you please post the first 20 lines from that access log so I can test it from my side?

allinurl on 24 Nov 2017

Sure:

2017-11-22T16:33:26.751965Z ELB 46.133.22.112:50991 192.168.1.48:443 0.00073 0.000009 0.000013 - - 255 2933 "- - - " "-" - -
2017-11-22T16:33:24.243675Z ELB 35.158.136.171:6141 192.168.1.48:443 0.000741 0.000009 0.000013 - - 1468 809 "- - - " "-" - -
2017-11-22T16:33:27.823568Z ELB 46.133.22.112:50974 192.168.1.48:443 0.000655 0.000011 0.000015 - - 789 30046 "- - - " "-" - -
2017-11-22T16:33:24.399139Z ELB 35.158.136.19:52721 192.168.1.48:443 0.000739 0.000008 0.000013 - - 2961 1817 "- - - " "-" - -
2017-11-22T16:33:33.757852Z ELB 157.55.39.51:15095 192.168.1.48:443 0.00069 0.000009 0.000012 - - 667 4181 "- - - " "-" - -
2017-11-22T16:33:24.276632Z ELB 35.158.136.171:24035 192.168.1.48:443 0.000586 0.000009 0.000024 - - 2467 1481 "- - - " "-" - -
2017-11-22T16:33:30.267254Z ELB 52.56.127.21:24439 192.168.1.48:443 0.000638 0.000009 0.000013 - - 2466 1481 "- - - " "-" - -
2017-11-22T16:33:31.117745Z ELB 52.56.127.21:55501 192.168.1.48:443 0.000669 0.000008 0.000013 - - 967 473 "- - - " "-" - -
2017-11-22T16:33:28.960082Z ELB 52.56.127.127:42041 192.168.1.48:443 0.000634 0.000008 0.000013 - - 2439 1481 "- - - " "-" - -
2017-11-22T16:33:31.904324Z ELB 52.56.127.127:41865 192.168.1.48:443 0.000613 0.000008 0.000012 - - 959 473 "- - - " "-" - -
2017-11-22T16:33:36.394564Z ELB 46.133.22.112:51153 192.168.1.48:443 0.000756 0.000009 0.000015 - - 1193 31362 "- - - " "-" - -
2017-11-22T16:33:38.481048Z ELB 76.72.167.154:54868 192.168.1.48:443 0.000774 0.000009 0.000014 - - 1150 31786 "- - - " "-" - -
2017-11-22T16:33:37.160185Z ELB 40.77.167.83:20829 192.168.1.48:443 0.000763 0.000014 0.000014 - - 663 32319 "- - - " "-" - -
2017-11-22T16:33:29.628690Z ELB 35.158.136.171:55247 192.168.1.48:443 0.000655 0.00001 0.000014 - - 4405 2825 "- - - " "-" - -
2017-11-22T16:33:37.644266Z ELB 35.158.136.171:37229 192.168.1.48:443 0.000639 0.000007 0.000012 - - 2473 1481 "- - - " "-" - -
2017-11-22T16:33:41.883258Z ELB 52.56.127.127:15567 192.168.1.48:443 0.000669 0.000009 0.000011 - - 965 473 "- - - " "-" - -
2017-11-22T16:33:40.020133Z ELB 35.158.136.19:60599 192.168.1.48:443 0.000594 0.000008 0.000012 - - 1490 809 "- - - " "-" - -
2017-11-22T16:33:37.680160Z ELB 52.56.127.127:39683 192.168.1.48:443 0.000618 0.000008 0.000011 - - 2365 1881 "- - - " "-" - -
2017-11-22T16:33:41.124293Z ELB 52.56.127.21:18811 192.168.1.48:443 0.000711 0.000008 0.000011 - - 1864 1545 "- - - " "-" - -
2017-11-22T16:33:53.372946Z ELB 185.224.132.125:34264 192.168.1.48:80 0.00006 0.000911 0.00002 301 301 0 0 "GET http://www.ramo.com:80/ HTTP/1.1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/61.0.3163.100 Safari/537.36" - -
2017-11-22T16:33:48.541218Z ELB 35.158.136.171:53825 192.168.1.48:443 0.000605 0.000007 0.00001 - - 967 473 "- - - " "-" - -
2017-11-22T16:33:48.539736Z ELB 35.158.136.171:29909 192.168.1.48:443 0.000665 0.000009 0.000014 - - 1473 809 "- - - " "-" - -
2017-11-22T16:33:25.240462Z ELB 212.120.92.232:58001 192.168.1.48:443 0.000714 0.000009 0.000013 - - 1315 29911 "- - - " "-" - -
2017-11-22T16:33:59.448279Z ELB 66.249.66.200:64077 192.168.1.48:80 0.000049 0.000972 0.000033 301 301 0 0 "GET http://www.ramo.com:80/it/scarpe/lace-up-sneakers-in-nappa-bianco-038059712223100.html?Country=IT HTTP/1.1" "Mozilla/5.0 (compatible; Googlebot/2.1; +http://www.google.com/bot.html)" - -
2017-11-22T16:34:01.090248Z ELB 66.249.66.200:64077 192.168.1.48:80 0.000048 0.000911 0.000026 301 301 0 0 "GET http://www.ramo.com:80/it/scarpe/lace-up-sneakers-in-nappa-bianco-038059712223100.html?Country=IT HTTP/1.1" "Mozilla/5.0 (Linux; Android 6.0.1; Nexus 5X Build/MMB29P) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.96 Mobile Safari/537.36 (compatible; Googlebot/2.1; +http://www.google.com/bot.html)" - -
2017-11-22T16:33:53.568232Z ELB 185.224.132.125:60480 192.168.1.48:443 0.000811 0.000009 0.000014 - - 1842 33843 "- - - " "-" - -
2017-11-22T16:34:00.865176Z ELB 35.158.136.19:37929 192.168.1.48:443 0.000928 0.000007 0.00001 - - 1472 809 "- - - " "-" - -
2017-11-22T16:34:01.607064Z ELB 35.158.136.171:37857 192.168.1.48:443 0.000803 0.00001 0.000015 - - 1472 809 "- - - " "-" - -
2017-11-22T16:33:58.930930Z ELB 52.56.127.127:52831 192.168.1.48:443 0.000717 0.00001 0.000014 - - 1500 809 "- - - " "-" - -
2017-11-22T16:34:00.844774Z ELB 35.158.136.19:16157 192.168.1.48:443 0.000727 0.000009 0.000013 - - 1971 1145 "- - - " "-" - -
2017-11-22T16:33:57.511704Z ELB 52.56.127.21:36759 192.168.1.48:443 0.000626 0.000009 0.000012 - - 1494 809 "- - - " "-" - -
2017-11-22T16:33:56.786794Z ELB 52.56.127.21:57777 192.168.1.48:443 0.0007 0.000015 0.000023 - - 2418 1681 "- - - " "-" - -
2017-11-22T16:33:58.658102Z ELB 52.56.127.127:10311 192.168.1.48:443 0.000665 0.000008 0.000014 - - 2990 1817 "- - - " "-" - -
2017-11-22T16:34:06.096644Z ELB 54.196.47.128:43366 192.168.1.48:443 0.000601 0.000009 0.000012 - - 639 33134 "- - - " "-" - -
2017-11-22T16:33:40.002080Z ELB 82.66.102.217:65196 192.168.1.48:443 0.000661 0.00001 0.000014 - - 1802 4039 "- - - " "-" - -
2017-11-22T16:34:13.578331Z ELB 35.158.136.171:3975 192.168.1.48:443 0.000586 0.000007 0.000009 - - 969 473 "- - - " "-" - -
2017-11-22T16:34:10.881488Z ELB 35.158.136.171:20475 192.168.1.48:443 0.000652 0.000009 0.000013 - - 1963 1145 "- - - " "-" - -
2017-11-22T16:34:08.171997Z ELB 35.158.136.19:10739 192.168.1.48:443 0.000754 0.000009 0.000014 - - 3924 2489 "- - - " "-" - -
2017-11-22T16:34:13.569675Z ELB 35.158.136.171:17685 192.168.1.48:443 0.000606 0.000009 0.000012 - - 1476 809 "- - - " "-" - -
2017-11-22T16:34:21.228391Z ELB 84.125.48.113:49286 192.168.1.48:80 0.00004 0.000834 0.000033 301 301 0 0 "GET http://www.ramo.com:80/robots.txt HTTP/1.1" "Mozilla/5.0 (compatible; Genieo/1.0 http://www.genieo.com/webfilter.html)" - -
2017-11-22T16:34:21.582420Z ELB 84.125.48.113:49286 192.168.1.48:80 0.000049 0.000875 0.000026 301 301 0 0 "GET http://www.ramo.com:80/ HTTP/1.1" "Mozilla/5.0 (compatible; Genieo/1.0 http://www.genieo.com/webfilter.html)" - -
2017-11-22T16:34:22.958224Z ELB 54.196.47.128:57070 192.168.1.48:443 0.000766 0.000009 0.000013 - - 639 34318 "- - - " "-" - -
2017-11-22T16:34:12.222954Z ELB 109.115.248.246:48958 192.168.1.48:443 0.000684 0.000009 0.000013 - - 327 3163 "- - - " "-" - -
2017-11-22T16:34:12.224748Z ELB 109.115.248.246:48956 192.168.1.48:443 0.000674 0.000007 0.00001 - - 327 3163 "- - - " "-" - -
2017-11-22T16:34:12.226003Z ELB 109.115.248.246:48957 192.168.1.48:443 0.000555 0.000005 0.000008 - - 327 3163 "- - - " "-" - -

Thanks.
Regards.
Ugo

lupoalberto12 on 24 Nov 2017

Got it. So the issue is the empty - status code on the first 10 lines parsed. I couldn't find documentation from the link you provided above as to why it's empty. I don't know if this is an issue in goaccess since my assumption is that there should be a status code on each request. However, what you can do is to increase the number of tests:

goaccess access.log --log-format=AWSELB --num-tests=100

Note that requests with invalid status codes are considered invalid requests.

allinurl on 24 Nov 2017

@allinurl it's works fine.
So, will you manage also this request (without status code) on the next version of GoAccess?
Thanks.
Regards.

lupoalberto12 on 27 Nov 2017

@lupoalberto12 I can certainly remove that restriction, however, I'm not sure yet if that's the route we should take. Do you have any reference that mentions that the status code can in fact be empty?

allinurl on 28 Nov 2017

@allinurl the logs that I send you, are production logs.
If you want, I can ask to AWS about log ELB and empty statsu code.
Thanks.

lupoalberto12 on 28 Nov 2017

It would be great if you could ask AWS why there are empty status codes or if they have any docs about this. Let me know. Thanks!

allinurl on 29 Nov 2017

Asked.
Waiting for a their response.
Bye!

lupoalberto12 on 29 Nov 2017

Hi @allinurl, AWS wrote me:

_As for the ELB, from the logs you shared with me, I see that you have TCP listeners and it's normal to get empty responses. This is because the request is not looked at by the ELB itself, rather it just creates the TCP connection._
_However, should you want to have proper logs for this, my suggestion would be to change the listener from TCP to HTTPS by adding a certificate on the load balancer._

So the empy status code is when on ELB there TCP listeners.
Do you want other informations about it?
Thanks.
Regards.

lupoalberto12 on 30 Nov 2017

@allinurl
other response from AWS:

_While this information is not explicitly stated anywhere, you can get this information from the link below: _
_http://docs.aws.amazon.com/elasticloadbalancing/latest/classic/access-log-collection.html#access-log-entry-format_

You should add another type for ELB TCP/IP.

Thanks.
Regards.

lupoalberto12 on 1 Dec 2017

Thank you for posting this. Have you tried changing the the listener from TCP to HTTPS and see if it logs the status code? To be honest, I'm still hesitant to remove the status code restriction from goaccess, especially considering its core function is to parse HTTP logs.

allinurl on 2 Dec 2017

Hi @allinurl.
We cannot to change listener from TCP to HTTPS for our infrastructure type.
For us it isn't a problem because with

_goaccess access.log --log-format=AWSELB --num-tests=100_

works very fine but it is possibile that other users can have the same problem.
BTW, thank you for your support.
Thanks.
Regards.

lupoalberto12 on 5 Dec 2017

Hi,
All of my logs are done using TCP not HTTP (because it has to) so i can't use the num-tests workaround.
Is there a logformat pattern that will allow processing of the logs?

2017-11-08T23:47:06.035761Z SmartConnect-TerminalServer-LB 202.124.119.58:1063 172.31.12.68:80 0.001165 0.000009 0.000013 - - 157 19 "- - - " "-" - -
2017-11-08T23:47:20.215920Z SmartConnect-TerminalServer-LB 103.25.188.89:55642 172.31.12.68:8187 0.001107 0.000012 0.000012 - - 0 0 "- - - " "-" - -
2017-11-08T23:47:21.129420Z SmartConnect-TerminalServer-LB 1.126.49.84:22071 172.31.12.68:443 0.001135 0.000008 0.000027 - - 0 0 "- - - " "-" ECDHE-RSA-AES128-SHA TLSv1.2
2017-11-08T23:47:21.515899Z SmartConnect-TerminalServer-LB 63.143.42.249:8453 172.31.12.68:8187 0.001188 0.000009 0.000013 - - 0 0 "- - - " "-" - -
2017-11-08T23:45:21.881323Z SmartConnect-TerminalServer-LB 202.92.216.75:18178 172.31.12.68:80 0.001185 0.000008 0.000012 - - 1524 264 "- - - " "-" - -
2017-11-08T23:47:16.018750Z SmartConnect-TerminalServer-LB 202.124.119.58:41575 172.31.12.68:80 0.001131 0.000015 0.000023 - - 157 19 "- - - " "-" - -
2017-11-08T23:45:15.155393Z SmartConnect-TerminalServer-LB 203.173.216.233:55635 172.31.12.68:80 0.001135 0.000013 0.000014 - - 1613 259 "- - - " "-" - -

Jamie-BitFlight on 8 Jan 2018

goaccess access.log --log-format='%dT%t.%^ %U %h:%^ %^ %L %^' --date-format=%Y-%m-%d --time-format=%T

However, note that you will certainly be missing a lot of metrics that you could get from an HTTP log.

allinurl on 8 Jan 2018

👍2

@allinurl thank you that worked. And thank you, you are right it is missing a lot of data. But it helped identify clusters of IP addresses that were slamming the LB.

Jamie-BitFlight on 10 Jan 2018

Added command line option --no-strict-status to disable status validation which addresses the original post. It will be deployed in the upcoming version. Feel free to test it out by building from development. Thanks

allinurl on 17 Dec 2020

👍1

Was this page helpful?

0 / 5 - 0 ratings