469737 - AMO scripts don't email amo-developers@ anymore?

Status: RESOLVED FIXED

(mozilla.org Graveyard :: Server Operations, task)

Description

[Wil Clouser [:clouserw]]

I'm trying to debug our maintenance scripts (parse_logs, specifically) and I noticed the archives for [e-mail] on mail.mozilla.org only go to Nov. 2nd.  Has the output been going somewhere else?

Comment 1

[Justin Scott [:fligtar]]

I changed my subscription from digest to normal and started getting them again (all the time) so it looks like it's a problem with the digest settings.

Comment 2

[Wil Clouser [:clouserw]]

But they should still be showing up at https://mail.mozilla.org/private/amo-developers/

Comment 3

[Aravind Gottipati [:aravind]]

Do you guys know how far back its supposed to go?  When was this list created?

If the list was created well before Nov, 07.. what am I tracking down here?  Missing archives?  Do we know for a fact that amo script output was being sent to this list instead of /dev/null or something like that?

Comment 4

[Wil Clouser [:clouserw]]

I don't know when it was created but I'm not worried about the old emails.  I'm interested in where they are going since, say, Dec 1 2008 until now.

I don't know anything about the script output redirection.  I assume it's in the cron jobs.  oremj would know.

Comment 5

[Dave Miller [:justdave]]

   ----- The following addresses had permanent fatal errors -----
[e-mail]
    (reason: 552 5.3.4 Message size exceeds file system imposed limit)
    (expanded from: <[e-mail]>)
<[e-mail]>
    (reason: 552 5.3.4 Message size exceeds file system imposed limit)

   ----- Transcript of session follows -----
... while talking to mail.mozilla.org.:
>>> MAIL From:<[e-mail]> SIZE=17441874430
<<< 552 5.3.4 Message size exceeds file system imposed limit
554 5.0.0 Service unavailable

Comment 6

[Dave Miller [:justdave]]

What are you doing that sends 17 GB emails? :)

Comment 7

[Wil Clouser [:clouserw]]

I agree the output of the scripts is too verbose but 17GB seems excessive.  Can you tell me which script created that output?

Comment 8

[Dave Miller [:justdave]]

Subject: Cron <root@dm-stats01> /usr/local/bin/addons_stats_collections.sh

Comment 9

[Wil Clouser [:clouserw]]

Is there a way to get a portion of the output?  The collections aren't working and it sounds like maybe the output is filled with error messages?

Comment 10

[Michael Morgan [:morgamic]]

Dave, how can we see the output?

Comment 11

[Wil Clouser [:clouserw]]

We're scheduling an update for AMO ASAP.  If this is a code problem I'd like to get it rolled into the update.

Comment 12

[Aravind Gottipati [:aravind]]

Output doesn't seem to have any error messages.  I didn't wait for it to finish since you only wanted a part of the output.  I am attaching what I got to the bug.

Comment 13

[Aravind Gottipati [:aravind]]

Attachment: output from the addons_stats_collections.sh script.

Comment 14

[Wil Clouser [:clouserw]]

Can you verify the full output has no error messages?

Comment 15

[Aravind Gottipati [:aravind]]

It finished without any errors and the final log file size is 2.5M, so not sure what happened earlier when dave said the log files were 17 G.  Here is the size on disk.

[root@dm-stats01 tmp]# du -h amo.log
2.5M    amo.log
[root@dm-stats01 tmp]#

Comment 16

[Wil Clouser [:clouserw]]

That seems more reasonable (although it's still too verbose).  Would you attach it or send it to me?  Thanks

Comment 17

[Aravind Gottipati [:aravind]]

(In reply to comment #16)
> That seems more reasonable (although it's still too verbose).  Would you attach
> it or send it to me?  Thanks

khan:/tmp/amo.log.gz

Comment 18

[Wil Clouser [:clouserw]]

Ah, right.  The output says all the logs have already been counted (even though they didn't work).  So the output from this run is different than from the 17G run.

To get the original output we'll need to run "update logs_parsed set collections_done=0" (affects a little over 27k rows).  Since no collections have been counted this shouldn't have any negative results.  Just the same I'd like to get a=fligtar on it.

Admittedly, debugging why collections doesn't work is getting off track from comment 0.  I can file a new bug if people would like.

Comment 19

[Justin Scott [:fligtar]]

resetting the collections_done column is fine with me

Comment 20

[Aravind Gottipati [:aravind]]

Whats the  next action on this?  Do you need me to change something and re-run the script?

Comment 21

[Wil Clouser [:clouserw]]

Hey Aravind.  To continue to debug the collections problem we'll need to do this:

1) Run "update logs_parsed set collections_done=0" on the AMO database.
2) Re-run /usr/local/bin/addons_stats_collections.sh

If you want a shorter/faster test case you can copy one of the log files from december somewhere and re-run the script pointing to that directory instead of all of them.

I'll need enough output from the script to tell what the problem is.  If it's something like the database is missing a column then you can kill the script and we can fix that.  If it's not as obvious capture all the output and we'll look at it.

I just ran the exact same command that is running in your script on my dev copy (using a directory with a single log file in it) and it worked fine.

Comment 22

[Aravind Gottipati [:aravind]]

Okay, updated the table, and am running the script.  Will send you the output once its done.

Comment 23

[Justin Scott [:fligtar]]

Wil, in regard to the original problem of this bug, after switching my amo-developers subscription from digest to normal, I got all the cron emails, including collections. I can't figure out why digest mode isn't working, but I noticed that you have "nomail" set on your account meaning you wouldn't get mail anyway. So if you remove that and digest mode, you'll start getting collections cron emails.

Comment 24

[Wil Clouser [:clouserw]]

Thanks Justin.  I disabled the email because there was so much coming in it was just noise.  I filed this bug because even if I'm not getting email they should still be going to the list and they should still be being archived at the URL in comment 2.

Comment 25

[Reed Loden [:reed]]

(In reply to comment #24)
> Thanks Justin.  I disabled the email because there was so much coming in it was
> just noise.  I filed this bug because even if I'm not getting email they should
> still be going to the list and they should still be being archived at the URL
> in comment 2.

I have a guess as to the problem. I'll look later today.

Comment 26

[Aravind Gottipati [:aravind]]

I put the log file from the last run on khan:/tmp/amo.log.gz.  Let me know if you need more information from me to troubleshoot the problem.

Comment 27

[Wil Clouser [:clouserw]]

Thanks for the output.  I'm going to need your help debugging.  The only errors I see are e.g.:

PHP Notice:  MySQL Error 0: 
Query was: [UPDATE addons_collections SET downloads = downloads + 2 WHERE addon_id=424 AND collection_id=1 LIMIT 1] in /data/stats/amo_stats/bin/database.class.php on line 104


Which are triggered from these lines:

if (!$result = mysql_query($qry, ($useWrite ? $this->write : $this->read))) {
    trigger_error('MySQL Error '.mysql_errno().': '.mysql_error()."\nQuery was: [".$qry.']', E_USER_NOTICE);
     return false;
}


I can't duplicate the error on my dev box when running the script or when running that query ^^ directly on the database.

Comment 28

[Michael Morgan [:morgamic]]

Stats are messed up, we need help with this ASAP or at least give us an ETA on when we can get some debug info from cron output.

Comment 29

[Aravind Gottipati [:aravind]]

Can I get an updated script that prints whatever debug info you need to troubleshoot this?  Is not, I'd be glad to run any specific commands you need that will give you the needed info.

Comment 30

[Michael Morgan [:morgamic]]

Check that -- spoke to Wil.  We can't debug this in dev, so we need help debugging this and understanding why it is producing these errors in prod.

Some things to check:
1) mysql version of client
2) timeout vars (wait_timeout=820, interactive_timeout=600) ?
3) script runtime info (exec time, where it fails)

Wil - what else can Aravind do to help?

Comment 31

[Aravind Gottipati [:aravind]]

mysql  Ver 14.12 Distrib 5.0.45, for redhat-linux-gnu (x86_64) using readline 5.0

wait_timeout=820

interactive_timeout=600

Not sure what info I can get from the script runtime.  I uploaded the entire execution log file to khan in the past, so what additional info would you need other than that.

Comment 32

[Wil Clouser [:clouserw]]

It was a permissions problem which oremj fixed (he can give more info).  Webdev
can't debug that.

So, from here:;

1) Run "update logs_parsed set collections_done=0" on the AMO database to clear
out all this testing.

2) Re-run /usr/local/bin/addons_stats_collections.sh

Thanks

Comment 33

[Jeremy Orem [:oremj]]

The addons_collections and collections tables were not writable by the download stats user (old perms listed in Bug 404449).  The new perms are:

GRANT SELECT ON `addons_remora`.`versions` 
GRANT SELECT, INSERT, UPDATE, DELETE ON `addons_remora`.`update_counts` 
GRANT SELECT, INSERT, UPDATE, DELETE ON `addons_remora`.`download_counts` 
GRANT SELECT, INSERT, UPDATE, DELETE ON `addons_remora`.`collections` 
GRANT SELECT, UPDATE ON `addons_remora`.`addons` 
GRANT SELECT, INSERT, UPDATE, DELETE ON `addons_remora`.`addons_collections` 
GRANT SELECT ON `addons_remora`.`files` 
GRANT SELECT ON `addons_remora`.`translations` 
GRANT SELECT, INSERT, UPDATE ON `addons_remora`.`logs_parsed` 


Anything else I can do for this bug?

Comment 34

[Wil Clouser [:clouserw]]

The two steps in comment 32 before the cron job fires to fix the collections problems.

The original bug was that the output of the scripts doesn't show up at https://mail.mozilla.org/private/amo-developers/ which is still valid.

Comment 35

[Jeremy Orem [:oremj]]

(In reply to comment #32)
> It was a permissions problem which oremj fixed (he can give more info).  Webdev
> can't debug that.
> 
> So, from here:;
> 
> 1) Run "update logs_parsed set collections_done=0" on the AMO database to clear
> out all this testing.
> 
> 2) Re-run /usr/local/bin/addons_stats_collections.sh
> 
> Thanks

Running.

Comment 36

[Michael Morgan [:morgamic]]

What is the status on this?

Comment 37

[Jeremy Orem [:oremj]]

Still running.

Comment 38

[Jeremy Orem [:oremj]]

Attachment: Collections run.

Comment 39

[Jeremy Orem [:oremj]]

The script has completed and I've added it back to cron.

Comment 40

[Wil Clouser [:clouserw]]

Thanks Jeremy.  I think the output looks good.  I'll know for sure once it finishes importing the dump.

I'm reopening the bug though because the original problem is that the amo-developers archives are not getting the output of the job and that still isn't fixed.

If the problem is there is too much output assign the bug to me and I'll fix it.  Thanks.

Comment 41

[Jeremy Orem [:oremj]]

Archives for amo-developers was disabled.  It is now enabled.

Comment 42

[Wil Clouser [:clouserw]]

awesome, thanks