Topic: Problem with AFFA after upgrade prodbox to SME 8.0

[idp_qbn]

I support a volunteer group 300 Km from my home. I set up affa to make backups of the production server ('artserver') to an AFFA box ('affa-server')
This worked fine when both servers were SME7.5. I upgraded 'affa-server' to SME 8.0 and all was still OK. That was actually an 'upgrade' not a 're-install'.
I have the same set-up at home and it works OK.
I then , a month or so later, upgraded 'artserver' to SME8.0 and AFFA stopped working. I was unable to check the system remotely (they changed ISP) for a while and have now discovered that something is preventing AFFA from completing a backup. I am not sure if the problem is on 'affa-server' or 'artserver'


I would appreciate any advice on how to solve the problem.
I have already uninstalled and re-installed AFFA and have spent hours reading logs and searching the forums and bug-zilla but have not come up with anything that helps.

Below are excerpts of log files from the two servers.....some obvious errors are highlighted in red
========================================================================
/var/log/affa/prodbox.log: Viewed at Mon 16 Jul 2012 08:02:05 AM EST

Mon Jul 16 08:00:24[3612]: ##################
Mon Jul 16 08:00:24[3612]: # Affa 2.0.0-rc4 #
Mon Jul 16 08:00:24[3612]: ##################
Mon Jul 16 08:00:24[3612]: Starting job prodbox scheduled (192.168.1.32)
Mon Jul 16 08:00:24[3612]: Description: Artserver Backup
Mon Jul 16 08:00:24[3612]: Checking SSH connection to 192.168.1.32
Mon Jul 16 08:00:25[3612]: Installing watchdog on 192.168.1.32 with dt=87000 seconds
Mon Jul 16 08:00:26[3612]: signaling pre-backup event on 192.168.1.32
Mon Jul 16 08:00:27[3612]: Error 881 in 'main': signaling pre-backup event failed.     <========= Hmmmm?
Mon Jul 16 08:00:27[3612]: Starting re-run 1 of 3 in the background.
Mon Jul 16 08:00:27[3612]: Total execution time:  0h00m03s
Mon Jul 16 08:00:27[3612]: Email sent to admin
Mon Jul 16 08:00:27[3612]: Exiting.
Mon Jul 16 08:00:27[3612]: .
Mon Jul 16 08:00:31[3658]: ##################
Mon Jul 16 08:00:31[3658]: # Affa 2.0.0-rc4 #
Mon Jul 16 08:00:31[3658]: ##################
Mon Jul 16 08:00:31[3658]: Starting job prodbox scheduled (192.168.1.32)
Mon Jul 16 08:00:31[3658]: Description: Artserver Backup
Mon Jul 16 08:00:31[3658]: Sleeping 597 seconds. Continuing at 08:10:28


========================================================================
Email from affa-server

To:    admin@artsound.local
Subject:    Error on affa-server.artsound.local (192.168.1.240): Job 'prodbox' failed.
Excerpt from log file /var/log/affa/prodbox.log:
Affa_2.0.0-rc4:_Running_/sbin/e-smith/affa_--run_prodbox
Job_configuration:
__AutoUnmount=yes
__ChunkSize=921600
__ChunkThresholdSize=2
__ConnectionCheckTimeout=120
__Debug=no
__Description=Artserver_Backup
__DiskSpaceWarn=strict
__EmailAddresses=admin
__RPMCheck=no
__RetryAfter=600
__RetryAttempts=3
__RetryNotification=yes
__RootDir=/var/affa
__SMEServer=yes
__SambaShare=yes
__TimeSchedule=1000,1300,1700,2230
__Watchdog=yes
__dailyKeep=7
__doneDaily=-1
__doneMonthly=-1
__doneWeekly=-1
__doneYearly=-1
__monthlyKeep=12
__remoteHostName=192.168.1.32
__remoteOS=centos
__rsync--inplace=yes
__rsyncCompress=no
__rsyncTimeout=900
__rsyncdMode=no
__rsyncdModule=AFFA
__rsyncdPassword=<not_shown>
__rsyncdUser=affa
__scheduledKeep=1
__sendStatus=weekly
__sshPort=2222
__status=enabled
__type=job
__weeklyKeep=4
__yearlyKeep=1
##################
#_Affa_2.0.0-rc4_#
##################
Starting_job_prodbox_scheduled_(192.168.1.32)
Description:_Artserver_Backup
Checking_SSH_connection_to_192.168.1.32
Exec_Out:_OK
Exec_Out:_exitstatus=0
Installing_watchdog_on_192.168.1.32_with_dt=87000_seconds
Watchdog_parameters:
___TRIGGER=>201207170810
___JOBNAME=>'prodbox'
___EMAIL=>'admin'
___BACKUPHOST=>'affa-server.artsound.local_(192.168.1.240)'
___SCHEDULED=>'Mon_Jul_16_08:00:25_2012'
___WDSCRIPT=>'affa-watchdog-prodbox-192.168.1.240'
Exec_Out:_exitstatus=0
Exec_Out:_exitstatus=0
signaling_pre-backup_event_on_192.168.1.32
Exec_Out:_exitstatus=1
Error_881_in_'main':_signaling_pre-backup_event_failed.                            <============= Hmmmm (just a repeat of the previous)
Starting_re-run_1_of_3_in_the_background.
Total_execution_time:__0h00m03s
========================================================================
Excerpt from messages.log on 'artserver' (prodbox)

Jul 16 08:00:26 artserver esmith::event[3940]: Processing event: pre-backup desktop
Jul 16 08:00:26 artserver esmith::event[3940]: Running event handler: /etc/e-smith/events/actions/generic_template_expand
Jul 16 08:00:26 artserver esmith::event[3940]: expanding /etc/dar/DailyBackup.dcf 
Jul 16 08:00:26 artserver esmith::event[3940]: generic_template_expand=action|Event|pre-backup|Action|generic_template_expand|Start|1342389626 624066|End|1342389626 923901|Elapsed|0.299835
Jul 16 08:00:26 artserver esmith::event[3940]: Running event handler: /etc/e-smith/events/pre-backup/S10mysql-delete-dumped-tables
Jul 16 08:00:26 artserver esmith::event[3940]: S10mysql-delete-dumped-tables=action|Event|pre-backup|Action|S10mysql-delete-dumped-tables|Start|1342389626 924655|End|1342389626 929729|Elapsed|0.005074
Jul 16 08:00:26 artserver esmith::event[3940]: Running event handler: /etc/e-smith/events/pre-backup/S20mysql-dump-tables
Jul 16 08:00:27 artserver esmith::event[3940]: mysqldump: Got error: 1017: Can't find file: 'procs_priv' (errno: 2) when using LOCK TABLES 
Jul 16 08:00:27 artserver esmith::event[3940]: S20mysql-dump-tables=action|Event|pre-backup|Action|S20mysql-dump-tables|Start|1342389626 930524|End|1342389627 235840|Elapsed|0.305316|Status|256
Jul 16 08:00:27 artserver esmith::event[3940]: Running event handler: /etc/e-smith/events/pre-backup/S30ldap-dump
Jul 16 08:00:27 artserver esmith::event[3940]: S30ldap-dump=action|Event|pre-backup|Action|S30ldap-dump|Start|1342389627 236566|End|1342389627 504449|Elapsed|0.267883
Jul 16 08:00:27 artserver esmith::event[3940]: Running event handler: /etc/e-smith/events/pre-backup/S50rewind-tape
Jul 16 08:00:27 artserver esmith::event[3940]: S50rewind-tape=action|Event|pre-backup|Action|S50rewind-tape|Start|1342389627 505268|End|1342389627 654810|Elapsed|0.149542

========================================================================


Both servers are SME8.0, 2 disk RAID1
artserver is 192.68.1.32
affa-server is 192.168.1.240


My gut feeling is  that :
a) something went wrong with the upgrade of 'artserver' and I did not notice at the time, OR
b) I have something configured incorrectly OR
c) I inadvertently deleted something when I was removing contribs from 'artserver' before upgrading.


Or all three


Cheeers
Ian

[janet]

idp_qbn

Without analysing your problem greatly, I would guess you should recreate the secure keys.
See step 5 here
http://wiki.contribs.org/Affa#Quick_start_example

[idp_qbn]

Thanks for your reply, Mary.
I have tried that without success, unfortunately.

I think the message on the AFFA (affaserver)box that says 
   Error 881 in 'main': signaling pre-backup event failed
combined with the message on the production server (artserver) that says
   mysqldump: Got error: 1017: Can't find file: 'procs_priv' (errno: 2) when using LOCK TABLES
together indicate the problem lies in the pre-backup process.

Perhaps 'artserver' can't complete the pre-backup and signals back to 'affaserver' which then halts the process (after a few more retries).

But I don't know what to do about it....

Cheers
Ian

[janet]

idp_qbn

I'd say the mysql error is your starting point. Something is wrong with a mysql table & this causes the pre-backup event to fail.

You could manually disable the affa backup temporarily.
Then try manually instigating the pre-backup event.
Then review the log files & I assume you may still see the mysql error. If so that just proves the
theory/possibility of where the problems lies.

Then I would start looking at the mysql tables, perhaps fire up phpmyadmin or use the mysql command line to check tables etc. I'd have to refer to my mysql notes re troubleshooting, it's early & my mysql memory bank has not yet dumped it's contents into my frontal lobes.
I vaguely recall some similar error to this going back approx 2 or 3 years, so you could try searching the forums on mysql.

Perhaps a table was not converted correctly during the sme8.0 upgrade and that table cannot be locked to perform the mysql dump during the pre-backup.

Hope that helps.

[nicolatiana]

Please post the result of:

mysql -BNre "show databases;"

maybe there's something to be cleaned/rebuilt in Mysql after the unistallation of some contrib.
 
I leave the place to some mysql "guru" to give You some more help . . . . 
 
Nicola

Addendum after Mary post: in italian forum there's this post: http://forums.contribs.org/index.php/topic,47580.msg235020.html#msg235020
The user installed and then removed zabbix (maybe not correctly or there's some bug in uninstall, I don't know) and he got similar error using DAR & DAR2 contribs: there was a "ghost" table named "history" belonging to zabbix and not removed. The user then installed phpmysqladmin contrib and made some wash&clean in the database and solved.
Be careful in washing & cleaning  .

[Stefano]

idp_qbn

use

Code: [Select]

mysqlcheck

to check your dbs and tables

read carefully the man page before

[nicolatiana]

procs_priv is a standard table of the database named "mysql" -> we can suspect that some contrib uninstall has removed/altered it  . . .
it should be like this:
   

Campo	Tipo	Null	Predefinito	Commenti
Host	char(60)	No
Db	char(64)	No
User	char(16)	No
Routine_name	char(64)	No
Routine_type	enum('FUNCTION', 'PROCEDURE')	No
Grantor	char(77)	No
Proc_priv	set('Execute', 'Alter Routine', 'Grant')	No
Timestamp	timestamp	No	CURRENT_TIMESTAMP

Nicola

[nicolatiana]

Any news idp_qbn ?
 
Nicola

[idp_qbn]

Thanks for everone's help.
Unfortunately, I was called away to FNQ (FAR NORTH QUEENSLAND) suddenly and won't be back until next week. In the meantime, using my tablet and a very dodgy internet link to reply. I will leave fixing things until my return - I don't want to totally stuff things up when I have no way of getting back to help.

On my return I will try the suggestions made so far. Once again, thank you all.
Ian

[nicolatiana]

Any meeting with crocodiles ? 
 
Nicola

[idp_qbn]

Only the sort who hang around bars ....
Back next week (I hope)

[idp_qbn]

Back now from FNQ (where it is warm......)
I have done some tests, as suggested
Thanks Mary, Stefano and Nicola for your help so far - I think I will need even more before this is resolved.

result of mysql -BNre "show databases
   information_schema
   horde
   mysql
   sme7admin
   test

result of mysqlcheck -c -A
horde.horde_alarms                                 OK
horde.horde_cache                                  OK
horde.horde_datatree                               OK
horde.horde_datatree_attributes                    OK
horde.horde_datatree_seq                           OK
horde.horde_groups                                 OK
horde.horde_groups_members                         OK
horde.horde_histories                              OK
horde.horde_histories_seq                          OK
horde.horde_locks                                  OK
horde.horde_perms                                  OK
horde.horde_prefs                                  OK
horde.horde_sessionhandler                         OK
horde.horde_signups                                OK
horde.horde_syncml_anchors                         OK
horde.horde_syncml_map                             OK
horde.horde_tokens                                 OK
horde.horde_users                                  OK
horde.horde_vfs                                    OK
horde.imp_sentmail                                 OK
horde.ingo_forwards                                OK
horde.ingo_lists                                   OK
horde.ingo_rules                                   OK
horde.ingo_shares                                  OK
horde.ingo_shares_groups                           OK
horde.ingo_shares_users                            OK
horde.ingo_spam                                    OK
horde.ingo_vacations                               OK
horde.kronolith_events                             OK
horde.kronolith_shares                             OK
horde.kronolith_shares_groups                      OK
horde.kronolith_shares_users                       OK
horde.kronolith_storage                            OK
horde.turba_objects                                OK
horde.turba_shares                                 OK
horde.turba_shares_groups                          OK
horde.turba_shares_users                           OK
mysql.columns_priv                                 OK
mysql.db                                           OK
mysql.func                                         OK
mysql.help_category                                OK
mysql.help_keyword                                 OK
mysql.help_relation                                OK
mysql.help_topic                                   OK
mysql.host                                         OK
mysql.proc                                         OK
mysql.procs_priv
Error    : Can't find file: 'procs_priv' (errno: 2)
error    : Corrupt
mysql.tables_priv                                  OK
mysql.time_zone                                    OK
mysql.time_zone_leap_second                        OK
mysql.time_zone_name                               OK
mysql.time_zone_transition                         OK
mysql.time_zone_transition_type                    OK
mysql.user                                         OK
sme7admin.afp                                      OK
sme7admin.dhcpd                                    OK
sme7admin.ftp                                      OK
sme7admin.pppoe                                    OK
sme7admin.samba                                    OK
sme7admin.ssh                                      OK
sme7admin.vpn                                      OK

(Sorry to post such a lot)
This confirms that procs_priv is missing or corrupt.

Questions:
1 - can i use the example procs_priv Nicola (nicolatiana) shows and copy the file from another mysql database?
2)- if I can, how do I do it and where do I copy it to and what changes may have to be made?
3)- if NOT,  how do I create/recreate a table?

You can see I am trying to avoid having to drive the 300 km to where the server is located.....
Tonight I will install  phpmyadmin contrib (which requires a reboot, I believe) and in the meantime start reading as much as I can take in about mysql and phpmyadmin.

Cheers
Ian

[idp_qbn]

Just an update - I "solved" the problem by installing phpmyadmin, looking at the databases listed, them going to a databse called "mysql" which did not seem to be in use. It had a table (procs_priv) that was corrupt so could not been used anyway.
I manually backked up all the user data and Ibays to a WinXP box(shudder)

I then used phpmyadmin to remove the table procs_priv. Just for good measure, and it was after 1.oo am by this stage, I rebooted both the production server and the AFFA server.

At the next scheduled AFFA run, all worked perfectly and over the next day a complete backup was done automatically.....AFFAmagically?

The production system continues to run, users report no problems and the limited testing of the backup I have tried seems to indicate everything is working OK.
When I am next down there (Canberra) I will try doing a full restore just to make sure.

Just goes to show
a) how good SME is
b) how good the advice in forums and bugzilla is
c) how much sleep one can lose trying to support something over a distance of 300km
d) how such a little thing (a corrupt mysql table) can cause such big problems.
e) how much close attention one should use when doing an upgrade - don't overlook/ignore/miss  warning messages!

Once again, thanks to all who responded.
Cheerio
Ian

[nicolatiana]

Maybe You should better try to recreate the removed table; I see that in my server(s) too this table is empty but . . . . Some help from a Mysql expert should be necessary.
Looking at an existing db You may look at the table structure and then recreate it.
 
Just for debug purpose: what did you do before upgrading the system (e.g. did You remove some Contrib). The upgrade went appearently smooth ?
 
Bye
 
Nicola
 
 

[idp_qbn]

I had an old contrib that put an "rsync" option into Server Manager list. I had not used it for some time  - since moving from 6.5 to 7.x. I think it may have been a precurser to DAR. I removed that. I think that was the only thing I changed.

I did not notice anything going wrong with the update during the process itself.  Everything seemed to be functioning after the upgrade. It was only when I looked at the affa backups (or lack of them) that I realised something had stopped.

The site had changed ISPs, new IP address for remote loging etc, so it was a while beofre I could connect again (300 km apart - PuTTy and SCP are my friends!)

Cheers
Ian