Logfile bug causing messages not to be displayed

[unimatrix]

Version: Latest SVN / Linux-64bit
Description: Sometimes when a new window pops up, the bug report window also appears with it. It can only be closed by clicking Ignore. After that, you will not be able to chat with the contact, because no further messages will be displayed. The remote contact actually does receive everything you type and send, and you can see when he/she "is typing a message", but you will not see anything you get or send. Restarting aMsn does NOT resolve the problem. You will not be able to chat with that particular contact, until you move or delete the contact's log file. Why? Because the log file owner and group are (for some reason) suddenly changed to root. That is probably why nothing is displayed, because aMsn can't write to the log file.
Possible cause: It usually happens when a contact who is in "appear offline/invisible" mode sends you a message. The initial message will be displayed but nothing afterwards (as described above).

So, why does the logfile suddenly change ownership?

[kakaroto]

good question.. the logfile should not change ownership or permissions! Maybe something else does....
In any case, yes, having the logging crash should not affect your chatting..
can you reproduce this ? if you can give me detailed instructions on what you do that makes it reproduce everytime, then that would help... Try to see also if it's not some other program doing this.. who knows...
btw, can you copy/paste the bugreport here ?

[unimatrix]

I'll try to reproduce this. No luck so far... it seems to be very random. What I know for sure is that it only happens when some other user sends you the first message. So I'm pretty sure it's aMsn... (unless it's some plugin).
Still working on reproducing the bug tho. I'm positive I'll be able to do it eventually.

About the bug report. I'm not really sure about the bugreport.amsn file structure. Seems like it appends every error there, right?
Anyway, if I'm correct, this is the only thing it writes in there when this happens (without me typing a problem description)...

Example one:

[22:44:00] <-::MSN::SB21-sock9 MSG medixxx@sadamsnuser.com M3njO_o.0.[b0].[b0]<3. 98
[22:44:00] Message Contents:
MIME-Version: 1.0
Content-Type: text/x-clientcaps

Client-Name: aMSN 0.97RC1
Chat-Logging: Y

Example two:

[22:44:00] <-::MSN::SB25-sock10 MSG ninabertoncxxx@sadamsnuser.com Nina 99
[22:44:00] Message Contents:
MIME-Version: 1.0
Content-Type: text/x-msmsgscontrol
TypingUser: ninabertoncxxx@sadamsnuser.com

But I am not 100% sure these are the right reports! As I've said... the bugreport file is a bit confusing to me.
I guess i will have to reproduce it to know for sure.

EDIT: you can probably ignore most of this post... the next one is more important

[unimatrix]

UPDATE:

I've managed to trace the bug a bit further.
I don't know WHY the logfile changes to root:root, but if you change a logfile ownership to root manually ($ sudo chown root:root user@mail.log) you will get exactly the bug I've described above! So I guess that's how you reproduce it. Try it.

Next task will be to find WHAT exactly changes the file ownership.

PS: Oh, and I've got a fresh bugreport file too, containing only this error, but it's 8.4KB long... should I post it here?

[kakaroto]

no it's ok.. the best way to report a bug is to click the 'details' button on the bug report, and copy *that*. What you pasted above is just the protocol log

[unimatrix]

Oh, ok sorry about that... I thought it would be easier than that :P
Have you tried to replicate it?

Anyway, here's the bug report (as i get from details):

couldn't open "/home/andrej/.amsn/myaddress_gmail_com/logs/medixxx@sadamsnuser.com": permission denied
    while executing
"open "[file join ${log_dir} ${email}.log]" a+"
    (procedure "CheckLogDate" line 98)
    invoked from within
"CheckLogDate $email"
    (procedure "StartLog" line 8)
    invoked from within
"StartLog $email"
    (procedure "::log::WriteLog" line 32)
    invoked from within
"::log::WriteLog $user_login "\|\"LITA$user :\|\"L$color $msg\n" 0 $user_list"
    (procedure "::log::PutLog" line 31)
    invoked from within
"::log::PutLog $chatid $nick $msg $fontformat"
    (procedure "::amsn::PutMessageWrapped" line 86)
    invoked from within
"::amsn::PutMessageWrapped medixxx@sadamsnuser.com medixxx@sadamsnuser.com {M3njO_o.0.°.°<3. like not} {whatever u like} user {helvetica bold 1950f9} 0"
    ("eval" body line 1)
    invoked from within
"eval $command"
    (procedure "FlushMessageFIFO" line 12)
    invoked from within
"FlushMessageFIFO $stack $lock"
    (procedure "SendMessageFIFO" line 7)
    invoked from within
"SendMessageFIFO [list ::amsn::PutMessageWrapped $chatid $user $nick $msg $type $fontformat $p4c] "::amsn::messages_stack($chatid)" "::amsn::messages_f..."
    (procedure "PutMessage" line 3)
    invoked from within
"PutMessage $chatid $user $nick $msg $type [list $fontfamily $style $fontcolor] $p4c"
    (procedure "::amsn::messageFrom" line 74)
    invoked from within
"::amsn::messageFrom $chatid $typer $nick $message user $p4c_enabled"
    (procedure "::SB::Snit_methodhandleMSG" line 105)
    invoked from within
"$self handleMSG $command $message"
    ("MSG" arm line 2)
    invoked from within
"switch -- [lindex $command 0] {
            MSG {
               $self handleMSG $command $message
            }
            BYE -
            JOI -
            IRO {
               cmsn_update_users $self $com..."
    (procedure "::SB::Snit_methodhandleCommand" line 24)
    invoked from within
"$options(-name) handleCommand $command $payload"
    (procedure "::Connection::Snit_methodreceivedData" line 52)
    invoked from within
"::MSN::SB21 receivedData"

[Daniel15]

It's trying to open the file, but can't do it because the file is owned by root. The question is, why does root own the file? aMSN shouldn't be running as root, so aMSN can't chown it (if a normal user tries to change the file owner to root, they'll get chown: changing ownership of `whatever': Operation not permitted). Something else must be changing its owner to root

Unless you run aMSN as root sometimes?

[unimatrix]

Well obviously I'm not running it as root, or it would probably be able to read the file.
Still, I agree something else may be changing the permissions. But what on earth (other than something connected with amsn) would even have a reason to modify those files?

[kakaroto]

nothing would have a reason to modify the ownership.. and i thought of maybe you run as root sometimes and it created a new file with root permissions but that's not possible either since it would create the file in /root/.amsn and not in /home/user/.amsn ...
for sure amsn doesn't change the ownership... Now the only thing we should fix is that if the log file can't be opened/written to, amsn should not stop reading/sending messages...

[unimatrix]

Yeah, that would be fine for now.
And I'll let you know if I find out anything new about the file ownership.

[unimatrix]

UPDATE [EDITED]:
Oh dear, I guess you guys were right all along. I did sometimes run amsn as root! I just didn't know it. It was ran by my update script.  :oops:  :oops:  :oops:
I wonder why it used my .amsn config files instead of creating a /root/.amsn directory. :?:

Anyway, aMsn still crashes if there's a logfile it can't write to. It would be nice if this was fixed to avoid any future issues.
Well at least I discovered this bug.

[H@t Trick]

Maybe a simple work around would be to check if permission is denied and if it is create a new log file instead of bugging. But still being int he process of learning the code, I am not sure how difficult this would be or if this is a valid workaround/solution

[unimatrix]

I wonder what would be better for the user.

I think we have three options how to do this:
1. Warn the user that the logfile couldn't be written [user knows something is wrong, but loses log data]
2. Make a new logfile and skip bothering the user [user has no idea something went wrong, but may someday discover unexplainable logfile duplicates]
3. A combination of #1 and #2 [user knows something went wrong, but still has a logfile]

#2 and #3 would probably require some additional changes, because then the history viewer would ignore the duplicates, so I personally think #1 would be good enough.

PS: I think the function we're talking about is in amsn/loging.tcl and is called WriteLog [line 311].

[kakaroto]

I would say #1 only.. because of the log viewer.. you only need one file per user...

[kakaroto]

Fixed in the latest SVN version.. in case the logfile can't be opened, we just silently ignore the error.