Error parsing $upstream_connect_time with multiple values

[wollsi]

Hi its me again :)

I have stumbled across another problem. I recently found some error messages in my logs. They look like this:

Traceback (most recent call last):
  File "/geoip2influx/geoip2influx.py", line 304, in <module>
    main()
  File "/geoip2influx/geoip2influx.py", line 298, in main
    logparse(
  File "/geoip2influx/geoip2influx.py", line 245, in logparse
    log_data_fields['connect_time'] = float(datadict['connect_time'])

I did a little research and found out that the log variable $upstream_connect_time can have multiple values.

The following is from the official nginx docs:

"
$upstream_connect_time
keeps time spent on establishing a connection with the upstream server (1.9.1); the time is kept in seconds with millisecond resolution. In case of SSL, includes time spent on handshake. Times of several connections are separated by commas and colons like addresses in the $upstream_addr variable.
"
(see: https://nginx.org/en/docs/http/ngx_http_upstream_module.html#var_upstream_connect_time)

And exactly thats what happend in my case. I found some log lines that contain two upstream connect times:

THE-IP - - [THE-TIME]"GET /THE-URL HTTP/1.1" 502 36"-" THE-HOST "THE-USER-AGENT""0.020" "0.000, 0.000""THE-CITY" "THE-COUNTRY"
(I masked some parts to keep it short) And thats the part where things go wrong ------------->|_____________|

I did not build anything to patch it as I do not know what would be the best way to solve it.

[GilbN]

Hi. Need the full traceback not a snippet.

[wollsi]

Well actually that is the whole Traceback.

The whole log looks like this:

GEOIP2INFLUX 13/Mar/2022 19:42:31 :: INFO :: Starting geoip2influx..

GEOIP2INFLUX 13/Mar/2022 19:42:31 :: INFO :: Starting log parsing

Traceback (most recent call last):

  File "/geoip2influx/geoip2influx.py", line 304, in <module>

    main()

  File "/geoip2influx/geoip2influx.py", line 298, in main

    logparse(

  File "/geoip2influx/geoip2influx.py", line 245, in logparse

    log_data_fields['connect_time'] = float(datadict['connect_time'])

ValueError: could not convert string to float: '0.000, 0.000'

GEOIP2INFLUX 13/Mar/2022 19:43:23 :: INFO :: Starting geoip2influx..

GEOIP2INFLUX 13/Mar/2022 19:43:23 :: INFO :: Starting log parsing

[GilbN]

Great, was looking for this. ValueError: could not convert string to float: '0.000, 0.000'

[wollsi]

Ah I am sorry. I thought I copied that too. But I missed that 😅

[GilbN]

Pushed a commit that I think fixes it.

[wollsi]

Thanks a lot, will try it out tomorrow