I can assure the log file and the config are the same. no one is altering the config file. The log file on the other hand is same, except it just gets deleted and recreated with the new data.
If I had a dollar for every time I heard nothing changed... or it is all the same... and then it actually did change.... I would be retired 
But in this case, I don't think that's the issue..
I think This ^^^^ is the key
Exactly how is the file being deleted and recreated?
Is it a Linux shell script That is removing the file and then a new file with the exact same name is created?
Is it being truncated by the application and then just appended too?
Is it really the exact file or another file with a new date...
Is it rotation?
I think This is a key ... I suspect... what is actually happening
You should probably read the details on this here
In your original, you did not have this BTW...
start_position => "beginning"
If I delete and then created a file or copied a file to the name, the new file was read and parsed
If I truncated the file and then appended to the file, the appended file was read.
@nkknkk So if you are having trouble debugging take out the multiline and focus on reading a new file...
why does it matter how the log is deleted or created?
logstash is able to read it. however, it is only parsing one pattern and ignoring another pattern, meaning its not an issue with the file creation or deletion.
To answer your all the other questions.
The file is "catalina.out"
everyday the app gets restarted and the old log file is deleted and recreated with the same name with same permissions.
no rotation.
I think you misunderstood the issue here.
The new log file is being read and processed everyday. except, it is only parsing one pattern and completely ignores the 2nd pattern.
which clearly means it is not a issue with the log file. I just need to find the right parsing/input settings I think. and that is what I am seeking for some help here.
hope this helps to understand the scenario.
Nothing in the configurations you have posted does any parsing of patterns.
Sorry @Badger we mean multiline codec... on the input when referring to patterns....
It can matter... there is a difference between rm and create and truncate and append... whether that is the issue or not I don't know but there is a difference.
So it is rm and replace.
I did exactly what you said... ran logstash ... read the file... then removed the file... then created a new file and it read the new lines fine
So if you take out all the multiline logic ... and just let logstash run does it pull in new lines... when the new file is created.
You are going to need to debug this as I can not reproduce.
Perhaps @Badger can provide some guidance
Here is my conf
input {
file {
path => "/Users/sbrown/workspace/sample-data/discuss/multi-line/discuss-multi.log"
start_position => "beginning"
codec => multiline {
pattern => "^\[|^\d{1,2}-\w{3}-\d{4}"
negate => "true"
what => "previous"
}
}
}
filter {
mutate {
remove_field => [ "event", "log", "host", "@version", "tags"]
}
}
output {
stdout{}
}
My sample log file
[<2 10, 2025 11:17:15 AM>:
Yr=2025
]
[<2 10, 2025 11:17:15 AM>: CurrentYear: close statement]
10-Feb-2025 11:17:09.201 WARNING [main] org.apache.naming.NamingContext.lookup Unexpected exception resolving reference
java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection
[<2 10, 2025 11:18:15 AM>:
Yr=2024
]
[<2 10, 2025 11:18:15 AM>: CurrentYear: close statement]
9-Feb-2025 11:17:09.201 ERROR [main] org.apache.naming.NamingContext.lookup Unexpected exception resolving reference
java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection
]
[<2 10, 2025 11:18:15 AM>:
Yr=2024
]
results
"message" => "[<2 10, 2025 11:17:15 AM>:\nYr=2025\n]",
"@timestamp" => 2025-02-11T15:33:13.929559Z
}
{
"message" => "[<2 10, 2025 11:17:15 AM>: CurrentYear: close statement]",
"@timestamp" => 2025-02-11T15:33:13.930711Z
}
{
"message" => "10-Feb-2025 11:17:09.201 WARNING [main] org.apache.naming.NamingContext.lookup Unexpected exception resolving reference\n java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection",
"@timestamp" => 2025-02-11T15:33:13.932675Z
}
{
"message" => "[<2 10, 2025 11:18:15 AM>: CurrentYear: close statement]",
"@timestamp" => 2025-02-11T15:33:13.935388Z
}
{
"message" => "[<2 10, 2025 11:18:15 AM>:\nYr=2024\n]",
"@timestamp" => 2025-02-11T15:33:13.935025Z
}
{
"message" => "9-Feb-2025 11:17:09.201 ERROR [main] org.apache.naming.NamingContext.lookup Unexpected exception resolving reference\n java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection\n]",
"@timestamp" => 2025-02-11T15:33:13.935887Z
}
DELETED and RECREATED FILE HERE...
{
"message" => "[<2 10, 2025 11:18:15 AM>:\nYr=2024\n]",
"@timestamp" => 2025-02-11T15:33:49.111676Z
}
{
"message" => "[<2 10, 2025 11:17:15 AM>: CurrentYear: close statement]",
"@timestamp" => 2025-02-11T15:34:14.238964Z
}
{
"message" => "[<2 10, 2025 11:18:15 AM>:\nYr=2024\n]",
"@timestamp" => 2025-02-11T15:34:14.239740Z
}
{
"message" => "9-Feb-2025 11:17:09.201 ERROR [main] org.apache.naming.NamingContext.lookup Unexpected exception resolving reference\n java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection\n]",
"@timestamp" => 2025-02-11T15:34:14.240412Z
}
{
"message" => "10-Feb-2025 11:17:09.201 WARNING [main] org.apache.naming.NamingContext.lookup Unexpected exception resolving reference\n java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection",
"@timestamp" => 2025-02-11T15:34:14.239312Z
}
{
"message" => "[<2 10, 2025 11:18:15 AM>: CurrentYear: close statement]",
"@timestamp" => 2025-02-11T15:34:14.239975Z
}
{
"message" => "[<2 10, 2025 11:17:15 AM>:\nYr=2025\n]",
"@timestamp" => 2025-02-11T15:34:14.238630Z
}
$ rm discuss-multi.log
$ cp discuss-multi.log.bak discuss-multi.log
if I delete the log file and recreate the log file with the same name... logstash reads the new file with the same name fine and finds both patterns fine
@Badger .... @nkknkk Is reporting he does not see the same behavior
@nkknkk If you take out the multline does it read the before and after file.
You can certainly test this (and the multi-line) and also test by just making a copy of the logs file... Point logstash to it... Read it... remove it ... create the new copy and observe the results... I can not reproduce the issue.
Apologies
This
and this communicates two different issues.... but I think I am back on track.
So back to you are only parsing one type of the multiline.
- You provided a sample log...
- I used that sample Log
- I create a multiline config
- It correctly parses / collects multi-line on both types as far as I understand, please tell me if it is not correct.
- All my code is in the previous post
So
a) Either the sample I am using that you provided is incorrect and thus my results are incorrect
b) There is something else going on
I can only work on the samples you provide...
Can you test and repeat with the config and sample I provided above?
What is wrong with my sample file?
If you can provide 100 lines or so of the actual file I can test with that... of the real file (anonymize the IPs)
Thank you @stephenb for all your inputs
The issue is happening only after the file is deleted and recreated. This is where logstash or the pipeline is getting lost for some reason.
The parsing works when the file is already exists and is static.
like when i made the config changes you mentioned yesterday. it parsed the yesterdays log file without any issues. however, come today and see it completely ignored the messages that start with "[<"
let me give you the log file with more messages
here is the sample log with 150 lines
[<2 11, 2025 11:02:47 AM>: - getRedirectFilter]
[<2 11, 2025 11:02:47 AM>: - getRedirectFilter: close statement]
[<2 11, 2025 11:02:52 AM>:
The JDBC database driver version is:
]
[<2 11, 2025 11:02:52 AM>:
needto=Y
]
[<2 11, 2025 11:02:52 AM>: .getFlag: close statement]
[<2 11, 2025 11:16:02 AM>: Exception:
Unable to lookup datasource: java:comp/env/jdbc/DataSource
org...util.DBHelper.getDataSource(DBHelper.java:124)
org...services.dao.helper..getCountryCodes(.java:70)
org...services.implementations.helper.HelperServicesImpl.getCountryCodes(HelperServicesImpl.java:29)
org...web.ContextListener.initlizeContext(ContextListener.java:70)
org...web.ContextListener.contextInitlized(ContextListener.java:62)
]
[<2 11, 2025 11:16:02 AM>: HelperDAO.getCountryCodes: close statement]
[<2 11, 2025 11:16:02 AM>: getSystemParameters]
[<2 11, 2025 11:16:02 AM>: - getSystemParameters]
[<2 11, 2025 11:20:24 AM>: - getSystemParameters: close statement]
- Root WebApplicationContext: initlization started
- Refreshing Root WebApplicationContext: startup date [Tue Feb 11 11:20:24 EST 2025]; root of context hierarchy
- Loading XML bean definitions from ServletContext resource [/WEB-INF/applicationContext.xml]
[<2 11, 2025 11:20:36 AM>: .getSelectList()]
context initlizing.
[<2 11, 2025 11:20:40 AM>: - getRequestParameterFilter]
[<2 11, 2025 11:20:40 AM>: - getRequestParameterFilter: close statement]
System Parameter found: .*(((<|<)(script|i))|prompt[ ]*\(|confirm[ ]*\(|alert[ ]*\(|eval[ ]*\(|(\$|#|%23|%24)(\{|%7b)).*
va:212)
at org.apache.tomcat.jdbc.pool.ConnectionPool.createConnection(ConnectionPool.java:744)
at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:676)
at org.apache.tomcat.jdbc.pool.ConnectionPool.init(ConnectionPool.java:483)
at org.apache.tomcat.jdbc.pool.ConnectionPool.<init>(ConnectionPool.java:154)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:343)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:474)
Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection
at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:720)
at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:586)
at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:729)
at oracle.net.ns.NSProtocol.connect(NSProtocol.java:340)
at oracle.jdbc.driver..connect(.java:1702)
at oracle.jdbc.driver..logon(.java:627)
... 64 more
Caused by: java.net.UnknownHostException: ..org
at java.net..0(.java:1281)
at java.net..(.java:1193)
at java.net..(.java:1127)
at oracle.net.nt..connect(.java:162)
at oracle.net.nt.ConnOption.connect(ConnOption.java:195)
at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)
... 69 more
11-Feb-2025 11:02:47.016 WARNING [main] org.apache.naming.NamingContext.lookup Unexpected exception resolving reference
java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection
at oracle.jdbc.driver..logon(.java:903)
at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:820)
at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:80)
at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:816)
at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:620)
at org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:319)
at org.apache.tomcat.jdbc.pool.PooledConnection.connect(PooledConnection.java:212)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:343)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:474)
Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection
at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:720)
at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:586)
at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:729)
at oracle.net.ns.NSProtocol.connect(NSProtocol.java:340)
at oracle.jdbc.driver..connect(.java:1702)
at oracle.jdbc.driver..logon(.java:627)
... 64 more
Caused by: java.net.UnknownHostException: ..org
at java.net..0(.java:1281)
at java.net..(.java:1193)
at java.net..(.java:1127)
at oracle.net.nt..connect(.java:162)
at oracle.net.nt.ConnOption.connect(ConnOption.java:195)
at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)
... 69 more
11-Feb-2025 11:02:47.017 WARNING [main] org.apache.catalina.core.NamingContextListener.addResource naming.jmxRegistrationFailed
11-Feb-2025 11:02:47.028 SEVERE [main] org.apache.tomcat.jdbc.pool.ConnectionPool.init Unable to create initl connections of pool.
java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection
at oracle.jdbc.driver..logon(.java:903)
at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:820)
at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:80)
at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:816)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:343)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:474)
Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection
at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:720)
at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:586)
at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:729)
at oracle.net.ns.NSProtocol.connect(NSProtocol.java:340)
at oracle.jdbc.driver..connect(.java:1702)
at oracle.jdbc.driver..logon(.java:627)
... 64 more
Caused by: java.net.UnknownHostException: ..org
at java.net..0(.java:1281)
at java.net..(.java:1193)
at java.net..(.java:1127)
at oracle.net.nt..connect(.java:162)
at oracle.net.nt.ConnOption.connect(ConnOption.java:195)
at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)
... 69 more
11-Feb-2025 11:02:47.437 WARNING [main] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [] appears to have started a thread named [oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
java.lang.Object.wait(Native Method)
oracle.jdbc.driver.BlockSource$ThreadedCachingBlockSource$BlockReleaser.run(BlockSource.java:331)
11-Feb-2025 11:02:47.438 WARNING [main] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [] appears to have started a thread named [InterruptTimer] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:502)
java.util.TimerThread.mainLoop(Timer.java:526)
java.util.TimerThread.run(Timer.java:505)
11-Feb-2025 11:02:47.441 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/opt//tomcat/webapps/.war] has finished in [1,763] ms
11-Feb-2025 11:02:47.442 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/opt//tomcat/webapps/.war]
11-Feb-2025 11:02:47.443 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin Match [Context/Manager] failed to set property [expireSessionsOnShutdown] to [false]
11-Feb-2025 11:02:51.528 INFO [main] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
: Failed to load class "org..impl.".
: Defaulting to no-operation (NOP) logger implementation
: See http://www..org/codes.html# for further details.
at oracle.jdbc.driver..logon(.java:627)
... 73 more
Caused by: java.net.UnknownHostException: ..org
at java.net..0(.java:1281)
at java.net..(.java:1193)
at java.net..(.java:1127)
at oracle.net.nt..connect(.java:162)
at oracle.net.nt.ConnOption.connect(ConnOption.java:195)
at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)
... 78 more
-- Caused by: --
javax.naming.NamingException: Unexpected exception resolving reference [Root exception is java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection]
at org.apache.naming.NamingContext.lookup(NamingContext.java:882)
at org.apache.naming.NamingContext.lookup(NamingContext.java:160)
at java.net..(.java:1127)
at oracle.net.nt..connect(.java:162)
at oracle.net.nt.ConnOption.connect(ConnOption.java:195)
at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)
... 78 more
11-Feb-2025 11:20:33.548 INFO [main] org.apache.2..Listener.info Starting 2 integration ...
ERROR could not find a logging implementation. Please add to the classpath. Using SimpleLogger to log to the console...
11-Feb-2025 11:20:40.988 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [1,077,372] milliseconds
Ok so here is my config.
I would be good if you can try it exactly as it is with only changing the filepath to your file I put your logs in discuss-multi.log
I used the exact logs above...
I did note in the logs above there are tabs not just spaces but that seems to be OK.
Here is the config named discuss-multi.conf
input {
file {
path => "/Users/sbrown/workspace/sample-data/discuss/multi-line/discuss-multi.log"
start_position => "beginning"
sincedb_path => "/dev/null"
codec => multiline {
pattern => "^\[|^\d{1,2}-\w{3}-\d{4}"
negate => "true"
what => "previous"
}
}
}
filter {
mutate {
remove_field => [ "event", "log", "host", "@version", "tags"]
}
}
output {
stdout{}
}
run this command in another window this will run logstash in the foreground
$ sudo ./bin/logstash -r -f /Users/sbrown/workspace/sample-data/discuss/multi-line/discuss-multi.conf
Here is the results, both patterns matched.
{
"message" => "[<2 11, 2025 11:20:40 AM>: - getRequestParameterFilter]",
"@timestamp" => 2025-02-11T17:47:35.809401Z
}
{
"message" => "[<2 11, 2025 11:02:47 AM>: - getRedirectFilter]",
"@timestamp" => 2025-02-11T17:47:35.801204Z
}
{
"message" => "[<2 11, 2025 11:20:40 AM>: - getRequestParameterFilter: close statement]\nSystem Parameter found: .*(((<|<)(script|i))|prompt[ ]*\\(|confirm[ ]*\\(|alert[ ]*\\(|eval[ ]*\\(|(\\$|#|%23|%24)(\\{|%7b)).*\nva:212)\n at org.apache.tomcat.jdbc.pool.ConnectionPool.createConnection(ConnectionPool.java:744)\n at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:676)\n at org.apache.tomcat.jdbc.pool.ConnectionPool.init(ConnectionPool.java:483)\n at org.apache.tomcat.jdbc.pool.ConnectionPool.<init>(ConnectionPool.java:154)\n at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n at java.lang.reflect.Method.invoke(Method.java:498)\n at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:343)\n at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:474)\n Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:720)\n at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:586)\n at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:729)\n at oracle.net.ns.NSProtocol.connect(NSProtocol.java:340)\n at oracle.jdbc.driver..connect(.java:1702)\n at oracle.jdbc.driver..logon(.java:627)\n ... 64 more\n Caused by: java.net.UnknownHostException: ..org\n at java.net..0(.java:1281)\n at java.net..(.java:1193)\n at java.net..(.java:1127)\n at oracle.net.nt..connect(.java:162)\n at oracle.net.nt.ConnOption.connect(ConnOption.java:195)\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)\n ... 69 more",
"@timestamp" => 2025-02-11T17:47:35.834232Z
}
{
"message" => "[<2 11, 2025 11:02:52 AM>: \nThe JDBC database driver version is:\n]",
"@timestamp" => 2025-02-11T17:47:35.803896Z
}
{
"message" => "11-Feb-2025 11:02:47.017 WARNING [main] org.apache.catalina.core.NamingContextListener.addResource naming.jmxRegistrationFailed",
"@timestamp" => 2025-02-11T17:47:35.840259Z
}
{
"message" => "[<2 11, 2025 11:02:47 AM>: - getRedirectFilter: close statement]",
"@timestamp" => 2025-02-11T17:47:35.803199Z
}
{
"message" => "11-Feb-2025 11:02:47.016 WARNING [main] org.apache.naming.NamingContext.lookup Unexpected exception resolving reference\n java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection\n at oracle.jdbc.driver..logon(.java:903)\n at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:820)\n at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:80)\n at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:816)\n at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:620)\n at org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:319)\n at org.apache.tomcat.jdbc.pool.PooledConnection.connect(PooledConnection.java:212)\n at java.lang.reflect.Method.invoke(Method.java:498)\n at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:343)\n at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:474)\n Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:720)\n at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:586)\n at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:729)\n at oracle.net.ns.NSProtocol.connect(NSProtocol.java:340)\n at oracle.jdbc.driver..connect(.java:1702)\n at oracle.jdbc.driver..logon(.java:627)\n ... 64 more\n Caused by: java.net.UnknownHostException: ..org\n at java.net..0(.java:1281)\n at java.net..(.java:1193)\n at java.net..(.java:1127)\n at oracle.net.nt..connect(.java:162)\n at oracle.net.nt.ConnOption.connect(ConnOption.java:195)\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)\n ... 69 more",
"@timestamp" => 2025-02-11T17:47:35.839782Z
}
{
"message" => "[<2 11, 2025 11:16:02 AM>: HelperDAO.getCountryCodes: close statement]",
"@timestamp" => 2025-02-11T17:47:35.806065Z
}
{
"message" => "11-Feb-2025 11:02:47.441 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/opt//tomcat/webapps/.war] has finished in [1,763] ms",
"@timestamp" => 2025-02-11T17:47:35.845740Z
}
{
"message" => "[<2 11, 2025 11:20:36 AM>: .getSelectList()]\n context initlizing.",
"@timestamp" => 2025-02-11T17:47:35.808658Z
}
{
"message" => "11-Feb-2025 11:20:33.548 INFO [main] org.apache.2..Listener.info Starting 2 integration ...\nERROR could not find a logging implementation. Please add to the classpath. Using SimpleLogger to log to the console...",
"@timestamp" => 2025-02-11T17:47:35.851415Z
}
{
"message" => "[<2 11, 2025 11:02:52 AM>: \n needto=Y\n]",
"@timestamp" => 2025-02-11T17:47:35.804563Z
}
{
"message" => "11-Feb-2025 11:02:47.028 SEVERE [main] org.apache.tomcat.jdbc.pool.ConnectionPool.init Unable to create initl connections of pool.\n java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection\n at oracle.jdbc.driver..logon(.java:903)\n at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:820)\n at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:80)\n at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:816)\n at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:343)\n at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:474)\n Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:720)\n at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:586)\n at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:729)\n at oracle.net.ns.NSProtocol.connect(NSProtocol.java:340)\n at oracle.jdbc.driver..connect(.java:1702)\n at oracle.jdbc.driver..logon(.java:627)\n ... 64 more\n Caused by: java.net.UnknownHostException: ..org\n at java.net..0(.java:1281)\n at java.net..(.java:1193)\n at java.net..(.java:1127)\n at oracle.net.nt..connect(.java:162)\n at oracle.net.nt.ConnOption.connect(ConnOption.java:195)\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)\n ... 69 more",
"@timestamp" => 2025-02-11T17:47:35.843651Z
}
{
"message" => "[<2 11, 2025 11:02:52 AM>: .getFlag: close statement]",
"@timestamp" => 2025-02-11T17:47:35.804809Z
}
{
"message" => "11-Feb-2025 11:02:47.437 WARNING [main] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [] appears to have started a thread named [oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:\n java.lang.Object.wait(Native Method)\n oracle.jdbc.driver.BlockSource$ThreadedCachingBlockSource$BlockReleaser.run(BlockSource.java:331)",
"@timestamp" => 2025-02-11T17:47:35.844202Z
}
{
"message" => "[<2 11, 2025 11:16:02 AM>: getSystemParameters]",
"@timestamp" => 2025-02-11T17:47:35.806290Z
}
{
"message" => "11-Feb-2025 11:02:47.442 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/opt//tomcat/webapps/.war]",
"@timestamp" => 2025-02-11T17:47:35.846762Z
}
{
"message" => "[<2 11, 2025 11:20:24 AM>: - getSystemParameters: close statement]\n- Root WebApplicationContext: initlization started\n- Refreshing Root WebApplicationContext: startup date [Tue Feb 11 11:20:24 EST 2025]; root of context hierarchy\n- Loading XML bean definitions from ServletContext resource [/WEB-INF/applicationContext.xml]",
"@timestamp" => 2025-02-11T17:47:35.807905Z
}
{
"message" => "11-Feb-2025 11:02:51.528 INFO [main] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.\n: Failed to load class \"org..impl.\".\n: Defaulting to no-operation (NOP) logger implementation\n: See http://www..org/codes.html# for further details.\n at oracle.jdbc.driver..logon(.java:627)\n ... 73 more\nCaused by: java.net.UnknownHostException: ..org\n at java.net..0(.java:1281)\n at java.net..(.java:1193)\n at java.net..(.java:1127)\n at oracle.net.nt..connect(.java:162)\n at oracle.net.nt.ConnOption.connect(ConnOption.java:195)\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)\n ... 78 more\n-- Caused by: --\njavax.naming.NamingException: Unexpected exception resolving reference [Root exception is java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection]\n at org.apache.naming.NamingContext.lookup(NamingContext.java:882)\n at org.apache.naming.NamingContext.lookup(NamingContext.java:160)\n at java.net..(.java:1127)\n at oracle.net.nt..connect(.java:162)\n at oracle.net.nt.ConnOption.connect(ConnOption.java:195)\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)\n ... 78 more",
"@timestamp" => 2025-02-11T17:47:35.850711Z
}
{
"message" => "[<2 11, 2025 11:16:02 AM>: - getSystemParameters]",
"@timestamp" => 2025-02-11T17:47:35.807144Z
}
{
"message" => "11-Feb-2025 11:02:47.443 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin Match [Context/Manager] failed to set property [expireSessionsOnShutdown] to [false]",
"@timestamp" => 2025-02-11T17:47:35.847173Z
}
{
"message" => "[<2 11, 2025 11:16:02 AM>: Exception: \nUnable to lookup datasource: java:comp/env/jdbc/DataSource\norg...util.DBHelper.getDataSource(DBHelper.java:124)\norg...services.dao.helper..getCountryCodes(.java:70)\norg...services.implementations.helper.HelperServicesImpl.getCountryCodes(HelperServicesImpl.java:29)\norg...web.ContextListener.initlizeContext(ContextListener.java:70)\norg...web.ContextListener.contextInitlized(ContextListener.java:62)\n]",
"@timestamp" => 2025-02-11T17:47:35.805811Z
}
{
"message" => "11-Feb-2025 11:02:47.438 WARNING [main] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [] appears to have started a thread named [InterruptTimer] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:\n java.lang.Object.wait(Native Method)\n java.lang.Object.wait(Object.java:502)\n java.util.TimerThread.mainLoop(Timer.java:526)\n java.util.TimerThread.run(Timer.java:505)",
"@timestamp" => 2025-02-11T17:47:35.845380Z
}
I made a copy of the log file and removed the original and then copied it back.
$ cp discuss-multi.log discuss-multi.log.bak
$ rm discuss-multi.log
$ cp discuss-multi.log.bak discuss-multi.log
And this was the immediate results ... it read the file again
Removed File Here and Copied Back, new results you can see the updated timestamps ... Here is the results, both patterns matched.
{
"message" => "11-Feb-2025 11:20:40.988 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [1,077,372] milliseconds",
"@timestamp" => 2025-02-11T17:51:59.972749Z
}
{
"message" => "[<2 11, 2025 11:16:02 AM>: - getSystemParameters]",
"@timestamp" => 2025-02-11T17:52:07.032118Z
}
{
"message" => "[<2 11, 2025 11:16:02 AM>: getSystemParameters]",
"@timestamp" => 2025-02-11T17:52:07.031874Z
}
{
"message" => "[<2 11, 2025 11:20:24 AM>: - getSystemParameters: close statement]\n- Root WebApplicationContext: initlization started\n- Refreshing Root WebApplicationContext: startup date [Tue Feb 11 11:20:24 EST 2025]; root of context hierarchy\n- Loading XML bean definitions from ServletContext resource [/WEB-INF/applicationContext.xml]",
"@timestamp" => 2025-02-11T17:52:07.032707Z
}
{
"message" => "11-Feb-2025 11:02:47.017 WARNING [main] org.apache.catalina.core.NamingContextListener.addResource naming.jmxRegistrationFailed",
"@timestamp" => 2025-02-11T17:52:07.040779Z
}
{
"message" => "[<2 11, 2025 11:20:40 AM>: - getRequestParameterFilter: close statement]\nSystem Parameter found: .*(((<|<)(script|i))|prompt[ ]*\\(|confirm[ ]*\\(|alert[ ]*\\(|eval[ ]*\\(|(\\$|#|%23|%24)(\\{|%7b)).*\nva:212)\n at org.apache.tomcat.jdbc.pool.ConnectionPool.createConnection(ConnectionPool.java:744)\n at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:676)\n at org.apache.tomcat.jdbc.pool.ConnectionPool.init(ConnectionPool.java:483)\n at org.apache.tomcat.jdbc.pool.ConnectionPool.<init>(ConnectionPool.java:154)\n at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n at java.lang.reflect.Method.invoke(Method.java:498)\n at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:343)\n at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:474)\n Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:720)\n at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:586)\n at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:729)\n at oracle.net.ns.NSProtocol.connect(NSProtocol.java:340)\n at oracle.jdbc.driver..connect(.java:1702)\n at oracle.jdbc.driver..logon(.java:627)\n ... 64 more\n Caused by: java.net.UnknownHostException: ..org\n at java.net..0(.java:1281)\n at java.net..(.java:1193)\n at java.net..(.java:1127)\n at oracle.net.nt..connect(.java:162)\n at oracle.net.nt.ConnOption.connect(ConnOption.java:195)\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)\n ... 69 more",
"@timestamp" => 2025-02-11T17:52:07.037431Z
}
{
"message" => "11-Feb-2025 11:02:47.016 WARNING [main] org.apache.naming.NamingContext.lookup Unexpected exception resolving reference\n java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection\n at oracle.jdbc.driver..logon(.java:903)\n at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:820)\n at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:80)\n at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:816)\n at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:620)\n at org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:319)\n at org.apache.tomcat.jdbc.pool.PooledConnection.connect(PooledConnection.java:212)\n at java.lang.reflect.Method.invoke(Method.java:498)\n at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:343)\n at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:474)\n Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:720)\n at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:586)\n at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:729)\n at oracle.net.ns.NSProtocol.connect(NSProtocol.java:340)\n at oracle.jdbc.driver..connect(.java:1702)\n at oracle.jdbc.driver..logon(.java:627)\n ... 64 more\n Caused by: java.net.UnknownHostException: ..org\n at java.net..0(.java:1281)\n at java.net..(.java:1193)\n at java.net..(.java:1127)\n at oracle.net.nt..connect(.java:162)\n at oracle.net.nt.ConnOption.connect(ConnOption.java:195)\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)\n ... 69 more",
"@timestamp" => 2025-02-11T17:52:07.040522Z
}
{
"message" => "[<2 11, 2025 11:20:36 AM>: .getSelectList()]\n context initlizing.",
"@timestamp" => 2025-02-11T17:52:07.033073Z
}
{
"message" => "[<2 11, 2025 11:20:40 AM>: - getRequestParameterFilter]",
"@timestamp" => 2025-02-11T17:52:07.033317Z
}
{
"message" => "[<2 11, 2025 11:02:52 AM>: \nThe JDBC database driver version is:\n]",
"@timestamp" => 2025-02-11T17:52:07.027710Z
}
{
"message" => "11-Feb-2025 11:02:47.441 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/opt//tomcat/webapps/.war] has finished in [1,763] ms",
"@timestamp" => 2025-02-11T17:52:07.044885Z
}
{
"message" => "[<2 11, 2025 11:02:52 AM>: \n needto=Y\n]",
"@timestamp" => 2025-02-11T17:52:07.028376Z
}
{
"message" => "11-Feb-2025 11:02:47.442 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/opt//tomcat/webapps/.war]",
"@timestamp" => 2025-02-11T17:52:07.045139Z
}
{
"message" => "[<2 11, 2025 11:02:52 AM>: .getFlag: close statement]",
"@timestamp" => 2025-02-11T17:52:07.029996Z
}
{
"message" => "11-Feb-2025 11:02:47.443 WARNING [main] org.apache.tomcat.util.digester.SetPropertiesRule.begin Match [Context/Manager] failed to set property [expireSessionsOnShutdown] to [false]",
"@timestamp" => 2025-02-11T17:52:07.045369Z
}
{
"message" => "[<2 11, 2025 11:02:47 AM>: - getRedirectFilter: close statement]",
"@timestamp" => 2025-02-11T17:52:07.026848Z
}
{
"message" => "11-Feb-2025 11:02:47.438 WARNING [main] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [] appears to have started a thread named [InterruptTimer] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:\n java.lang.Object.wait(Native Method)\n java.lang.Object.wait(Object.java:502)\n java.util.TimerThread.mainLoop(Timer.java:526)\n java.util.TimerThread.run(Timer.java:505)",
"@timestamp" => 2025-02-11T17:52:07.044647Z
}
{
"message" => "[<2 11, 2025 11:02:47 AM>: - getRedirectFilter]",
"@timestamp" => 2025-02-11T17:52:07.026490Z
}
{
"message" => "11-Feb-2025 11:02:47.437 WARNING [main] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [] appears to have started a thread named [oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:\n java.lang.Object.wait(Native Method)\n oracle.jdbc.driver.BlockSource$ThreadedCachingBlockSource$BlockReleaser.run(BlockSource.java:331)",
"@timestamp" => 2025-02-11T17:52:07.043994Z
}
{
"message" => "11-Feb-2025 11:02:47.028 SEVERE [main] org.apache.tomcat.jdbc.pool.ConnectionPool.init Unable to create initl connections of pool.\n java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection\n at oracle.jdbc.driver..logon(.java:903)\n at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:820)\n at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:80)\n at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:816)\n at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:343)\n at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:474)\n Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:720)\n at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:586)\n at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:729)\n at oracle.net.ns.NSProtocol.connect(NSProtocol.java:340)\n at oracle.jdbc.driver..connect(.java:1702)\n at oracle.jdbc.driver..logon(.java:627)\n ... 64 more\n Caused by: java.net.UnknownHostException: ..org\n at java.net..0(.java:1281)\n at java.net..(.java:1193)\n at java.net..(.java:1127)\n at oracle.net.nt..connect(.java:162)\n at oracle.net.nt.ConnOption.connect(ConnOption.java:195)\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)\n ... 69 more",
"@timestamp" => 2025-02-11T17:52:07.043457Z
}
{
"message" => "[<2 11, 2025 11:16:02 AM>: HelperDAO.getCountryCodes: close statement]",
"@timestamp" => 2025-02-11T17:52:07.031613Z
}
{
"message" => "11-Feb-2025 11:20:33.548 INFO [main] org.apache.2..Listener.info Starting 2 integration ...\nERROR could not find a logging implementation. Please add to the classpath. Using SimpleLogger to log to the console...",
"@timestamp" => 2025-02-11T17:52:07.048270Z
}
{
"message" => "[<2 11, 2025 11:16:02 AM>: Exception: \nUnable to lookup datasource: java:comp/env/jdbc/DataSource\norg...util.DBHelper.getDataSource(DBHelper.java:124)\norg...services.dao.helper..getCountryCodes(.java:70)\norg...services.implementations.helper.HelperServicesImpl.getCountryCodes(HelperServicesImpl.java:29)\norg...web.ContextListener.initlizeContext(ContextListener.java:70)\norg...web.ContextListener.contextInitlized(ContextListener.java:62)\n]",
"@timestamp" => 2025-02-11T17:52:07.031108Z
}
{
"message" => "11-Feb-2025 11:02:51.528 INFO [main] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.\n: Failed to load class \"org..impl.\".\n: Defaulting to no-operation (NOP) logger implementation\n: See http://www..org/codes.html# for further details.\n at oracle.jdbc.driver..logon(.java:627)\n ... 73 more\nCaused by: java.net.UnknownHostException: ..org\n at java.net..0(.java:1281)\n at java.net..(.java:1193)\n at java.net..(.java:1127)\n at oracle.net.nt..connect(.java:162)\n at oracle.net.nt.ConnOption.connect(ConnOption.java:195)\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)\n ... 78 more\n-- Caused by: --\njavax.naming.NamingException: Unexpected exception resolving reference [Root exception is java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection]\n at org.apache.naming.NamingContext.lookup(NamingContext.java:882)\n at org.apache.naming.NamingContext.lookup(NamingContext.java:160)\n at java.net..(.java:1127)\n at oracle.net.nt..connect(.java:162)\n at oracle.net.nt.ConnOption.connect(ConnOption.java:195)\n at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:653)\n ... 78 more",
"@timestamp" => 2025-02-11T17:52:07.047907Z
}
Please try to reproduce this using the exact config and steps.
I don't see any big difference between yours and mine.
this is how my config is.
input {
file {
path => "/opt/logs/catalina.out"
start_position => "beginning"
sincedb_path => "/dev/null"
codec => multiline {
pattern => "^\[|^\d{2}-\w{3}-\d{4}"
negate => "true"
what => "previous"
auto_flush_interval => 5
}
}
}
filter {
mutate {
remove_field => [ "host", "@version", "event" ]
}
}
output {
elasticsearch {
hosts => ["http://elkstack:9200"]
index => "dev01"
user => "elastic"
password => "***"
}
}
I really don't see any big difference between your config and my config. do you still think i need to have it exactly like yours?
now, I ran my logstash with the exact config of mine as above and I got the correct results for today. This is what I have been noticing. I get the expected results when the first time I run it. but when the log file gets deleted and recreated tomorrow morning that's when I don't see the expected results. which is weird
the file from tomorrow is still being parsed but it is only giving me the results that start with 11-Feb-2025 and ignores the messages that starts with [<2 11, 2025
and i have noticed in the log file. the first message always starts with [<2 11, 2025 and the last message starts with 11-Feb-2025. maybe it is somehow getting confused with both the patterns and only continues to find the next match in the new file that is previously found in the old log which is 11-Feb-2025
i don't know if it makes sense of what i am trying to explain here
Our patterns are different
Mine
Yours
Not sure that matters...
But you don't have to wait till tomorrow
Why not Just make a copy of the log file point your logstash to it, run it, delete it and copy it back and see what happens... Follow my methodology above and see what happens... Using your config or mine at least you don't have to wait for once a day to figure it out... Or save off today's file and get a copy of tomorrow's file and you can try that..
My example followed exactly what you said. Started and ended with the same log line types that you just mentioned...
I'm sure you'll figure it out...
Question, does the end of the log have a fresh newline or does it not...
Not sure How to help...
Perhaps @Badger can comment now that we're on the same page.
This increasingly sounds like inode re-use and logstash is skipping the first x bytes of today's log where x is the length of yesterday's log. This is why Stephen kept asking about how the log file rotation was done.
If the file is truncated and then overwritten the file input will lose data. If the file is deleted and then newly created it can lose data if it is unlucky enough to get the same inode from the inode cache (assuming that your filesystem caches free inodes in the first place).
It is hard to see how the codec could ignore one of the patterns. If one of the patterns were wrong it would result in extra lines being appended to some of the events (the ones with the pattern that works).
If the input is failing to read the data then the only things I can think of are start_position being incorrect or inode re-use. If it were an unsupported network file system the problem would more likely be duplicated data than missing data.
1 Like
yeah, same issue come today. it captured all the log entries that start with 12-Feb-2025 and ignored all the entries starting with [<2 12, 2025. weird.
i don't know what else to try here.
I changed my pattern to just have one
pattern => "^\[<\d{1,2}"
I wanted to see if atleast it will capture all the messages starting with [<2 come tomorrow.
How do you know it is ignoring them? What exactly are you checking to see if the text from those lines is in elasticsearch?
oh, I have Kibana and I go to discover index and search for something like "AM or PM". it gave me results from yesterday but nothing today. i got results for today if i search for something like "12-Feb"