[syslog-ng] load failures in afsocket and afsql
Balazs Scheidler
bazsi at balabit.hu
Fri Dec 17 14:51:12 CET 2010
On Thu, 2010-12-16 at 23:26 -0600, Martin Holste wrote:
> Congrats! Go do some gambling because your karma has to be extremely
> positive at this point!
>
> On Thu, Dec 16, 2010 at 10:32 PM, Matthew Hall <mhall at mhcomputing.net> wrote:
> > I think this patch might well fix it.
> >
> > I tried it with the patch just now and it seemed to launch OK.
> >
> > Matthew.
> >
> > On Thu, Dec 16, 2010 at 08:20:44PM -0800, Matthew Hall wrote:
> >> Untested patch:
> >>
> >> --- /home/megahall/dbparser.c 2010-12-16 20:07:03.000000000 -0800
> >> +++ syslog-ng-3.2.1/modules/dbparser/dbparser.c 2010-12-16 20:14:59.000000000 -0800
> >> @@ -140,6 +140,11 @@
> >> else
> >> {
> >> log_db_parser_reload_database(self);
> >> + /* XXX: mhall: repair corruption of persistent config */
> >> + if (self->db)
> >> + {
> >> + cfg_persist_config_add(cfg, log_db_parser_format_persist_name(self), self->db, (GDestroyNotify) pattern_db_free, FALSE);
> >> + }
> >> }
> >>
> >> self->timer_tick_id = g_timeout_add_seconds(1, log_db_parser_timer_tick, self);
> >>
> >> Matthew.
> >>
> >> On Thu, Dec 16, 2010 at 08:06:43PM -0800, Matthew Hall wrote:
> >> > On Thu, Dec 16, 2010 at 04:55:09PM -0600, Martin Holste wrote:
> >> > > Keep fighting the good fight, hopefully you'll get some hints soon.
> >> > > You're well outside the range of my debugging-fu at this point.
> >> > >
> >> > > On Thu, Dec 16, 2010 at 3:34 PM, Matthew Hall <mhall at mhcomputing.net> wrote:
> >> > > > Getting closer.
> >> > > >
> >> > > > The problem goes away when the XML pattern DB is disabled. The problem
> >> > > > does not appear if the XML pattern db is used in one log {} per below.
> >> > > > Once it is used in two log {} blocks, KABOOM! I'm going to try debugging
> >> > > > the other half of this which writes to the persistent store to see if I
> >> > > > can sort out what's breaking the write. For what it's worth, the problem
> >> > > > shows up in both 32 and 64 bit.
> >> > > >
> >> > > > Matthew.
> >> >
> >> > I think the problem could be found now. In the log_db_parser_deinit,
> >> > there is a call to cfg_persist_config_add but there is no corresponding
> >> > call in log_db_parser_init.
> >> >
> >> > When the db_parser is referenced once in the config file, self->db is
> >> > NULL, so log_db_parser_reload_database is called to create the right
> >> > data structure. It's important to remember that this is going to set
> >> > self->db_file_inode and self->db_file_mtime.
> >> >
> >> > When the db_parser is referenced again in the config file, self->db
> >> > should be non NULL because the db_parser was supposed to be persisted.
> >> >
> >> > Bug 1) When we call cfg_persist_config_fetch but we get NULL again so we
> >> > call log_db_parser_reload_database again.
> >> >
> >> > Bug 2) (Unrelated to my issue) Even if we had stored the db_parser, if
> >> > we call stat, we just copy the new inode and mtime, and do not reload
> >> > the patterns. So configuration reloads will probably not refresh the
> >> > pattern DB.
> >> >
> >> > Now in my case when we go into log_db_parser_reload_database the second
> >> > time, we have a check if the DB file exists. If no we have an error.
> >> > Fair enough. But if yes, then we check if self->db_file_inode and
> >> > self->sb_file_mtime have changed, or not.
> >> >
> >> > If they have not changed, we return right away, without initializing the
> >> > self->db. But we have already destroyed the valid self->db pointer from
> >> > the first initialization, by replacing it with the retval from
> >> > cfg_persist_config_fetch, which was NULL because the config was not
> >> > persisted.
> >> >
> >> > Now we check self->db again at the end of log_db_parser_init where we
> >> > find it has become NULL. This we return a failing retval because we
> >> > never suceeded in initializing the log_db_parser to a non-NULL value.
> >> >
> >> > We pass this error many frames up the stack until we hit the "Error
> >> > initializing message pipeline" in log_center_init.
> >> >
> >> > This goes a few frames up, until we exit with an error code.
> >> >
> >> > I think the patch would be adding code to log_db_parser_init and/or
> >> > log_db_parser_reload_database, which calls cfg_persist_config_add. I am
> >> > going to try this Monday since I'm off tomorrow and see what I get.
> >> >
> >> > Could somebody else try making a config which references the EXACT SAME
> >> > patterndb file twice in two log {} blocks and see if it blows up for
> >> > them as well? I want to try to eliminate as many environment specific
> >> > issues as possible. I described the config you need in my previous mail.
> >> >
> >> > Regards,
> >> > Matthew.
> >> >
> >> > static gboolean log_db_parser_init(LogParser *s, GlobalConfig *cfg)
> >> > {
> >> > LogDBParser *self = (LogDBParser *) s;
> >> >
> >> > self->db = cfg_persist_config_fetch(cfg, ***log_db_parser_format_persist_name***(self));
> >> > if (self->db)
> >> > {
> >> > struct stat st;
> >> >
> >> > if (stat(self->db_file, &st) < 0)
> >> > {
> >> > msg_error("Error stating pattern database file, no automatic reload will be performed",
> >> > evt_tag_str("error", g_strerror(errno)),
> >> > NULL);
> >> > }
> >> > else
> >> > {
> >> > self->db_file_inode = st.st_ino;
> >> > self->db_file_mtime = st.st_mtime;
> >> > }
> >> > }
> >> > else
> >> > {
> >> > log_db_parser_reload_database(self);
> >> > }
> >> >
> >> > self->timer_tick_id = g_timeout_add_seconds(1, log_db_parser_timer_tick, self);
> >> > return self->db != NULL;
> >> > }
> >> >
First of all thanks for tracking this down, and sorry that
1) there's a bug in the first place
2) I wasn't here to help out.
But anyway, reading through code is always a useful experience, you'll
be able to resolve much more complex issues next time. :)
About the patch:
I'm afraid it is not the correct solution, and I don't see an easy way
forward, since you're using db-parser() in a way that I planned to
explicitly restrict, and in my 3.3 codebase there's an explicit check
that the same db-parser() instance cannot be used multiple times, but
that has not (yet) trickled to 3.2.
But maybe we can come up with a better solution than my "restriction",
since I thought that it can be reasonably said that only one db-parser()
instance is needed in a configuration.
But anyway, here's the root cause:
1) starting with 3.2 we do have correllation capabilities with
db-parser(), which also sports a feature to generate new messages.
2) I intend these messages to "appear" from the db-parser() instance,
e.g. they wouldn't be reposted from the internal() source as in 3.2, but
would original from the db-parser() where it is referenced from a log
path.
3) this means that a single db-parser() instance can have only _one_
outgoing side, or otherwise I wouldn't know where to post messages.
The reason the db-parser() saves something to the "persist" store is
that it has to save the correllation state accross SIGHUPs, so that a
reload doesn't empty your complete correllation state.
Using the same state in two independent db-parser() instances is
probably not what you want.
I'll check you I could fix your use-case, but I need some thinking time.
I just wanted to drop this mail so that you know that I'm alive, I was
just distracted by other things.
Also, I appreciate your time you spent on diagnosing this issue. If you
spotted anything in the code that could have helped your diagnosis (e.g.
missing code comments) I'd be happy to get some feedback.
Thanks.
--
Bazsi
More information about the syslog-ng
mailing list