Bug 65982 - updating of chat window takes ages when there are many messages
Summary: updating of chat window takes ages when there are many messages
Status: RESOLVED LATER
Alias: None
Product: kopete
Classification: Applications
Component: History Plugin (show other bugs)
Version: unspecified
Platform: Compiled Sources Linux
: NOR normal
Target Milestone: ---
Assignee: Kopete Developers
URL:
Keywords:
: 81002 83215 (view as bug list)
Depends on:
Blocks:
 
Reported: 2003-10-13 20:07 UTC by Jesse
Modified: 2005-11-14 19:02 UTC (History)
4 users (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments
historyYagami.diff (6.37 KB, text/x-diff)
2004-07-17 21:32 UTC, Alexandre Pereira
Details
historyYagami.diff (5.20 KB, text/x-diff)
2004-07-17 22:51 UTC, Alexandre Pereira
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Jesse 2003-10-13 20:07:13 UTC
Version:            (using KDE Devel)
Installed from:    Compiled sources
OS:          Linux

Whenever there are many messages in the chat window and more messages come in, my CPU hits 100% for about a second or two trying to update the chat window.  During this time no painting will occur.  Now I have a P4 3.06 HT CPU so this shouldn't be the issue.  I tried several different styles but they are all equally horrible.  I have kopete set to display 300 messages but even when there are much fewer than that, I still see quite a bit of CPU hogging going on.  Makes IRC completely useless for chanels like kde-devel etc. -- that in and of itself could be a showstopper.

I compile from source using --disable-debug and C and CXXFLAGS of
--mcpu=pentium4 -O2 -fomit-frame-pointer -fPIC -pipe

This should be looked at before 3.2 final hits.
Comment 1 Jason Keirstead 2003-10-13 20:39:52 UTC
Subject: Re: [Kopete-devel]  New: updating of chat window takes ages when there are many messages

> Whenever there are many messages in the chat window and more messages come
> in, my CPU hits 100% for about a second or two trying to update the chat
> window.  During this time no painting will occur.  Now I have a P4 3.06 HT
> CPU so this shouldn't be the issue.  I tried several different styles but
> they are all equally horrible.  I have kopete set to display 300 messages
> but even when there are much fewer than that, I still see quite a bit of
> CPU hogging going on.  Makes IRC completely useless for chanels like
> kde-devel etc. -- that in and of itself could be a showstopper.
>

Since Kopete just appends new messages using the KHTML DOM, any bugs relating
to rendering speed on DOM appends should be posted there.


Comment 2 Casey Allen Shobe 2003-10-13 20:42:49 UTC
I can reproduce this.  I thought in might be related to the sound effects (I 
have a rather large sound buffer configured for artsd), but I have not played 
around to check.  I have a P4 2.4GHz and 1Gb dual-channel DDR RAM.  Quite 
silly ;-) 
 
I'll play with the sound effect options later. 
Comment 3 Martijn Klingens 2003-10-13 21:23:44 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Monday 13 October 2003 20:42, Casey Allen Shobe wrote:
> I can reproduce this.  I thought in might be related to the
> sound effects (I have a rather large sound buffer configured for artsd),
> but I have not played around to check.  I have a P4 2.4GHz and 1Gb
> dual-channel DDR RAM.  Quite silly ;-)
>
> I'll play with the sound effect options later.

Better: try using kcachegrind to get some real profiling information.

See e.g. http://www.blackie.dk/~dfaure/n7y/Debugging/html/slide_7.html

I'm curious to see where most CPU time goes.

Comment 4 Jesse 2003-10-13 21:27:16 UTC
I've used cachegrind before as I hack on Kate every once in a while but I'm not sure if 
I'll be able to isolate the problem as it takes a while before lots of messages are in 
there.  I'll see what I can come up with ... though I'm not sure if letting it run for hours 
will bring out the CPU hogs even more or water them down to almost nothing.   I'll 
keep in touch. 
Comment 5 Martijn Klingens 2003-10-13 21:34:18 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

Thanks in advance already (cachegrind is even slower than valgrind and is 
REALLY unworkable on my Celeron 450, so I can't do this myself :( ), and 
maybe a hint:

Create an empty channel, join it with Kopete and another client and spam from 
the other client. As long as you avoid the excess flood that should help you 
to force the problem sooner than a 'real' channel ever can.

Comment 6 Jesse 2003-10-13 23:13:08 UTC
Ah, thanks for the hint.  Yeah I tried just connecting to kde-devel ... but the stream of 
messages (if you'd call them that most of the time) just saturated my CPU and I 
couldn't do anything.  So I made my own channel and spammed myself with Gaim.   
 
Good news and bad news.  The good news is I was retarded and forgot I had the 
history plugin enabled (which happens to work with XML and write out to disk fairly 
often)--so that might be the issue or at least a lead on to where to start. The bad news 
is is that even this test with a private chat is a pain to do and I haven't done one with 
history disabled.  But if you want one I can do one maybe later tonight :) 
 
Interesting still though.  Some things that I've seen with a very cursory look (obviously 
needs a better look though): 
1) There are quite a few,very expensive calls to the regular expression engine? Why? 
2) Both IRC and History plugin share responsibility for the mess 
 
KopeteMessage::setBody seems to be problematic with the regular expression calls 
and so forth.  KopeteMessageManager::appendMessage doesn't seem to do much 
harm. 
 
The calltree output is here on my server (7.5megs) for interested parties 
http://omega.cs.iit.edu/~jesse/cachegrind.out.28929 
 
Comment 7 Jesse 2003-10-14 00:32:50 UTC
Hmm, now that I've turned history off, kde-devel works fine now.  No long pauses 
anymore and no CPU spikes.  The history file was 345k before I turned it off.  Guess 
it's just a sideeffect of using xml and updating the file.  But 345k is not a whole lot and 
I've routinely had logs in the 2+meg area before a weekly logrotate gobbled them up ... 
 
Perhaps a more braindead approach to the file (just spit the text out with some 
formatting) and forget pure XML.  Or stick it in a thread of somesort and maybe batch 
the messages so the file is only updated every so often -- with risk of loosing messages 
in case of crash -- but that shouldn't happen anyway ;) 
Comment 8 Martijn Klingens 2003-10-14 10:17:57 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

Thanks for all your testing, it's quite valuable.

Yes, we should probably try to reduce our use of regexps a bit, but that's not 
so easy to do, Kopete does a lot of string manipulations and many of them do 
need regexps or complex hand-written loops.

I won't be able to look at your calltrace before the weekend, so please leave 
it on your server until at least then :)

Comment 9 Jason Keirstead 2003-10-14 13:22:47 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On October 13, 2003 06:13 pm, Jesse Yurkovich wrote:

> Good news and bad news.  The good news is I was retarded and forgot I had
> the history plugin enabled (which happens to work with XML and write out to
> disk fairly often)--so that might be the issue or at least a lead on to
> where to start. The bad news is is that even this test with a private chat
> is a pain to do and I haven't done one with history disabled.  But if you
> want one I can do one maybe later tonight :)

Neither of these would have any effect on the original issue, namely that the
window slows down as more messages are appended. This would only affect 
the mean time of each message in general.

> Interesting still though.  Some things that I've seen with a very cursory
> look (obviously needs a better look though):
> 1) There are quite a few,very expensive calls to the regular expression
> engine? Why? 2) Both IRC and History plugin share responsibility for the
> mess

See above. While I know there quite a few regexps done on each message,
some for emotiocons, some for IRC RTF, these are done for each and every
message and would not get slower as more messages arrive.

It seems to me we are losing sight of the issue. The bug report is not that
message appends are slow in general, it is that they get slower and slower
with each message appended, and when the window fill sup they take on
the order of seconds.

As I posted above the only thing that I can see that could be causing this is
KHTML's rendering of DOM node appends, since Kopete itself only renders
the messages one by one and then appends then result HTML through the
DOM, unless the style is updated.


Comment 10 Jason Keirstead 2003-10-14 22:30:35 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On October 13, 2003 07:32 pm, Jesse Yurkovich wrote:
> ------- Additional Comments From yurkjes@iit.edu  2003-10-14 00:32 -------
> Hmm, now that I've turned history off, kde-devel works fine now.  No long
> pauses anymore and no CPU spikes.  

Having just looked at the history plugin code I can tell you *exactly* what is causing
this problem.

Every time you get a new message, this history plugin is loading the file on disk
into a QDomDocument and appending the message to it, and then dumping it to
disk again.

This is an incredibly slow way to do this logging.

Before this plugin was written, the code that I had to write the XML logs to disk did not
do this. It used an ( admittedly hackish ) mechanism of appending the log strings directly
onto the end of the file without using the QDOM.

A simmilar thing needs to be done here, loading the whole QDOM every time and appending
nodes is way too slow. Needless to say, this slowdown will occurr not only as the chat window
fills up, but as the log *file* fills up, which means even closing and re-opening the chat will not
save you.


Comment 11 Martijn Klingens 2003-10-15 10:06:07 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Tuesday 14 October 2003 22:30, Jason Keirstead wrote:
> Every time you get a new message, this history plugin is loading the file on
> disk into a QDomDocument and appending the message to it, and then dumping
> it to disk again.

*** OUCH ***

> Before this plugin was written, the code that I had to write the XML logs to
> disk did not do this. It used an ( admittedly hackish ) mechanism of
> appending the log strings directly onto the end of the file without using
> the QDOM.

Hmm, alternatively, and ensuring the DOM is always correct XML, would it be an 
alternative to keep the DOM tree in memory and store it every time? I'd say 
loading is the slow part, not appending nodes and converting to ascii. OTOH, 
it might eat memory alive :(

Comment 12 Jason Keirstead 2003-10-15 13:41:30 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On October 15, 2003 5:06 am, Martijn Klingens wrote:

> Hmm, alternatively, and ensuring the DOM is always correct XML, would it be
> an alternative to keep the DOM tree in memory and store it every time? I'd
> say loading is the slow part, not appending nodes and converting to ascii.
> OTOH, it might eat memory alive :(

Yes, indeed it would would eat memory like it was going out of business. Also 
I do not believe that the QDom is really fast... appending nodes ot it is 
nowhere near as efficient as say, a QValueList. Plus every time you dump it 
to disk it has to parse the whole node structure out again.

The most sensible thing i can think of is to maintain an open file pointer on 
the log file, and remember the last position we previously wrote to before 
the closing XML tag (the end of the last message node) ). We can then just 
write to the file at this location, and save the point again,  overwriting 
the close tag. With every one of these appends, we write a new close tag.

When the log is first opened, we can reverse seek on it to get the position of 
the end of the last message node, so we don't have to seek over the whole 
potentially large file.

Comment 13 Olivier Goffart 2003-10-15 14:31:46 UTC
> Every time you get a new message, this history plugin is loading the file on disk 
> into a QDomDocument and appending the message to it, and then dumping it to 
> disk again. 

eh? normaly that's not what appends.
For each chat window, the QDomDocument is stored in memory, and the new message is just happened at the end of the DOM tree,  so the file should be loaded only when the chatwindow is created.
(but that's true, the file is saved on the disk for each message, i could fix that and save it only every 50 messages and when the chatwindow is closed)

Comment 14 Jason Keirstead 2003-10-15 14:37:48 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On October 15, 2003 9:31 am, Olivier Goffart wrote:

> eh? normaly that's not what appends.
> For each chat window, the QDomDocument is stored in memory, and the new
> message is just happened at the end of the DOM tree,  so the file should be
> loaded only when the chatwindow is created.

This isn't what it looked like, but OK. Even so, this is WAYYY slow, since the
QDom is slow. It also sucks RAM like gangbusters.

> (but that's true, the file is 
> saved on the disk for each message, i could fix that and save it only every
> 50 messages and when the chatwindow is closed)

Thats not a good option because you could then lose a ton of messages if the 
engine crashes. Besides, it would not solve the memory issue  or all of the 
speed issues (the disk IO isn't the only thing making it slow ).

We should not be using the QDom to log messages. It is much too heavyweight an 
object for that task. The nodes should just be dumped out as strings at the 
end of the file before the close tag.

Comment 15 Martijn Klingens 2003-10-15 15:44:13 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Wednesday 15 October 2003 14:37, Jason Keirstead wrote:
> We should not be using the QDom to log messages. It is much too heavyweight
> an object for that task. The nodes should just be dumped out as strings at
> the end of the file before the close tag.

If we go that route we shouldn't be using XML in the first place.

The more I think about it, the more a plaintext format sounds appealing as it 
doesn't eat memory, is fast and doesn't require ugly hacks to keep closing 
elements in place.

If we stick with XML we have think about a fast, performant and 
memory-conserving solution that doesn't need hacks. Might be rather tough to 
do :(

Comment 16 Jason Keirstead 2003-10-15 15:58:16 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On October 15, 2003 10:44 am, Martijn Klingens wrote:

> If we go that route we shouldn't be using XML in the first place.

> If we stick with XML we have think about a fast, performant and
> memory-conserving solution that doesn't need hacks. Might be rather tough
> to do :(

I don't see how appending plain text at the end of a file is any less hacky 
then appending XML at the end of a file. The only difference between the two 
is instead of leaving the file pointer at the absolute end of the file, you 
move it up by a couple of bytes to before the XML close tag. This is not a 
hack and would require very little CPU. Seems the exact same as plain text to 
me, except you now have decent structure in the log.

XML logs have a number of benefits relating to their display, and I really 
prefer them over plain text.

Comment 17 Martijn Klingens 2003-10-15 16:41:29 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Wednesday 15 October 2003 15:58, Jason Keirstead wrote:

> I don't see how appending plain text at the end of a file is any less hacky 
> then appending XML at the end of a file. The only difference between the two 
> is instead of leaving the file pointer at the absolute end of the file, you 
> move it up by a couple of bytes to before the XML close tag. This is not a 
> hack and would require very little CPU. Seems the exact same as plain text
> to me, except you now have decent structure in the log.

With plain text you
- don't set a file pointer, you open a file in append mode and don't care
- don't need to load expensive DOM trees in memory
- don't need to convert XML to ascii when writing
- can append at the end of a file

> XML logs have a number of benefits relating to their display, and I really 
> prefer them over plain text.

... and a number of downsides. I am leaning towards the opinion that those 
outweight the (valid) benefits you mention. In other words: sticking 
religiously to XML is too expensive here.

Use the right tool for the job, which probably isn't XML in this case, unless 
the job is called 'stress testing a computer'.

Comment 18 Jason Keirstead 2003-10-15 17:01:08 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On October 15, 2003 11:41 am, Martijn Klingens wrote:

> With plain text you
> - don't set a file pointer, you open a file in append mode and don't care

Granted, but this is a minimal difference since we will be seeking in reverse.

> - don't need to load expensive DOM trees in memory

Don't have to do that with the method I proposed

> - don't need to convert XML to ascii when writing

Don't have to do that with the method I proposed, it should
be a QString the whole time


Comment 19 Martijn Klingens 2003-10-15 20:39:02 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Wednesday 15 October 2003 17:01, Jason Keirstead wrote:
> > - don't set a file pointer, you open a file in append mode and don't care
>
> Granted, but this is a minimal difference since we will be seeking in
> reverse.

You can't. At least not reliably, if someone changed the XML by e.g. adding an 
SGML comment node the seek would fail.

With a file format designed for appending that is no problem.

> > - don't need to convert XML to ascii when writing
>
> Don't have to do that with the method I proposed, it should
> be a QString the whole time

That's a hack. If you use XML on disk but not in memory you could just as well 
use plaintext on disk. It's the nice hierarchical node structure in memory 
that is the sole benefit of XML for Kopete, so if you're not going to make 
use of it (and do manual conversion to XML, with all its potential bugs that 
QDom::toString would avoid for free) you really should not be using XML.

Once again, use the right tool for the job.

The holy and beloved XML is not the right tool for this job.

If you insist on using it you need at least two evil hacks, seeking in a file 
using unsafe heuristics and abusing strings as XML. I'd protest to either of 
these, let alone the combination. At to that that XML isn't a must-have and 
avoiding it nicely solves the problem and you know why I'm beginning to 
question why we're using XML in the first place...

Comment 20 Jason Keirstead 2003-10-15 21:01:24 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On October 15, 2003 3:39 pm, Martijn Klingens wrote:

> That's a hack. If you use XML on disk but not in memory you could just as
> well use plaintext on disk. 

Its not a hack to construct the XML string yourself if you arne't going to be 
doing any manipulation on it.

And if this is such a hack then why was I met with such resistance back when I 
changed all the contact list handling code to use the QDom, which previously 
WAS constructing all the XML using QString?

> You can't. At least not reliably, if someone changed the XML by e.g. adding
> an SGML comment node the seek would fail.

Totally untrue, see below.

> It's the nice hierarchical node structure in 
> memory that is the sole benefit of XML for Kopete, 

Using XML for logging, or for the contact list, or anything else for that 
matter has no benefits at all for Kopete. It never has and that is not the 
purpose of it. XML is for data interchange between applications, that is the 
whole reason it exists.  

Logging as XML has benefits for other apps that want to read our logs, or if 
the user wants to write a script to do stuff with them, or wants to write a 
nice XSL stylesheet to put his chat logs on a web site. If the logs were 
going to be used by Kopete and Kopete only, then plain text is fine. But 
assuming that is very limiting and short sighted.

> If you insist on using it you need at least two evil hacks, seeking in a
> file using unsafe heuristics 

How is scanning backwards to look for </log> or whatever and appending nodes 
there "dangerous" ???? And how does this prevent you from adding comments? I 
see no problem.

> and abusing strings as XML. 

We *don't need* the XML node structure, writing the logs as anything *but* 
straight strings is a waste of resources.


Comment 21 Martijn Klingens 2003-10-15 21:15:43 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Wednesday 15 October 2003 21:01, Jason Keirstead wrote:
> Its not a hack to construct the XML string yourself if you arne't going to
> be doing any manipulation on it.

Sure, the seeking thing is worse (and the fact that we don't need XML), but 
it's still a hack, because you have to do all escaping yourself for example.

> And if this is such a hack then why was I met with such resistance back
> when I changed all the contact list handling code to use the QDom, which
> previously WAS constructing all the XML using QString?

Because of my fear for performance degradation. Which is exactly what we have 
here. Using XML stored in QStrings is one way to solve them, but ditching XML 
altogether might be way better.

> Using XML for logging, or for the contact list, or anything else for that
> matter has no benefits at all for Kopete. It never has and that is not the
> purpose of it. XML is for data interchange between applications, that is
> the whole reason it exists.

And as you know I really don't care a rat's ass about that beyond documenting 
our file format. It's a feature that's easy to achieve with plaintext too, 
even better probably. (See below.)

> Logging as XML has benefits for other apps that want to read our logs, or
> if the user wants to write a script to do stuff with them, or wants to
> write a nice XSL stylesheet to put his chat logs on a web site. If the logs
> were going to be used by Kopete and Kopete only, then plain text is fine.
> But assuming that is very limiting and short sighted.

Well, if you want to script, how about sed, awk and grep? I use them all day 
at work, they never left me in the cold except when parsing the dreaded XML.

So if it were up to me we'd pick a file format that's easy to parse using the 
shell tools that are fast, small, mature, existing for 20 years and available 
on any system on the planet.

> How is scanning backwards to look for </log> or whatever and appending
> nodes there "dangerous" ???? And how does this prevent you from adding
> comments? I see no problem.

Scanning backwards is slow, and you need to do it for every node you append.

fseek( fd, -20, SEEK_END ) would be fast and unreliable.

fopen( "a", file );
fputs( file, logline );
fclose( file );

is fast and reliable.

Keeping the file open would be even faster though I'm not sure you can 
concurrently add to the file then from another app. As I don't think we need 
that it can be done. For reliability a flush is needed though after every 
write.

> We *don't need* the XML node structure, writing the logs as anything *but*
> straight strings is a waste of resources.

Then why encapsulate it in XML? ;-)

Comment 22 Jason Keirstead 2003-10-15 21:37:03 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On October 15, 2003 4:15 pm, Martijn Klingens wrote:

> Sure, the seeking thing is worse (and the fact that we don't need XML), but
> it's still a hack, because you have to do all escaping yourself for
> example.

What escaping? The message text is in a CDATA section, there is no escaping. 
Even if there was we would have to do it ourselves anyway, the QDom doesn't 
do any escaping.

> And as you know I really don't care a rat's ass about that beyond
> documenting our file format. It's a feature that's easy to achieve with
> plaintext too, even better probably. (See below.)

It doesn't matte rhow well we document our file format, you won't be able to 
use resulting file with

	- an XSL stylesheet
	- an XML Application
	- a SQL database that has XML drivers
	- an XML capable DB application like OpenOffice

> Well, if you want to script, how about sed, awk and grep? I use them all
> day at work, they never left me in the cold except when parsing the dreaded
> XML.

You're basically advotaing going backwards in time to apps all using their own 
proprietary formats. This is the whole POINT of XML, to get rid of this type 
of crap. Instead of wirting a 75 line perl script to search for all the 
messages with $FOO in the text between $X and $Y times, I can do it with a 
one line XPath query, because it is in standard XML and I have umpteen dozen 
ways to work with it already.

> Scanning backwards is slow, and you need to do it for every node you
> append.

No you dont, you only need to do it the first time you open the log file, 
namely once per conversation. After that we already have the file pointer and 
all we are doing is writing to it.

> > We *don't need* the XML node structure, writing the logs as anything
> > *but* straight strings is a waste of resources.
>
> Then why encapsulate it in XML? ;-)

FOR OTHER APPLICATIONS

If nothing but Kopete is going to be reading the damn logs then we might as 
well just dump the KopeteMessage memory straight to disk and load it back in 
later! Save space and speed it up at the same time!

Obviously I am joking, but seriously, if nothing but Kopete is supposed to 
read the logs then the loggging is next to useless.


Comment 23 Martijn Klingens 2003-10-15 22:59:42 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Wednesday 15 October 2003 21:37, Jason Keirstead wrote:
> You're basically advotaing going backwards in time to apps all using their
> own proprietary formats. This is the whole POINT of XML, to get rid of this
> type of crap. Instead of wirting a 75 line perl script to search for all
> the messages with $FOO in the text between $X and $Y times, I can do it
> with a one line XPath query, because it is in standard XML and I have
> umpteen dozen ways to work with it already.

I can do that in a 3-4 line bash statement, if not less, but I have no tools 
installed that support XPath. *EVERY* unix system can handle plain text, few 
can script XML.

> > Then why encapsulate it in XML? ;-)
>
> FOR OTHER APPLICATIONS

And so is plaintext.

In fact, converting plaintext to XML is rather easy, the other way is not.

XML is a nice standard on the web when interfacing with other OS's, but within 
Kopete's unix world it's much more being buzzword and marketing compliant 
than being actually better suited than plaintext.

If at all that's only marginal, at the cost of less ubiquitous tools, much 
steeper memory overhead, less mature tools and much slower speed.

Comment 24 Casey Allen Shobe 2003-10-16 08:57:03 UTC
> If we go that route we shouldn't be using XML in the first place. 

Plaintext, *please*.

More readable, faster, smaller, and unix standard for log files.  All you need is some separator character that you escape in the logged text.

GAIM format: (15:04:17) gai1ee: blah blah blah

Kopete format: <msg nick="SomeLinuxGuy" in="0" from="somelinuxguy" time="11 15:4:17" >blah blah blah</msg>
...I will note that nick="" is completely useless here since the logs are now directoried by nickname.  from="" seems redundant.  And wtf is that '11 ' prefix in time=""?

But still you would have:
<msg in="0" from="somelinuxguy" time="11 15:4:17" >blah blah blah</msg>

I propose:
~/.kde/share/apps/kopete/logs/[protocol]Protocol/[Nickname]/[Contactname].log
...as it is now, containing lines:
<[Nickname] 15:04:17 [inbound message text]
> 15:04:38 [outbound message text]
...and just appending the new log line on each message.

Simplicity is the key here.
Comment 25 Stefan Gehn 2003-10-16 09:15:15 UTC
No, I'm strictly against it because gaim logs are virtually unparseable _because_ of being plaintext. Logfiles really need some kind of structure, not as complicated as we have now but at least some kind of structure. It's also important because we can have different messagetypes, some protocols do HTML others don't.

>~/.kde/share/apps/kopete/logs/[protocol]Protocol/[Nickname]/[Contactname].log 
Btw, why do we complicate this so much, why not like this:
.../logs/[AccountID]/[contactid].xml
As you can see the extra protocol subdir is not really needed (and I really doubt accountIDs can overlap on two protocols).
Also I'm a bit unsure about why we have monthly protocols

We should also try to come up with something that allows displaying our logs directly in konq and/or any XML-capable Browser, that would be way more handy for users like me who usually search for stuff in an old conversation. Also please finally come up with sane history acccess in kopete, having the display in two places (chatwin and that old history window) is confusing and both places are not very usable IMO.
Comment 26 Stefan Gehn 2003-10-16 09:24:20 UTC
Btw, in case we finally decide on how to do logging I'd help a bit on it (especially if somebody tells me how to make XML files display in a browser) :)
Comment 27 Martijn Klingens 2003-10-16 10:33:05 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Thursday 16 October 2003 08:57, Casey Allen Shobe wrote:
> I propose:
> ~/.kde/share/apps/kopete/logs/[protocol]Protocol/[Nickname]/
> [Contactname].log

That doesn't work when users change nick. Should be contactid at least.

Probably even better if we are really going to throw this upside down once 
again:

kopete/logs/[meta contact]/[protocol]Protocol/[contactid].log

This way you start grouping per meta contact instead of protocol. When 
renaming the MC (which is always local and never on the server, so it's easy 
to track) you can rename the folder, so synchronization is safe and easy as 
well.

When moving contacts to another MC you can also move them around on disk.

Safer, simpler and more reliable than starting with protocol (which is a weird 
primary key anyway from a user point of view)

Comment 28 Jason Keirstead 2003-10-16 14:01:12 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

> ------- Additional Comments From mETz81@web.de  2003-10-16 09:24 -------
> Btw, in case we finally decide on how to do logging I'd help a bit on it
> (especially if somebody tells me how to make XML files display in a
> browser) :)

Me and Martijn decided on a  compromise. For 3.2, we will fix the existing XML 
performance. Post 3.2, we will extend the logging plugin quite a bit to allow 
for different output streams besides XML. Some I have in mind are Plain Text, 
SQL, and External Application (ie a program or shell script that takes a 
number of paramaters that we will have to document ). 

mETz I can give you a quick and dirty XSL tutorial anytime your on IRC :P It's 
pretty simple. Note Konq doesn't have XSL transform support, but Mozilla 
does.

Comment 29 Jason Keirstead 2003-10-16 14:03:28 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On October 16, 2003 5:33 am, Martijn Klingens wrote:

> Probably even better if we are really going to throw this upside down once
> again:
>
> kopete/logs/[meta contact]/[protocol]Protocol/[contactid].log

I agree fully.

Comment 30 Olivier Goffart 2003-10-28 20:23:10 UTC
Isn't this bug a dupe of the Bug 62669 ?
Comment 31 Jesse 2003-10-28 22:23:07 UTC
It hasn't been determined if they are really related.  For me, I see lots of CPU activitely.  The larger the logged conversation, the more CPU.   Disk activety never becomes much a problem as it's not really dealing with a lot of data.  With a small 200k logfile, the logging bring a P4 to its knees.  Logfiles much bigger than that (and hence more disk activety) would be harder to diagnose.

Comment 32 Sean Chittenden 2003-12-16 03:03:19 UTC
What's hackish about doing the C++ equiv of:

fwrite(fd, s->len, "<xml>foo</xml>\n");

??? That's perfectly acceptable way to write streaming XML (which is what writing to a log file is doing).  Then, on close of the conversation in a background thread, closing off the tag.  If kopete crashes, have a background thread run around and verify that all log files for the current month are valid, otherwise have it append the closing tag.  Changing the DOM structure wouldn't hurt either:

<kopete>
  <conv>
    <msg>...</msg>
    <msg>...</msg> <!-- These get written with fwrite()'s -->
  </conv> <!-- This gets written when the window gets closed -->
</kopete> <!-- If a SAX parser is used, I don't know if its necessary to have this.... but, you could open() the file, then fseek() to the end of the file minus sizeof("</kopete>") and continue writing -->

Just some thoughts.
Comment 33 Jason Keirstead 2003-12-16 13:18:39 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On December 15, 2003 10:03 pm, Sean Chittenden wrote:
> What's hackish about doing the C++ equiv of:
>
> fwrite(fd, s->len, "<xml>foo</xml>\n");
>
> ??? That's perfectly acceptable way to write streaming XML (which is what
> writing to a log file is doing). 
Comment 34 Martijn Klingens 2003-12-16 14:46:07 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Tuesday 16 December 2003 13:18, Jason Keirstead wrote:
> The only gotcha is when you open the file for logging you have to remove the
> end close tag, but thats no big deal.

While I fully agree with this solution (I wanted to do the same when I have 
time to tackle it, but if Jason wants to beat me, fine with me :), be aware 
of two issues:

1. If the closing tag is somehow missing due to a crashed Kopete it should
   be added when reading the history to make it wellformed again.

2. Suppose the XML is edited and ends with extra data like SGML comments,
   how are you going to detect that without opening the file in its entirety
   and parsing it?

Comment 35 Jason Keirstead 2003-12-16 15:14:01 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On December 16, 2003 9:46 am, Martijn Klingens wrote:
> 2. Suppose the XML is edited and ends with extra data like SGML comments,
>    how are you going to detect that without opening the file in its
> entirety
 and parsing it?

Well, assuming the tag for a message is <message />, what should *always* be 
done is  to open the file, strip off everything after the last <message/>, 
and start appending. Then after the file is closed you'd tack it back on.

That would work for both the case where there is </log> and there are other 
superfluous tags.

Again, on the crash situation you'd need to validate the file and add a </log> 
if missing when you read it in. But validating on read in is more efficient 

Comment 36 Casey Allen Shobe 2003-12-16 17:06:33 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

Jason Keirstead (Tue, December 16 2003 07:18)
> The only gotcha is when you open the file for logging you have to remove
> the
 end close tag, but thats no big deal.

It's a big deal if Kopete crashes (which happens often), and leaves the log 
file without an ending.

Comment 37 Martijn Klingens 2003-12-16 17:59:05 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Tuesday 16 December 2003 15:14, Jason Keirstead wrote:
> Well, assuming the tag for a message is <message />, what should *always* be 
> done is  to open the file, strip off everything after the last <message/>, 
> and start appending. Then after the file is closed you'd tack it back on.

That's tricky - If Kopete crashes it's lost forever and it's not guaranteed to 
be ONLY the closing tag.

> Again, on the crash situation you'd need to validate the file and add a
> </log> if missing when you read it in.

Then we need to detect a crash. You cannot validate the file every time it's 
opened, that gives the same sluggishness and memory consumption when opening 
xml files of megabytes and more.

Comment 38 Jason Keirstead 2003-12-16 19:08:05 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

> That's tricky - If Kopete crashes it's lost forever and it's not guaranteed
> to 
 be ONLY the closing tag.

Actually, assuming we create a DTD yes it *is* in fact guarenteed to be only 
the closing tag,with the exception of comments (which aren't really 
important ).

> > Again, on the crash situation you'd need to validate the file and add a
> > </log> if missing when you read it in.

> Then we need to detect a crash. You cannot validate the file every time
> it's 
 opened, that gives the same sluggishness and memory consumption when
> opening xml files of megabytes and more.

All you have to do is check if </log> exists at the end of the file, if it 
doesn't, add it.

Or use the DTD to validate the file.

Comment 39 Martijn Klingens 2003-12-17 10:23:09 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Tuesday 16 December 2003 19:08, Jason Keirstead wrote:
> Actually, assuming we create a DTD yes it *is* in fact guarenteed to be only 
> the closing tag,with the exception of comments (which aren't really 
> important ).

I wouldn't say that - if a user added comments we should try very hard to 
preserve them.

> All you have to do is check if </log> exists at the end of the file, if it 
> doesn't, add it.

It's not that easy to check for '\s*</log\s*>\s*' at the end of a file, not 
even mentioning the added work to detect SGML comments and treat them 
correctly.

Even the following should pass:

       <!-- almost the end of the file -->
                        </log      >
<!-- end of contact list -->

To make an evil testcase. And opening the XML file and trying to parse it is 
not a solution as it defeats the very purpose for which we're trying to write 
in append mode in the first place.

Comment 40 Jason Keirstead 2003-12-17 14:07:30 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On December 17, 2003 5:23 am, Martijn Klingens wrote:
> I wouldn't say that - if a user added comments we should try very hard to
> preserve them.

I am trying hard to think why someone would open up a log file and add a bunch 
of XML comments at the end in the first place?

> > All you have to do is check if </log> exists at the end of the file, if
> > it doesn't, add it.
>
> It's not that easy to check for '\s*</log\s*>\s*' at the end of a file, not
> even mentioning the added work to detect SGML comments and treat them
> correctly.

Why isn't it? You do a reverse seek on the file pointer, starting at the end, 
ignoring comments, and ensure that </log> is the last thing there.

>Even the following should pass:
>
>       <!-- almost the end of the file -->
>                        </log      >
><!-- end of contact list -->

Why is that an "evil" test case? It would not be any harder to spot than 
anything else.

>To make an evil testcase. And opening the XML file and trying to parse it is 
>not a solution as it defeats the very purpose for which we're trying to write 
>in append mode in the first place.

You're not trying to parse it, your just trying to p[lace the file pointer at 
the right position to start your writing. This has to be done anyways to 
append to the file.

Comment 41 Martijn Klingens 2003-12-17 14:36:10 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Wednesday 17 December 2003 14:07, Jason Keirstead wrote:
> I am trying hard to think why someone would open up a log file and add a
> bunch of XML comments at the end in the first place?

Rest assured, me too :)

But even if we both consider it insane and stupid I think causing data loss is 
inexcusable. At least as long as we're using XML, which claims to be open and 
actively invites things like editing the files manually.

> Why isn't it? You do a reverse seek on the file pointer, starting at the
> end, ignoring comments, and ensure that </log> is the last thing there.

How do you want to do that? The only way I'm aware of to read backwards is a 
dog slow byte-by-byte approach, which doesn't even work properly for UTF-8. 
And the readLine methods in QFile would require you to read the entire file. 
(And using glibc is not an option if only because of the UTF-8 support and 
portability).

> You're not trying to parse it, your just trying to place the file pointer
> at the right position to start your writing. This has to be done anyways
> to append to the file.

Sure. The problem that I'm pointing out is that while this is the best way to 
go to kill the performance problem with logging, it is _FAR_ from trivial to 
place the file pointer at "the right position", because it's very hard to 
_determine_ "the right position".

Comment 42 Jason Keirstead 2003-12-17 15:03:03 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On December 17, 2003 9:36 am, Martijn Klingens wrote:
> How do you want to do that? The only way I'm aware of to read backwards is
> a dog slow byte-by-byte approach, which doesn't even work properly for
> UTF-8. 

Look at the source code for tac

> And the readLine methods in QFile would require you to read the 
> entire file. (And using glibc is not an option if only because of the UTF-8
> support and portability).

If we want to read backwards using QT is insufficient. It's also unneeded
overhead when just appending to the file.

And since the file is XML and therefore always written in UTF-8 (or UTF-16 or 
whatever we specify), all that needs to be done is to use setLocale to be 
able to read it in UTF with normal API calls.

man utf-8 / man unicode

Comment 43 Martijn Klingens 2003-12-17 15:19:08 UTC
Subject: Re: [Kopete-devel]  updating of chat window takes ages when there are many messages

On Wednesday 17 December 2003 15:03, Jason Keirstead wrote:
> If we want to read backwards using QT is insufficient. It's also unneeded
> overhead when just appending to the file.
> 
> And since the file is XML and therefore always written in UTF-8 (or UTF-16
> or whatever we specify), all that needs to be done is to use setLocale to
> be able to read it in UTF with normal API calls.

If you are sure that this

1. Has no side effects outside the code using it (isn't setlocale a global
   setting, affecting the rest of Kopete too?)

and

2. Is portable outside linux

be my guest to code it. I for one am both very worried about the impact of 
this and very curious to see what you have in mind - to me it sounds like 
voodoo magic to get this right :)

Thanks for your effort!

(PS: Please post patches first!)

Comment 44 jstuart 2004-02-17 03:40:47 UTC
Devs, anyone working on this?  Can the bug status be changed to assigned?
Comment 45 Martijn Klingens 2004-02-17 10:50:04 UTC
On Tuesday 17 February 2004 03:40, jstuart@computer-city.net wrote:
> Devs, anyone working on this?

Not to my knowledge.

On this subject btw, Rob Kaper complained about this issue to me at work 
yesterday, and he mentioned that Neil Stevens' jabber client (Light Hawk) 
uses a history file per session.

Sounds like a good idea to me as it solves all issues that we have with 
performance, even if you tell history to show the last couple of chat 
messages like I do. Jason's proposal helps in speeding up the writing, but 
not the reading, and the memory footprint of large logs can get pretty steep.

I see a lot of potential in the idea...

Comment 46 Markus Moser 2004-03-22 01:51:04 UTC
Ok... you made a big discussion about the best file-format for the history, but we've got still the Performance-problem. What about adding an option "plaintext" to the history-plugin and improve XML later? Or the other way round (don't know what's easier), so the user can make the decision himself for the best file-format. It doesn't have to be perfect!!!

In further times (before i discovered the pinguin ;) ) I used Trillian. Except the bootup-time, this program was very fast... and it used a history in plaintext-format... and I was very satisfied with it! :)

I would do the programming myself, but i have no knowledge about programming/editing linux-programms... i've got already problems to handle this "new" OS...


Comment 47 Olivier Goffart 2004-03-22 17:52:52 UTC
I'm personally still not sure this "performance problem" has anything related with the History plugin.  all works fine for me.
Comment 48 Markus Moser 2004-03-22 18:05:37 UTC
Oh yes, it does!

I've got a friend, who I talk often to. His chat-window is such slow, that my computer stops almost for 2sec. (even the mousepointer stops!) when I receive a message from him or if i send one. 
Compared to the people, i don't often talk to, the messages i send/receive cause no system-stop... and all of this since I've activated the History-Plugin. (I got used to the history, because every messenger has this built-in and its veeeeeeeeery useful!)
Comment 49 Jason Keirstead 2004-03-23 20:33:12 UTC
The problem is if you tlak to someone a lot in 1 month the XML DOm gets huge and slow to write to disk.

If the history XML files were stored on a per-chat session basis, it would not only solve this problem, but also make the back and next functionality of the history plugin much simpler code.

Right now from what I can see, the ganularity is

logs/Protocol/Account/contactId.<year><month start>.xml

Proposal:

logs/Protocol/Account/contactId.<year><month start>-conversationNumber.xml

Or maybe better..

logs/Protocol/Account/contactId/year/month start/conversationNumber.xml

Basically, you just take the highest conversation # present and add 1.

Then, you can just make the back and next buttons load up the last and previous conversation files respectively.

Downside: Another change to history format, another import.
Comment 50 Gavin Hamill 2004-04-22 16:13:54 UTC
Just a suggestion. This bun-fight has been going for six months now without a resolution. Can we *please* have some action?

My own two cents: I personally prefer plain text logs because they are searchable with traditional UNIX tools like grep, and as such can easily be used with other software without having to involve XML parsers.

If the community cannot decide on whether to use XML or plaintext logs, then let's have the option to *CHOOSE* - surely isn't one of the strengths of free software that of CHOICE?

I know you're all busy and have day-jobs, but *please*! This bug has been killing Kopete for months - I even moved to Gaim for a while as a result of it!

Cheers,
Gavin.


Comment 51 Jason Keirstead 2004-04-22 16:35:46 UTC
On April 22, 2004 11:13 am, Gavin Hamill wrote:
> f the community cannot decide on whether to use XML or plaintext logs, then
> let's have the option to *CHOOSE* - surely isn't one of the strengths of
> free software that of CHOICE?

This was the idea all along, and why it was moved to a plugin. Different 
logging methods ( SQL, XML, plain text ) are all still on the roadmap for the 
history AFAIK.

> I know you're all busy and have day-jobs, but *please*! This bug has been
> killing Kopete for months - I even moved to Gaim for a while as a result of
> it!

This is the thing, we are all super busy AFAIK. Martijn has been on hiatus it 
seems, Richard is out for awhile, I am super busy with work and the JS 
plugin, Matt is busy doing everything it seems...

It will be taken care of one way or another, be patient please :P The quickest  
way to fix the XML method would be to change the XML rotation from 1 / day to 
1 / 3 or 6 hours, that'd keep the DOM smaller and the logging faster, and 
keep the code changes to a minimum. Maybe this is the solution?

Comment 52 Gavin Hamill 2004-04-22 16:42:35 UTC
Well, from looking in ~/.kde/share/apps/kopete/logs/IRCProtocol/gdh@io-oftc-net:6667, at present it's one log per month:

-rw-r--r--     977524 Mar 31 23:02 #blug.200403.xml
-rw-r--r--    1155433 Apr 22 15:38 #blug.200404.xml

So even adding a drop-down box of 'Rotate logs every Day/Week/Month' would be better than what we have now :)

Alternatively, how about an 'external hook command' so that end users not fluent in C / C++ could write logging backends as they see fit?

Cheers,
Gavin.
Comment 53 Jason Keirstead 2004-04-22 18:44:58 UTC
On April 22, 2004 11:42 am, Gavin Hamill wrote:
> Alternatively, how about an 'external hook command' so that end users not
> fluent in C / C++ could write logging backends as they see fit?

If you want to do something like that you can just use the JavaScript plugin, 
to be released in CVS soon.

I already wrote and example script that logs to an SQL database in it, in only 
around 20 lines of code. Appending to a text file, you could do in 1 line.

Comment 54 Matt Rogers 2004-05-05 23:37:01 UTC
*** Bug 81002 has been marked as a duplicate of this bug. ***
Comment 55 Matt Rogers 2004-06-11 14:46:16 UTC
*** Bug 83215 has been marked as a duplicate of this bug. ***
Comment 56 Olivier Goffart 2004-07-16 12:22:50 UTC
CVS commit by ogoffart: 

Divide per two the time needed to log a message.

I designed the history code to load the history file only once.
But unfortunately, i saved it to a copy of the map. So it was not realy keeped in memory, and the logger still loaded the document each time.

CCMAIL: 65982@bugs.kde.org
Actualy, the file is still saved on the disk for each message. I'll add a timer to save less often.


  M +1 -0      historylogger.cpp   1.18


--- kdenetwork/kopete/plugins/history/historylogger.cpp  #1.17:1.18
@@ -149,4 +149,5 @@ QDomDocument HistoryLogger::getDocument(
 
         documents.insert(month, doc);
+        m_documents[c]=documents;
 
         return doc;


Comment 57 Olivier Goffart 2004-07-16 13:50:05 UTC
CVS commit by ogoffart: 

Add a timer to delay the saving of the history.
The history is saved when the chatwindow is closed or if there are no message for 3 minutes.
I have not yet installed a crash handler, but i plan to.

CCMAIL: 65982-done@bugs.kde.org


  M +39 -4     historylogger.cpp   1.19
  M +18 -4     historylogger.h   1.9


--- kdenetwork/kopete/plugins/history/historylogger.cpp  #1.18:1.19
@@ -2,5 +2,5 @@
     historylogger.cpp
 
-    Copyright (c) 2003 by Olivier Goffart        <ogoffart@tiscalinet.be>
+    Copyright (c) 2003-2004 by Olivier Goffart        <ogoffart@tiscalinet.be>
 
     Kopete    (c) 2003-2004 by the Kopete developers  <kopete-devel@kde.org>
@@ -24,4 +24,5 @@
 #include <qdatetime.h>
 #include <qdom.h>
+#include <qtimer.h>
 
 #include <kdebug.h>
@@ -40,4 +41,5 @@ HistoryLogger::HistoryLogger( KopeteMeta
  : QObject(parent, name)
 {
+        m_saveTimer=0L;
         m_metaContact=m;
         m_hideOutgoing=false;
@@ -55,4 +57,5 @@ HistoryLogger::HistoryLogger( KopeteCont
  : QObject(parent, name)
 {
+        m_saveTimer=0L;
         m_cachedMonth=-1;
         m_metaContact=c->metaContact();
@@ -69,4 +72,6 @@ HistoryLogger::HistoryLogger( KopeteCont
 HistoryLogger::~HistoryLogger()
 {
+        if(m_saveTimer && m_saveTimer->isActive())
+                saveToDisk();
 }
 
@@ -234,12 +239,42 @@ void HistoryLogger::appendMessage( const
         msgElem.appendChild( msgNode );
 
-        //TODO: Is that a good thing to save every time?
-        KSaveFile file( getFileName(c,0) );
+        
+        // I'm temporizing the save.
+        // On hight-traffic channel, saving can take lots of CPU. (because the file is big)
+        // So i wait 3 minutes. If no message has been received/send in 3 minutes, we save.
+        
+        const QString filename=getFileName(c,0);
+        if(!m_toSaveFileName.isEmpty() && m_toSaveFileName != filename)
+        { //that mean the contact or the month has changed, save it now.
+                saveToDisk();
+        }
+        
+        m_toSaveFileName=filename;
+        m_toSaveDocument=doc;
+        
+        if(!m_saveTimer)
+        {
+                m_saveTimer=new QTimer(this);
+                connect( m_saveTimer, SIGNAL( timeout() ) , this, SLOT(saveToDisk()) );
+        }
+        m_saveTimer->start( 150000 /*~2min*/, true /*singleshot*/ ); 
+}
+
+void HistoryLogger::saveToDisk()
+{
+        if(m_saveTimer)
+                m_saveTimer->stop();
+        if(m_toSaveFileName.isEmpty() || m_toSaveDocument.isNull())
+                return;
+
+        KSaveFile file( m_toSaveFileName );
         if( file.status() == 0 )
         {
                 QTextStream *stream = file.textStream();
                 //stream->setEncoding( QTextStream::UnicodeUTF8 ); //???? oui ou non?
-                doc.save( *stream, 1 );
+                m_toSaveDocument.save( *stream, 1 );
                 file.close();
+                m_toSaveFileName=QString::null;
+                m_toSaveDocument=QDomDocument();
         }
 }

--- kdenetwork/kopete/plugins/history/historylogger.h  #1.8:1.9
@@ -2,5 +2,5 @@
     historylogger.cpp
 
-    Copyright (c) 2003 by Olivier Goffart        <ogoffart@tiscalinet.be>
+    Copyright (c) 2003-2004 by Olivier Goffart        <ogoffart@tiscalinet.be>
     Kopete    (c) 2003-2004 by the Kopete developers  <kopete-devel@kde.org>
 
@@ -25,4 +25,5 @@ class KopeteMetaContact;
 class QFile;
 class QDomDocument;
+class QTimer;
 
 /**
@@ -162,4 +163,11 @@ private:
          Sens m_oldSens;
 
+         /**
+          * the timer used to save the file
+          */ 
+        QTimer *m_saveTimer;
+        QDomDocument m_toSaveDocument;
+        QString m_toSaveFileName;
+
         /*
          * FIXME:
@@ -175,4 +183,10 @@ private slots:
          */
         void slotMCDeleted();
+        
+        /**
+         * save the current month's document on the disk. 
+         * connected to the m_saveTimer signal
+         */
+        void saveToDisk();
 };
 


Comment 58 Casey Allen Shobe 2004-07-16 18:01:57 UTC
On Friday 16 July 2004 04:50, Olivier Goffart wrote:
> Add a timer to delay the saving of the history.
> The history is saved when the chatwindow is closed or if there are no
> message for 3 minutes. I have not yet installed a crash handler, but i plan
> to.

And what about when I'm having a long, fast-moving conversation and the power 
goes out?  I certainly hope you made this optional, otherwise please revert.

Comment 59 Alexandre Pereira 2004-07-16 20:31:00 UTC
Em Sexta, 16 de Julho de 2004 17:01, o Casey Allen Shobe escreveu:
> And what about when I'm having a long, fast-moving conversation and the
> power goes out?  I certainly hope you made this optional, otherwise please
> revert.


of course it should be optional .. but since we are on string freeze , and gof 
doesnt want to make kopeterc options , the default behavior like this is 
better ... in fact , i would go into making it more than 3 minutes.

Comment 60 Alexander Hvostov 2004-07-17 03:02:41 UTC
Saving history in a delayed fashion like this is /extremely/ dangerous. Please do not make this default behavior! Crash handlers cannot guarantee that the logs will be reliably saved, since there's no guarantee that the portion of memory that the logs are being kept hasn't been trashed. For that matter, such a crash handler could instead overwrite the log with garbage! Also, if the power goes out, Kopete is killed by Linux's out-of-memory handler, or anything else happens that prevents Kopete from saving its logs, the logs get lost. This is NOT good.
Comment 61 Alexandre Pereira 2004-07-17 03:06:47 UTC
does here anyone ACTUALLY USE KOPETE ??? for irc ??

with large conversations , old history logger would start using 100 % !!!

so this  way , although not perfect ( at least for fail proof logging ) is better than the old way , that were unusable , only usable for chitchat on msn or jabber or etc
Comment 62 Alexander Hvostov 2004-07-17 03:12:59 UTC
Then you get a choice of a logger that's slow, or a logger that's dangerous and fragile. Great.

I didn't say that this behavior of writing the logs in a delayed fashion is a bad thing. I said that it should not be default behavior. People are likely to be thoroughly displeased if power cuts out or Kopete crashes and the logs are truncated and/or corrupted. I know I will be if that happens.

And if you can't add things to kopeterc, how do you turn this behavior on / off, anyway?
Comment 63 Olivier Goffart 2004-07-17 08:46:38 UTC
It's not for the few messages you type in 3 minutes that can get lost.

And that information is not realy lost since you can simply ask to your contact to repeat important informations.
Comment 64 Alexander Hvostov 2004-07-17 08:58:48 UTC
> And that information is not realy lost since you can simply ask to your
> contact to repeat important informations.

At the risk of sounding incredibly arrogant and otherwise unpleasant, that's not good enough.
Comment 65 Till Gerken 2004-07-17 09:58:37 UTC
I also think that this is not a valid fix, especially regarding the long intervals of saving the log. Can the intervals be lowered to something like 10 seconds?

I think for the next release, a thorough redesign of the history mechanism is required.
Comment 66 Olivier Goffart 2004-07-17 11:34:43 UTC
The slowness and CPU usage are fixed.
this is another problem.
let's open another report.
Comment 67 Alexandre Pereira 2004-07-17 21:32:36 UTC
ok , i have made a patch that can make everybody happy

it allows to specify the log level you want in kopeterc

you have 4 values :

	0 - really fast logging ... almost instant

	1 - default as gof wants

	2 - a more slower logging 

	3 - really slow logging

as some tend to want instant logging ..... i tend to do a more late logging , 
as long as it doesnt use to much cpu.

please , review my patch and commit it please :) hope it gets in on kde 3.3


Created an attachment (id=6711)
historyYagami.diff
Comment 68 Alexandre Pereira 2004-07-17 22:51:59 UTC
Em Sábado, 17 de Julho de 2004 20:32, o Iori Yagami escreveu:
> ------- You are receiving this mail because: -------
> You are on the CC list for the bug, or are watching someone who is.
>
> http://bugs.kde.org/show_bug.cgi?id=65982
>
>
>
>
> ------- Additional Comments From yagami netcabo pt  2004-07-17 21:32
> ------- ok , i have made a patch that can make everybody happy
>
> it allows to specify the log level you want in kopeterc
>
> you have 4 values :
>
> 	0 - really fast logging ... almost instant
>
> 	1 - default as gof wants
>
> 	2 - a more slower logging
>
> 	3 - really slow logging
>
> as some tend to want instant logging ..... i tend to do a more late logging
> , as long as it doesnt use to much cpu.
>
> please , review my patch and commit it please :) hope it gets in on kde 3.3


... after several reviews ... here it is my latest version




Created an attachment (id=6713)
historyYagami.diff
Comment 69 Casey Allen Shobe 2004-07-18 23:25:10 UTC
On Friday 16 July 2004 23:46, Olivier Goffart wrote:
> And that information is not realy lost since you can simply ask to your
> contact to repeat important informations.

That defeats the whole purpose of having a logging plugin, now then doesn't 
it?  It _is_ important, and you don't know if that contact is going to be 
available.

I'll give you a specific example.  I was chatting with a friend who I had 
never met - we were going to meet for dinner since I recently moved here, and 
this is where they live.  They IM'd me their phone number, and I said I would 
be leaving shortly.  The power went out, and came back on.  When I got back 
online, they had signed off.  I needed to leave immediately, but could not 
leave without their phone number, since I would need it to find them.  It was 
in my log.  If it wasn't, because of this stupid delay, then they would have 
been waiting for me, I would have no idea where to go, we would have missed 
our dinner reservations, and it would have been a nightmare.

Instant logging is very important to me.

Logging in XML is the problem, and what should change to fix this.  Maybe some 
big huge IRC channel isn't that important - in that case give me a way to 
turn off logging per-contact, don't slow down log writing.

Comment 70 Casey Allen Shobe 2004-07-18 23:28:05 UTC
> The slowness and CPU usage are fixed.

No, the core issues are still there.  Maybe you've delayed the CPU hits, but every write to the XML file is still a big slowdown, it's just made more intermittent now.

> this is another problem. 
> let's open another report.

Nope.  When a patch introduces other bugs, worse bugs, the answer is to revert that patch and come up with a more correct solution.  It doesn't matter if it makes it into 3.3 - this solution is WRONG and BAD and you might as well just not even have a history plugin.
Comment 71 Olivier Goffart 2004-07-19 00:25:29 UTC
CVS commit by ogoffart: 

This patch *must* (it's an order :-D) make anyone happy

On normal chat: almost no delay.
On hight-trafic chat: not more than 5 minutes.

You may argue than loosing 5 minutes is bad on hight traffic chat, but without it, it simply doesn't work actualy. So better being able to using it with a delay than don't use it. And don't tell me it's important for you to save IRC chat, i'll will not beleive you because it was unusable before so you were not logging irc chat 

CCMAIL: 65982-done@bugs.kde.org


  M +20 -2     historylogger.cpp   1.23
  M +1 -0      historylogger.h   1.11


--- kdenetwork/kopete/plugins/history/historylogger.cpp  #1.22:1.23
@@ -42,4 +42,5 @@ HistoryLogger::HistoryLogger( KopeteMeta
 {
         m_saveTimer=0L;
+        m_saveTimerTime=0;
         m_metaContact=m;
         m_hideOutgoing=false;
@@ -59,4 +60,5 @@ HistoryLogger::HistoryLogger( KopeteCont
 {
         m_saveTimer=0L;
+        m_saveTimerTime=0;
         m_cachedMonth=-1;
         m_metaContact=c->metaContact();
@@ -253,5 +255,5 @@ void HistoryLogger::appendMessage( const
         // I'm temporizing the save.
         // On hight-traffic channel, saving can take lots of CPU. (because the file is big)
-        // So i wait 3 minutes. If no message has been received/send in 3 minutes, we save.
+        // So i wait a time proportional to the time needed to save..
         
         const QString filename=getFileName(c,0);
@@ -269,5 +271,6 @@ void HistoryLogger::appendMessage( const
                 connect( m_saveTimer, SIGNAL( timeout() ) , this, SLOT(saveToDisk()) );
         }
-        m_saveTimer->start( 150000 /*~2min*/, true /*singleshot*/ ); 
+        if(!m_saveTimer->isActive())
+                m_saveTimer->start( m_saveTimerTime, true /*singleshot*/ ); 
 }
 
@@ -279,4 +282,7 @@ void HistoryLogger::saveToDisk()
                 return;
 
+        QTime t;
+        t.start(); //mesure the time needed to save.
+
         KSaveFile file( m_toSaveFileName );
         if( file.status() == 0 )
@@ -286,7 +292,19 @@ void HistoryLogger::saveToDisk()
                 m_toSaveDocument.save( *stream, 1 );
                 file.close();
+                
+                m_saveTimerTime=QMIN(t.elapsed()*1000, 500000); 
+                    //a time 1000 times supperior to the time needed to save.  but with a upper limit of 8 minutes
+                //on a my machine, (2.4Ghz, but old HD) it should take about 10 ms to save the file. 
+                // So that would mean save every 10 seconds, which seems to be ok.
+                // But it may take 500 ms if the file to save becomes too big (1Mb).
+                // So saving every 8 minutes is a good deal.
+                kdDebug(14310) << k_funcinfo << m_toSaveFileName << " saved in " << t.elapsed() << " ms " <<endl ;
+                
                 m_toSaveFileName=QString::null;
                 m_toSaveDocument=QDomDocument();
         }
+        else
+                kdError(14310) << k_funcinfo << "impossible to save the history file " << m_toSaveFileName << endl;
+        
 }
 

--- kdenetwork/kopete/plugins/history/historylogger.h  #1.10:1.11
@@ -169,4 +169,5 @@ private:
         QDomDocument m_toSaveDocument;
         QString m_toSaveFileName;
+        unsigned int m_saveTimerTime; //time in ms between each save
         
         /**


Comment 72 Alexander Hvostov 2004-07-19 04:51:41 UTC
Why is there a setting for almost no delay but not one for absolutely no delay?
Comment 73 Rob Kaper 2004-07-19 06:44:56 UTC
On Sun, Jul 18, 2004 at 10:25:32PM -0000, Olivier Goffart wrote:
> You may argue than loosing 5 minutes is bad on hight traffic chat, but
> without it, it simply doesn't work actualy. So better being able to using
> it with a delay than don't use it. And don't tell me it's important for
> you to save IRC chat, i'll will not beleive you because it was unusable
> before so you were not logging irc chat

I can't do A (log busy chats) because of bug B.
- We've changed B.
But I still can't do A!
- We've fixed B. A is not important, it never worked.

While this workaround might be the best thing possible for 3.3, I'd prefer
if this report became a REMINDME for 4.0. QDomDocument is simply too slow
for the log requirements of Kopete.

Rob
Comment 74 Till Gerken 2004-07-19 10:25:00 UTC
Reopening to change resolution.
Comment 75 Till Gerken 2004-07-19 10:26:45 UTC
Will rewrite after 3.3. No way to get in a better fix during freeze.

Olivier: your comment says you save every 5 minutes, but the timer actually fires with a max. time of 500 seconds - is that intentional?
Comment 76 benjamin weber 2005-07-21 17:00:57 UTC
This still seems to be a big problem, and is becoming more apparent with the more complex chat window styles.

This also doesn't only affect the history plugin, even with the history plugin messages still appear to be left in memory after they roll off the top of the scrollback according to cat /dev/mem | strings | grep nickname. This quickly gets out of hand with long chats / irc

doing a 

while true; do ps ax -o vsz,rss,command | grep kopete | head -n 1 | cut -d" " -f 1-2 >> ~/Desktop/kopete.memlog ; sleep 30; done

Produced the following graphs of kopete memory use without history: http://bw.uwcs.co.uk/kopetemem.pdf

and with history:http://bw.uwcs.co.uk/kopetememhistory.pdf

as you can see, the first is bad, the second is insane, I only have 1gb of ram in this machine at present and kopete using 1/3 of it without history of 95% of it with history makes it increasingly difficult to use, there are probably still lots of people with <1gb of ram too. To me, and probably quite a few others this is by far the most pressing problem with kopete.
Comment 77 Jason Keirstead 2005-07-21 21:01:01 UTC
On Thursday 21 July 2005 12:00 pm, benjamin weber wrote:
> This also doesn't only affect the history plugin, even with the history
> plugin messages still appear to be left in memory after they roll off the
> top of the scrollback according to cat /dev/mem | strings | grep nickname.
> This quickly gets out of hand with long chats / irc


I don't really know what the issue is.. I can set in an active IRC session for 
hours, exceeding my 250 line buffer (so I know the mem used by the display is 
maxed out), I have the logger enabled,  and Kopete is still only using 30 MB 
RSS - about the same as my standard Kontact session.
Comment 78 benjamin weber 2005-07-23 20:52:38 UTC
Since some people were thinking this was just an issue with irc rather than general j0hnnyB (from #kopete) and myself tried spamming messages through jabber conversation for a couple of mins, during which time kopete's memory usage grew by about 60mb for both of us, and the memory wasn't even freed on closing of the conversation window. It seems that every message received is never removed from memory. (this was without history plugin)

vsz 
196076
201904
220348
242052
255072
255072 
255072 
255072 
255072
255064 <- cloesd chat window somewhere about here
255064 
255064 
256080
256212
256212
256212
256212

(readings every 30 seconds as before)
Comment 79 Nabil Sayegh 2005-09-12 13:58:17 UTC
This bug is definitely not resolved.
A contact with 110kb log takes 25 seconds to open.

I also agree to benjamin weber: This is not related to irc, it's a general problem.
Comment 80 Andrew Kohlsmith 2005-11-14 15:16:44 UTC
This isn't resolved.  Kopete MSN conversations in 3.5beta2 still do this.  I don't use Kopete for IRC at all.
Comment 81 Matt Rogers 2005-11-14 19:02:45 UTC
Will be resolved in a later version after we switch away from xslt for chat window styles. Scheduled target for switching away from XSLT is the 0.12 release. Planning for this release is still in process.