179351 - Oddly formatted dependency emails

Status: RESOLVED FIXED

(Bugzilla :: Email Notifications, defect, P3)

Description

[Joel Peshkin]

Received the following notification. 



Date: Sun, 10 Nov 2002 05:56:33 -0800 (PST)
Message-Id: <[e-mail]>
From: [e-mail]
To: [e-mail]
Subject: [Bug 98304] Allow Bugzilla to work with PostgreSQL (PgSQL)
X-Bugzilla-Reason: CC

http://bugzilla.mozilla.org/show_bug.cgi?id=98304


[e-mail] changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
Bug 98304 depends on bug 114696, which changed state.

Bug 114696 Summary: Permission checking in queries not optimal
http://bugzilla.mozilla.org/show_bug.cgi?id=114696

           What    |Old Value                   |New Value
----------------------------------------------------------------------------
             Status|ASSIGNED                    |RESOLVED
         Resolution|                            |FIXEDBug 98304 depends on bug
114696, which changed state.

Bug 114696 Summary: Permission checking in queries not optimal
http://bugzilla.mozilla.org/show_bug.cgi?id=114696

           What    |Old Value                   |New Value
----------------------------------------------------------------------------
             Status|ASSIGNED                    |RESOLVED
         Resolution|                            |FIXED

Comment 1

[Gervase Markham [:gerv]]

This may be another buffer issue :-)

Gerv

Comment 2

[J. Paul Reed [:preed]]

I tried to reproduce this, but didn't really have much luck (I didn't try that
long either, though, so...)

Gerv: are you saying you think this is a buffering issue in processmail or in
templating or... ?

joel and I were talking about it on IRC and were semi-confused.

One other thing interesting tidbit from that conversation:

<joel> actually, it is stranger than that...
<joel> I think this happened when a completely unrelated bug changed state
<joel> the person who is said to have made the change did nothing to wither of
theose 2 bugs

Hrm...

Comment 3

[Joel Peshkin]

This isn't just oddly formatted, it seems to be spillover from an unrelated event.

Adding [e-mail] to the bug and asking the question....

We are trying to figure out what was going on at the time this email was
generated.  Were you doing anything potentially related at the time?

Comment 4

[Joel Peshkin]

1 more note on the triggering event,

patl was added to the cc list of bug 98304 at... 2002-11-10 05:56:29

Comment 5

[Joel Peshkin]

Bug 71794 looks like a really good candidate for triggerring this.

Comment 6

[Patrick J. LoPresti]

All I did was add myself to the CC list of bug 98304.  Or at least, that is what
I *tried* to do.

On the first attempt, it failed because I had inadvertently changed the
"milestone" field to 2.20.  So I clicked "back" in my browser, set the milestone
back to 2.18, and typed my Email address again, and hit Enter.

That worked, but the bizarre notification got sent...

Comment 7

[Joel Peshkin]

Patrick:

  Yep, that makes sense.  Was the add to the CC list done by viewing the bug and
adding youself or was it using the buglist "change serveral at once" to add
yourself?

(I'm wondering if the trasition-checking in process_bug was treating
"dontchange" as differrent than the old status)

Comment 8

[Patrick J. LoPresti]

I viewed the bug and added myself.

Comment 9

[Bradley Baetz (:bbaetz)]

Yeah, I've had this a few times, always on dependency-changed mail. I can't see
what causes this, though - processmail runs as a separate process, and we've now
reenabled buffering everywhere (processmail sets $|=1, too), so there shouldn't
be anything which stays arround as persisted.

Even if we were sending mails twice, they'd be separate mails, I would have thought

Comment 10

[Bradley Baetz (:bbaetz)]

Actually.....

I submitted that particular bug (bug 114696) as FIXED just before bmo shutdown,
and that went through, but the dependency emails didn't get sent - they were
caught by the shutdownhtml check (and showed as sent to noone/__UNKNOWN__)

All the bugs I've got this for have been dependent on that bug, or dpeendent on
a dependant of that bug; I'm wondering if thats what caused this, combined with
some breakage when processmail ends up triggereing the dependency thing.

Can people get this on testbed installs, by playing with delta_ts + lastchanged?

[e-mail], was there no indication in that mail about your cc change?

Comment 11

[Bradley Baetz (:bbaetz)]

The other hting ot thikn about is that processmail does:

           $thisdiff =
              "\nBug $id depends on bug $depbug, which changed state.\n\n" .

Note the leading \n, which appears to have somehow vanished in the resulting mail??

Comment 12

[Patrick J. LoPresti]

Attachment: Sample bogus mail

Bogus Email message I received when I added myself to the CC list of the bug.

Comment 13

[Patrick J. LoPresti]

Hm.  Looking at the headers, and come to think of it, I also voted for the bug...

So I voted for the bug, and then I went back and added myself to the CC list. 
The message in the attachment was the only Email notification I received, however.

Comment 14

[Gervase Markham [:gerv]]

Is bug 71794 still under suspicion here?

Gerv

Comment 15

[Bradley Baetz (:bbaetz)]

gerv: Not sure, but I think its unlikely

from myk's post-shutdown bmo db, we have:

mysql> SELECT bug_id, delta_ts, lastdiffed FROM bugs WHERE bug_id IN (98304,
114696);
+--------+----------------+---------------------+
| bug_id | delta_ts       | lastdiffed          |
+--------+----------------+---------------------+
|  98304 | 20021107203846 | 2002-11-08 18:03:18 |
| 114696 | 20021108180933 | 2002-11-08 18:09:38 |
+--------+----------------+---------------------+

Not sure why 98304's lastdiffed was updated at 18:03, but its clear that bug
98304 didn't manage to send out the dep mail. 

Comment 16

[Joel Peshkin]

WRT comment 14, I'll answer in the style of a crummy cop movie...
There's no evidence that it is the culprit, but it shouln't leave town :-)

Comment 17

[Joel Peshkin]

Downgrading priority and severity due to the following...

1) All the people notified by the strange emails would have reasonably had
access to at least some of these bugs.

2) Both know cases where this has occurred involve a bug that was being modified
just prior to the shutdown and major upgrade.  It probably would pay to run
processmail --rescanall immediately prior to upgrade.

We seem to be converging on observations that a bug had a bugmail pending just
as the system was shut down and something odd happened after that.

If correct, this would be a rather isolate incident.

Comment 18

[Bradley Baetz (:bbaetz)]

Until someone proves otherwise, this isn't a regression fromthe recent upgrade

Comment 19

[J. Paul Reed [:preed]]

Just a datapoint, but I've gotten three or four more messages with these same
formatting errors since the upgrade.

Has anyone else seen these since the upgrade?

Comment 20

[Bradley Baetz (:bbaetz)]

JP: have all those mails been related to bug 114696 or its deps?

Comment 21

[J. Paul Reed [:preed]]

No, actually.

I'll attach a couple of mails that showed this behavior, but that don't have
anything to do with that bug (AFAICT).

Comment 22

[J. Paul Reed [:preed]]

Attachment: Another oddly formatted email

Comment 23

[Bradley Baetz (:bbaetz)]

Hmm. That was changing dep + resolution in one mail. Did that confuse something?

Comment 24

[J. Paul Reed [:preed]]

You know... I was thinking about this... this isn't just some weird special case
of bug 133368, is it?

Comment 25

[Bradley Baetz (:bbaetz)]

I don't know. It may be related, but we're getting one mail with the _same_ data
twice, not two mails.

Has anyone reproded this when changing dep + resolution in one go?

Comment 26

[J. Paul Reed [:preed]]

*** Bug 190059 has been marked as a duplicate of this bug. ***

Comment 27

[Aleksey Nogin]

Dup bug 190059 has more exact information on what might be causing this.

I've just marked bug 189563 as blocking 59652 at the same time marking it as
RESOLVED FIXED (it was in "ASSIGNED" state). The bugmail it generated for bug
59652 (see below) is completely messed up:
1) It does *not* say that a new bug was added to its dependency list
2) The "state change" message is repeated twice
3) The "state change" message includes NEW -> ASSIGNED transition that happened
well before the dependency was added (so it shouldn't be included).

The bugmail I received was the following:
------
http://bugzilla.mozilla.org/show_bug.cgi?id=59652


[e-mail] changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
Bug 59652 depends on bug 189563, which changed state.

Bug 189563 Summary: use of uninitialized value found by valgrind
http://bugzilla.mozilla.org/show_bug.cgi?id=189563

           What    |Old Value                   |New Value
----------------------------------------------------------------------------
             Status|NEW                         |ASSIGNED
             Status|ASSIGNED                    |RESOLVED
         Resolution|                            |FIXEDBug 59652 depends on bug
189563, which changed state.

Bug 189563 Summary: use of uninitialized value found by valgrind
http://bugzilla.mozilla.org/show_bug.cgi?id=189563

           What    |Old Value                   |New Value
----------------------------------------------------------------------------
             Status|NEW                         |ASSIGNED
             Status|ASSIGNED                    |RESOLVED
         Resolution|                            |FIXED

Comment 28

[Dave Miller [:justdave]]

Bumping severity back to blocker.  This needs to be fixed before we can call
Bugzilla version 2.18.

I just got mail like this again (will attach momentarily)

Bug 84876 was set as depending on bug 124174 a long time ago.  All that was done
in the resolving action was to resolve the bug.  Bug 84876 just generated one of
these emails when bug 124174 was resolved.  This eliminates setting as a dep and
resolving at the same time as the specific cause (adjusting summary accordingly).

Comment 29

[Dave Miller [:justdave]]

Attachment: another weird dep mail

notice in here at the top it says:

"[e-mail] changed:"

When in fact it was [e-mail] who made the change....

this is nasty when it's putting the wrong person in here, too.

Comment 30

[Dave Miller [:justdave]]

I just got a mail almost identical to this from Bugscape, which is running the
CVS tip as of Sunday night, so it's not limited to b.m.o, and it's not fixed on
the tip, even with the new BugMail.pm code.

Comment 31

[Bradley Baetz (:bbaetz)]

We need steps to repro this before we can fix it.

Comment 32

[Aleksey Nogin]

Do steps in comment #27 (add another bug in "bug xxx blocks" box, select
RESOLVED FIXED and hit "Commit" and see what you get as a bugmail for that
"another" bug) work?

Comment 33

[J. Paul Reed [:preed]]

Just a note to make sure we get this down for posterity: there were some musings
on IRC that this may be caused by/related to bug 192877.

Comment 34

[J. Paul Reed [:preed]]

*** Bug 220339 has been marked as a duplicate of this bug. ***

Comment 35

[Boris 'pi' Piwinger]

Let me copy from the duped bug report I produced:

So here is my suggestion how to solve it. If we want to combine different
incidents in one mail (I don't think we should, but this is not the question
here), then each incident should be given completly, seperated by a clear marker
like a line like this:

--------------------- change n ------------------------------------

pi

Comment 36

[J. Paul Reed [:preed]]

re comment 35:

I don't think anyone is considering combining bug email reports; the emails you
got are is a symptom of a bug, not a "feature."

Comment 37

[Gervase Markham [:gerv]]

*** Bug 133368 has been marked as a duplicate of this bug. ***

Comment 38

[Teemu Mannermaa (:wicked)]

AFAICS, the problem is in Bugzilla/Bugmail.pm around line 273 where it generates
the dependencies change diff data and around line 227 where it generates normal
field change diff data. Oddly formatted email is generated when there is both
normal field change (BugsThisDependsOn) and dependency change.

Problem happens because the dependency differ uses only text hash key to create
diffpart and header hash value will contain the same data the normal field
differ used. Now the diffparts will contain two entries and both of them have
same header. Email generation at around line 767 will filter out the other
header because it's same so that counts for the one extra What/Removed/Added header.

I still don't know why the duplication of dependency data happens but I suspect
it's because of the same problem. I'll try to find out more and produce a patch
that fixes the problem and probably clarifies what I'm trying to say here..
Unless I'm totally wrong on this, of course. :)

Comment 39

[Teemu Mannermaa (:wicked)]

Attachment: Fix

I think I was right.. This patch fixes the odd formatting of emails by clearing
the variable used for diffing. Now the dependency email will also show fields
that were changed (usually only BugsThisDependsOn field).

Comment 40

[Dave Miller [:justdave]]

Hmmm.... I think you might be on to something. :)

Would it achieve the same end to localize $diffpart within the foreach loop at
line 229?  Since it's getting pushed onto @diffparts before leaving that loop,
the $diffpart generated within it doesn't seem to have any use beyond that
point, and that seems to be where the leftover is coming from...

Comment 41

[Dave Miller [:justdave]]

Attachment: Fix v2

That was indeed it. :)

I revised it just slightly...  there were only two places that $diffpart was
being used, so it's now declared locally within the scope of each of the two
places using it, which is logically a little cleaner than just clearing it
before the second use. :)

Tested on landfill: can reproduce 100% by making any given bug block bug 1 at
the same time as resolving it (the bugmail for bug 1 would then be the "funky"
one) before applying this patch.  With this patch applied, it looks nice and
pretty :)

Comment 42

[Joel Peshkin]

Comment on attachment 144314 [details] [diff] [review]
Fix v2

Good job!
r=joel

Comment 43

[Vlad Dascalu]

Checking in Bugzilla/BugMail.pm;
/cvsroot/mozilla/webtools/bugzilla/Bugzilla/BugMail.pm,v  <--  BugMail.pm
new revision: 1.11; previous revision: 1.10
done