Queries Fail due to invalid dates

[GoogleCodeExporter]

What steps will reproduce the problem?
Not sure how to reproduce beyond my setup, but I have an archlinux server 
running the elsa node instance, and an Ubuntu 12.04 server running the 
webserver instance.
I have bro running on the node server, and bro flatfiles go into syslog go into 
elsa

What is the expected output? What do you see instead?
When I run queries, I expect to get a response. Instead (no matter what start 
or end dates I put) I get the error:
Invalid start or end: Wed Dec 31 19:00:00 1969 Wed Dec 31 19:00:00 1969 at 
/usr/local/elsa/web/lib/Query.pm line 656.

What version of the product are you using? On what operating system?
Latest from SVN on Ubuntu 12.04 and archlinux

Please provide any additional information below.
Both systems' clocks are synchronized with ntp.

Original issue reported on code.google.com by i...@pingas.org on 6 Jul 2012 at 5:41

[GoogleCodeExporter]

This indicates that the frontend is not finding any logs because there are no 
indexes listed.  The 1969 dates mean that the found "start" and "end" dates 
were "0."  Are you able to see any logs with any query?  What is the output of 
this query on the node?
mysql syslog -e "select * from v_indexes order by start"

Original comment by mchol...@gmail.com on 7 Jul 2012 at 4:02

[GoogleCodeExporter]

I get a response "Empty set (0.00 sec)".
Something must be wrong with the indexer.
I have been trying to port ELSA to Arch Linux for some time now, and even after 
getting everything installed and configured it seems I'm still missing 
something!
The installer script simply doesn't work on Arch Linux, so I've had to package 
everything on my own... I'd love your help as the company I work for wants to 
make ELSA a pretty big part of our log parsing.
Perhaps we should merge this bug into the Arch Linux support bug and go from 
there?

Arch Linux uses a system known as the Arch Build System to package/install 
software. For my first ABS script handling ELSA, you can look at 
https://aur.archlinux.org/packages/el/elsa/PKGBUILD for a bash script that 
installs the files and dependencies needed for ELSA.

If you were to provide a tarball and rely on the end-user to configure each 
part of the entire 'ELSA' system individually, this would greatly increase the 
portability and extensiblity of your software. I will gladly help you as much 
as I can to get configuration for each part of ELSA written.

One thing I cannot figure out is why my indexes aren't getting indexed. I'm not 
sure if it's syslog-ng or sphinx that isn't doing its work. What can we do to 
figure out what part of the system isn't working?

Original comment by i...@pingas.org on 9 Jul 2012 at 12:55

[GoogleCodeExporter]

Ok, let's try to get your setup working on Arch, then we'll see what's involved 
with the overall process to hopefully provide canonical support for Arch.

First things: If you remove any times listed and run a search for "seq" what do 
you get?  (seq is input in the initial test run so it should be there.)

Next: What do you have for indexes on your node?  You can find with:
mysql syslog -e "select * from v_indexes order by start"

Original comment by mchol...@gmail.com on 9 Jul 2012 at 2:06

[GoogleCodeExporter]

"Invalid start or end: Wed Dec 31 19:00:00 1969 Wed Dec 31 19:00:00 1969 at 
/usr/local/elsa/web/lib/Query.pm line 656."
Even though both time boxes are blank, I still get this error when searching 
for "seq".

I have no indexes on my node, as that mysql command returns nothing.

Original comment by i...@pingas.org on 9 Jul 2012 at 2:09

[GoogleCodeExporter]

I have changed the /etc/elsa_node.conf and /etc/sphinx/sphinx_elsa.conf files, 
and I've at least got something in my v_indexes table now. However, I have set 
up syslog-ng to take data from some Bro flatfiles and I still cannot see it 
when I make a query.

Original comment by i...@pingas.org on 10 Jul 2012 at 1:33

[GoogleCodeExporter]

Do you see anything if you run the same query in archive mode?  You can switch 
to archive using the drop-down menu labeled "Index."

Original comment by mchol...@gmail.com on 10 Jul 2012 at 2:04

[GoogleCodeExporter]

Running in archive mode is giving me a few results, but nothing related to what 
Bro is logging. Looking at the syslog db in my MySQL, there is no data 
currently being taken from Bro or syslog-ng.

Original comment by i...@pingas.org on 10 Jul 2012 at 3:37

[GoogleCodeExporter]

Ok, let's make sure there's no problem with elsa.pl.  On the log node, run:
echo "testing 123" | perl elsa.pl -on
Are there any errors listed?

Original comment by mchol...@gmail.com on 10 Jul 2012 at 4:49

[GoogleCodeExporter]

This is what I get:

isaac@archie ~ $ sudo bash -c "echo 'testing 123' | perl 
/usr/share/elsa/node/elsa.pl -on -c /etc/elsa/elsa_node.conf"
testing
isaac@archie ~ $

Searching for "testing" in both Archive and Index mode does not return any 
results.

Original comment by i...@pingas.org on 10 Jul 2012 at 5:18

[GoogleCodeExporter]

Ok, look for any errors in the log file, there should be an indication of what 
it decided to do, since it didn't die with any fatal errors.

Original comment by mchol...@gmail.com on 10 Jul 2012 at 5:37

[GoogleCodeExporter]

Where does the perl script log to?

Original comment by i...@pingas.org on 10 Jul 2012 at 5:38

[GoogleCodeExporter]

Nevermind, I found node.log
I have a *lot* of lines that look like either of these two:

* ERROR [2012/07/10 13:39:08] /usr/share/elsa/node/Writer.pm (122) 
Writer::_sql_error_handler 28189 SQL_ERROR: DBD::mysql::st execute failed: 
called with 653 bind variables when 468 are needed, query: INSERT INTO 
syslog_data.syslogs_archive_1 (id, timestamp, host_id, program_id, class_id, 
msg, i0, i1, i2, i3, i4, i5, s0, s1, s2, s3, s4, s5) VALUES 
(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?
,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?
,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?
,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?
,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?
,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?
,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?
,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?
,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?
),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?
,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?
,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?),(?,?,?,?,?
,?,?,?,?,?,?,?,?,?,?,?,?,?)
* WARN [2012/07/10 13:39:09] /usr/share/elsa/node/Reader.pm (228) 
Reader::parse_line 28189 Missing required field class id

Original comment by i...@pingas.org on 10 Jul 2012 at 5:40

[GoogleCodeExporter]

Uh oh, looks like realtime's not working for you.  Uncomment the "realtime" 
section in the elsa_node.conf file and restart syslog-ng.  Then hopefully your 
Bro logs start showing up.

Original comment by mchol...@gmail.com on 10 Jul 2012 at 5:46

[GoogleCodeExporter]

After disabling realtime, I'm still unable to find anything bro-related, and I 
have many sets of lines similar to this in my node.log file

isaac@archie ~ $ tail -n 21 /srv/elsa/log/node.log
Copyright (c) 2001-2012, Andrew Aksyonoff
Copyright (c) 2008-2012, Sphinx Technologies Inc (http://sphinxsearch.com)

using config file '/etc/sphinx.conf'...
WARNING: no such index 'temp_1014', skipping.
total 0 reads, 0.000 sec, 0.0 kb/call avg, 0.0 msec/call avg
total 0 writes, 0.000 sec, 0.0 kb/call avg, 0.0 msec/call avg
* TRACE [2012/07/10 13:53:28] /usr/share/elsa/node/Indexer.pm (1421) 
Indexer::_sphinx_index 8589 ran cmd: /usr/bin/sphinx-indexer --config 
/etc/sphinx.conf --rotate temp_1014 2>&1
* ERROR [2012/07/10 13:53:28] /usr/share/elsa/node/Indexer.pm (1440) 
Indexer::_sphinx_index 8589 Hit retry limit of 3
* ERROR [2012/07/10 13:53:28] /usr/share/elsa/node/Indexer.pm (1446) 
Indexer::_sphinx_index 8589 Indexing didn't work for temp_1014, output: $VAR1 = 
[
          'Sphinx 2.0.4-id64-release (r3135)',
          'Copyright (c) 2001-2012, Andrew Aksyonoff',
          'Copyright (c) 2008-2012, Sphinx Technologies Inc (http://sphinxsearch.com)',
          '',
          'using config file \'/etc/sphinx.conf\'...',
          'WARNING: no such index \'temp_1014\', skipping.',
          'total 0 reads, 0.000 sec, 0.0 kb/call avg, 0.0 msec/call avg',
          'total 0 writes, 0.000 sec, 0.0 kb/call avg, 0.0 msec/call avg'
        ];
* INFO [2012/07/10 13:53:28] /usr/share/elsa/node/Indexer.pm (1450) 
Indexer::_sphinx_index 8589 Indexed temp_1014 with 0 rows in 0.09198 seconds 
(0.00000 rows/sec)
* DEBUG [2012/07/10 13:53:28] /usr/share/elsa/node/Indexer.pm (437) 
Indexer::_validate_directory 8589 Wiping via index perm_1014

Original comment by i...@pingas.org on 10 Jul 2012 at 5:54

[GoogleCodeExporter]

Your above message indicated you were using /etc/sphinx/sphinx_elsa.conf, but 
that error says it's trying to use /etc/sphinx.conf.  You may need to change 
the setting in your elsa_node.conf to match.

Original comment by mchol...@gmail.com on 10 Jul 2012 at 6:04

[GoogleCodeExporter]

They are symlinked.

Original comment by i...@pingas.org on 10 Jul 2012 at 6:05

[GoogleCodeExporter]

Ok, well is there a configuration for "temp_1014" in the sphinx.conf?  
Otherwise, it looks like you changed the setting for number of indexes but 
didn't recreate the sphinx.conf file.  (This can be done easily by simply 
deleting or moving it, ELSA will autocreate it.)

Original comment by mchol...@gmail.com on 10 Jul 2012 at 6:08

[GoogleCodeExporter]

There is not a configuration for temp_1014. I've deleted the sphinx.conf file 
but elsa seems to have rebuilt it incorrectly.

Jul 10 14:22:39 archie searchd[15222]: ERROR: line too long in 
/etc/sphinx/sphinx_elsa.conf line 52182 col 1.

I have attached my sphinx.conf file.

Original comment by i...@pingas.org on 10 Jul 2012 at 6:27

Attachments:

• sphinx.conf

[GoogleCodeExporter]

I think you have way too many indexes. Set "num_indexes" down to something like 
400.

Original comment by mchol...@gmail.com on 10 Jul 2012 at 6:34

[GoogleCodeExporter]

Alright, I've lowered the number of indexes. I can search for things in archive 
mode (a search for "bro" returned an error bro gave me upon restart of the 
node. Hurray!) but I get an error when making queries in the "index" mode:

No nodes available at /usr/local/elsa/web/lib/API.pm line 1771.

I'm not exactly sure what this means.

Original comment by i...@pingas.org on 10 Jul 2012 at 7:00

[GoogleCodeExporter]

"No nodes available" implies a problem trying to connect to searchd.  Make sure 
that the port listed in elsa_web.conf for "nodes/<node>/mysql_port" matches the 
port that searchd is listening on (9306, by default, 3307 in older ELSA 
implementations).

Original comment by mchol...@gmail.com on 10 Jul 2012 at 7:17

[GoogleCodeExporter]

I have gotten queries working (it was an iptables issue), but I do not seem to 
have any useful patterndb action going on. Queries are surprisingly blank.

What am I forgetting? This is what happens when I click "info" on a bro_http 
event.

Original comment by i...@pingas.org on 16 Jul 2012 at 1:36

Attachments:

• [patterndb not working.PNG](https://storage.googleapis.com/google-code-attachments/enterprise-log-search-and-archive/issue-41/comment-22/patterndb not working.PNG)

[GoogleCodeExporter]

I think it's related to my syslog-ng configuration, so I've also attached that.

I followed the Bro section of the Documentation page, by the way.

Original comment by i...@pingas.org on 16 Jul 2012 at 1:38

Attachments:

• syslog-ng.conf.txt

[GoogleCodeExporter]

Ah, the problem is indeed in your syslog-ng.conf.  You are doing individual log 
{} statements for Bro, such as:
log { source(s_bro_communication); destination(d_elsa); };
But that doesn't do all of the rewriting, etc. like in the above:
log { 
    source(s_network);
    rewrite(r_host);
    rewrite(r_cisco_program);
    rewrite(r_snare);
    rewrite(r_pipes);
    parser(p_db);
    rewrite(r_extracted_host); 
    destination(d_elsa);
};

So, you need to add the Bro statements in like this:

log { 
    source(s_network);
        source(s_bro_communication);
        source(s_bro_conn);
        source(s_bro_dns);
        source(s_bro_http);
        source(s_bro_known_services);
        source(s_bro_notice);
        source(s_bro_software);
        source(s_bro_stderr);
        source(s_bro_stdout);
        source(s_bro_ssl);
        source(s_bro_weird);
    rewrite(r_host);
    rewrite(r_cisco_program);
    rewrite(r_snare);
    rewrite(r_pipes);
    parser(p_db);
    rewrite(r_extracted_host); 
    destination(d_elsa);
};

Original comment by mchol...@gmail.com on 16 Jul 2012 at 1:53

[GoogleCodeExporter]

I notice that there are lines like this as well:
source s_bro_ssl { file("/var/log/bro/current/ssl.log" flags(no-parse) 
program_override("bro_ssl")); };
That have the "flags(no-parse)" option. Is that going to interfere with the 
patterndb parsing later on in the log directive?

Original comment by i...@pingas.org on 16 Jul 2012 at 1:56

[GoogleCodeExporter]

No, the no-parse flag is separate and applies only to the log source.  
PatternDB parsing applies to all logs in the log {} chain it's in, regardless 
of source.

Original comment by mchol...@gmail.com on 16 Jul 2012 at 2:20

[GoogleCodeExporter]

Closing for now due to inactivity.

Original comment by mchol...@gmail.com on 29 Nov 2012 at 10:33

• Changed state: Done