Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Multiline parser undocumented error: "#0 got incomplete line before first line" #466

Open
joek-office opened this issue Aug 7, 2023 · 1 comment

Comments

@joek-office
Copy link

Describe the bug

Get the following error message: #0 got incomplete line before first line

Configuration:

<source>
  @type tail
  path /var/log/kolla/*/*-access.log,/var/log/kolla/*/*-error.log,/var/log/kolla/*/*_access.log,/var/log/kolla/*/*_error.log
  pos_file /var/run/td-agent/kolla-openstack-wsgi.pos
  tag kolla.*
  enable_watch_timer false
  <parse>
    @type multiline
    format_firstline /^([^\/\r\nA-Z]*?\[|\[?)(?<Timestamp>((\+)?((?<=[A-Za-z]{4})\d{2,6}|(?<![A-Za-z]{4})(\d{2,6}|\w{3}))(\/|-|:|\s|\.)?){3,7}(?=\d{4}\])\d{4})\]?/
    format1 /^([^\/\r\nA-Z]*?\[|\[?)(?<Timestamp>((\+)?((?<=[A-Za-z]{4})\d{2,6}|(?<![A-Za-z]{4})(\d{2,6}|\w{3}))(\/|-|:|\s|\.)?){3,7}(?=\d{4}\])\d{4})\]?(?<Payload>(.*\p{Space})*$)/
  </parse>
</source>

There comes multiple message sources together. There are mostly one liners and some multi line messages. Think that these regex would match any. But get the error mentioned above.
have seen this issue but dont helps: Issue 338

Lastly some example messages that should matched and with what i have tested in regex101:

10.1.101.12 - - [28/Jun/2023:08:11:12 +0200] "GET /v2.1/os-simple-tenant-usage?detailed=1 HTTP/1.1" 200 1311 29116 "-" "gophercloud/2.0.0"
- - - [28/Jun/2023:08:11:56 +0200] "GET / HTTP/1.1" 200 373 1885 "-" "curl-healthcheck"
10.1.101.14 - - [28/Jun/2023:08:11:56 +0200] "GET /v2.1/limits?tenant_id=7b6766aea33949bca93663202930927e HTTP/1.1" 200 307 25731 "-" "gophercloud/2.0.0"
- - - [28/Jun/2023:08:12:26 +0200] "GET / HTTP/1.1" 200 373 2173 "-" "curl-healthcheck"
10.1.101.12 - - [28/Jun/2023:08:12:11 +0200] "POST /v3/auth/tokens HTTP/1.1" 201 5979 268157 "-" "gophercloud/2.0.0"
- - - [28/Jun/2023:08:12:19 +0200] "GET / HTTP/1.1" 300 267 1929 "-" "curl-healthcheck"


[Tue Jun 27 12:07:40.882366 2023] [suexec:notice] [pid 7:tid 7] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Tue Jun 27 12:07:40.898198 2023] [lbmethod_heartbeat:notice] [pid 7:tid 7] AH02282: No slotmem from mod_heartmonitor


2023/06/28 08:36:20 [crit] 34#34: *223027 SSL_read() failed (SSL: error:0A000126:SSL routines::unexpected eof while reading) while waiting for request, client: 10.1.101.24, server: 10.1.101.10:9999
2023/06/28 08:36:26 [crit] 34#34: *223047 SSL_read() failed (SSL: error:0A000126:SSL routines::unexpected eof while reading) while waiting for request, client: 10.1.101.24, server: 10.1.101.10:9999


[2023-06-28 08:36:26 +0200].455 33 WARNING [-] Invalid HTTP request received.
Traceback (most recent call last):
  File "/var/lib/kolla/venv/lib64/python3.9/site-packages/uvicorn/protocols/http/h11_impl.py", line 129, in handle_events
    event = self.conn.next_event()
  File "/var/lib/kolla/venv/lib64/python3.9/site-packages/h11/_connection.py", line 443, in next_event
    exc._reraise_as_remote_protocol_error()
  File "/var/lib/kolla/venv/lib64/python3.9/site-packages/h11/_util.py", line 76, in _reraise_as_remote_protocol_error
    raise self
  File "/var/lib/kolla/venv/lib64/python3.9/site-packages/h11/_connection.py", line 425, in next_event
    event = self._extract_next_receive_event()
  File "/var/lib/kolla/venv/lib64/python3.9/site-packages/h11/_connection.py", line 367, in _extract_next_receive_event
    event = self._reader(self._receive_buffer)
  File "/var/lib/kolla/venv/lib64/python3.9/site-packages/h11/_readers.py", line 68, in maybe_read_from_IDLE_client
    raise LocalProtocolError("illegal request line")
h11._util.RemoteProtocolError: illegal request line


[Fri Jun 16 15:16:13.876815 2023] [suexec:notice] [pid 7:tid 7] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Fri Jun 16 15:16:13.893031 2023] [lbmethod_heartbeat:notice] [pid 7:tid 7] AH02282: No slotmem from mod_heartmonitor
2023-06-16 15:08:24.274940 AH01909: ctrlhost1.fra1.de.epg.cloud:8775:0 server certificate does NOT include an ID which matches the server name
[Tue Jun 20 14:10:12.584311 2023] [mpm_event:notice] [pid 7:tid 7] AH00489: Apache/2.4.53 (Rocky Linux) OpenSSL/3.0.7 mod_wsgi/4.7.1 Python/3.9 configured -- resuming normal operations
[Tue Jun 20 14:10:12.584335 2023] [core:notice] [pid 7:tid 7] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND'


2023-06-27 09:49:10.619993   File "/var/lib/kolla/venv/lib64/python3.9/site-packages/oslo_reports/guru_meditation_report.py", line 152, in setup_autorun
2023-06-27 09:49:10.619996     cls._setup_signal(signal.SIGUSR2,


2023-06-28 08:35:03.538840 2023-06-28 08:35:03.538 54 WARNING keystone.common.password_hashing [None req-8446ea77-67af-4e96-a8b7-898915f773d9 - - - - - -] Truncating password to algorithm specific maximum length 54 characters.\x1b[00m
2023-06-28 08:35:04.418830 2023-06-28 08:35:04.418 52 WARNING keystone.common.password_hashing [None req-8bcace3f-f1cb-4447-ab81-fee40bb3e129 - - - - - -] Truncating password to algorithm specific maximum length 54 characters.\x1b[00m


[Thu Jun 22 16:46:19.912925 2023] [suexec:notice] [pid 7:tid 7] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Thu Jun 22 16:46:19.938792 2023] [so:warn] [pid 7:tid 7] AH01574: module ssl_module is already loaded, skipping


2023-06-28 08:32:12.611440 /var/lib/kolla/venv/lib64/python3.9/site-packages/oslo_context/context.py:100: DeprecationWarning: Policy enforcement is depending on the value of is_admin. This key is deprecated. Please update your policy file to use the standard policy values.
2023-06-28 08:32:12.611462   warnings.warn('Policy enforcement is depending on the value of '
2023-06-28 08:32:12.771982 /var/lib/kolla/venv/lib64/python3.9/site-packages/oslo_context/context.py:100: DeprecationWarning: Policy enforcement is depending on the value of is_admin. This key is deprecated. Please update your policy file to use the standard policy values.


[Thu Jun 22 16:58:35.580354 2023] [suexec:notice] [pid 7:tid 7] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Thu Jun 22 16:58:35.594706 2023] [so:warn] [pid 7:tid 7] AH01574: module ssl_module is already loaded, skipping
2023-06-16 15:15:09.351074 AH01909: ctrlhost1.fra1.de.epg.cloud:8000:0 server certificate does NOT include an ID which matches the server name
[Thu Jun 22 16:58:31.598404 2023] [suexec:notice] [pid 7:tid 7] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Thu Jun 22 16:58:31.612314 2023] [so:warn] [pid 7:tid 7] AH01574: module ssl_module is already loaded, skipping
2023-06-16 15:15:05.252521 AH01909: ctrlhost1.fra1.de.epg.cloud:8004:0 server certificate does NOT include an ID which matches the server name

Link to the problematic documentation

https://docs.fluentd.org/parser/multiline#format_firstline
https://docs.fluentd.org/parser/multiline#formatn

Expected explanation

Want to have a description what can be the source of this error.

Additional context

No response

@Envely
Copy link

Envely commented Mar 4, 2024

I encountered a similar issue to yours; the official example only displays the first line of logs for stdout, missing the last two lines.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants