SQLite: disk I/O error errorcode: 522 Backup Server

Hallo Community und uroni;)

Mein System
HP 380 G9 7 TB im Raid 5 (mit Raid 1 lief alles)
Ubuntu 14.04 letzter Pachlevel, UrBackup 2.0.31 über dpkg -i und apt-get install f installiert
Backup von 4 Windows 2008 R2 Server
Hat bisher immer geklappt.

Fehler
Ich bekomme zu jedem Anfang des Zeitgesteuerten Filebackup’s die
WARNING: SQLite: disk I/O error errorcode: 522
2016-08-04 20:04:05: ERROR: Error preparing Query [PRAGMA synchronous=NORMAL]: disk I/O error. Retrying in 1s…
das geht so lange bis Urbackup abstürtzt.
Dann mache ich ein
/etc/init.d# ./urbackupsrv status
urbackupsrv is not running
urbackupsrv remove-unknown ok löscht alle Datei Leichen
urbackupsrv repair-database und urbackupsrv defrag-database bekomme ich ein
ERROR: Database already openend
ERROR: Couldn’t open Database backup_server_settings.db. Exiting???
Starte urbackup /etc/init.d# ./urbackupsrv start
Dann funktioniert es, die Datensicherung geht los und sichert alle Server im vorgehsehen Verzeichnis.

Neuinstallation hat nicht geholfen. Der einzige Unterschied ist das ich von Raid 1 (1TB) auf Raid 5 (7 TB)
gewechselt bin aber die Hardware dürfte dafür nicht zu langsam sein;)

Bin für jeden Tipp Dankbar!

Could you run it with strace (strace -f urbackupsrv run -v debug) and post the last few output pages?

Sorry about the defrag/repair problem. Will be repaired with server 2.0.33.

ok ich mache ein Probe Backup fertig.
was sagst du dazu
https://sourceforge.net/projects/urbackup/files/Server/2.0.32/ ???
2.0.32??? stimmt das oder machen die wieder mal ein paar Zeilen Code selber rein;)

Herzlichen Dank!

Hallo uroni,

Testbackups (mit einem Client VM liefen durch, war ja klar;)
Es läuft aber das Echtbackup gerade und ich bekomme das hier

2016-08-05 20:04:50: WARNING: SQLite: statement aborts at 343: [SELECT * FROM (SELECT a.id AS backupid, clientid, name, strftime('%s', a.backuptime) AS backuptime, backuptime AS bt,incremental, (strftime('%s',running)-strftime('%s',a.backuptime)) errorcode: 522

und

016-08-05 20:05:08: WARNING: SQLite: statement aborts at 27: [UPDATE backups SET running=CURRENT_TIMESTAMP WHERE id=?] disk I/O error errorcode: 522
2016-08-05 20:05:08: ERROR: Error in CQuery::Execute - disk I/O error Stmt: [UPDATE backups SET running=CURRENT_TIMESTAMP WHERE id=?]

hier die Gui

Zur Sicherung selber, es sind hier 2 VM Server die gleichzeitig von einem ESX Server auf den Backupserver gesichert werden.
Gerade ist er abgestorben. Ich mache den log fertig.
Danke.

Hier die Log Datei.

PT: Hashing file “XXX”
HT: Linked file: “XXX”
GT: Loaded file “XXX”

habe ich entfernt.

You could download the SQLite shell or SQLite Browser and then run PRAGMA integrity_check manually on the database files to exclude db corruption.

Herzlichen Dank uroni,

werde ich machen, was mir bloß nicht einleuchten will ist das sogar bei einer neu angelegt und eingerichteten Urbackup Installation die DB schon korrupt sein soll.
Ich melde mich.
Danke!

sqlite3 backup_server_settings.db “PRAGMA integrity_check”
ok

Could you do the same for backup_server.db?

The reason is that this might be an issue that must be reported upstream to the SQLite mailing list. Therefore disk issues must be ruled out. The strace would be helpful as well.

sqlite3 backup_server.db “PRAGMA integrity_check”
ok

Wenn es an den Festplatten/RAID liege sollte warum funktioniert es wenn ich den start nach dem ersten Abbruch via
/etc/init.d# ./urbackupsrv start anstoße?
Die Backup’s die ich via VGhetto auf dem Backupserver schreiben lasse laufen durch und ein Test Recover funktionert.
Auch gibt mir ein dd if=/dev/zero of=/root/testfile bs=1G count=1 oflag=dsync nichts aufälliges aus.
Ich meine SQL ist schon sensibel was RAID Cache etc. angeht. Aber bei der Performance dürfte das kein Problem sein.
Danke!

Ich sehe mir heute Abend mal den nächsten Backupjob an.
Danke.

leider wieder das gleiche, wenn das Backup fertig ist schicke ich dir das Log via Mail. Wo kann ich noch suchen? Wenn ich wie oben schon beschrieben starte (/etc/init.d# ./urbackupsrv start) funktioniert es ja, nur wenn der Task von selbst starten soll geht es ja nicht!
Vielleicht verschluckt er sich ja bei der Installation da ich via dpkg und apt-get install -f installiere und nicht über die Ubuntu repo?
Danke uroni!

Hallo uroni,

danke für das update auf 2.0.32 aber leider ist der Fehler nicht weg.
nach update neue Fehlermeldung
WARNING: SQLite: statement aborts at 5: [UPDATE backups SET running=CURRENT_TIMESTAMP WHERE id=?] disk I/O error errorcode: 522)
WARNING: SQLite: statement aborts at 5: [UPDATE backups SET running=CURRENT_TIMESTAMP WHERE id=?] disk I/O error errorcode: 522")

meine versuche bis dahin, urbackup über repo installiert aber auch ohne Erfolg.

Hallo uroni,

die Sicherungen sind gestern ohne Fehler durchgelaufen ABER er hat die vorigen nicht gelöscht was er sonst immer gemacht hat.
Ich melde mich wieder.
(Das VHDZ mount funktioniert wieder, ging mit der 2.0.31 ja nicht)

Danke.

Hallo uroni,

so leider wieder das selbe

2016-08-15 20:27:10: File processing speed: 500000 files/s
2016-08-15 20:27:10: Updating file statistics: 99%
2016-08-15 20:27:10: Done updating statistics.
2016-08-15 20:27:11: msg=WAKEUP
2016-08-15 20:27:11: server_prepare_hash Thread finished (exit)
2016-08-15 20:27:11: server_hash Thread finished - normal
2016-08-15 20:27:30: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:30: ERROR: Error preparing Query [PRAGMA synchronous=NORMAL]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:31: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:31: ERROR: Error preparing Query [PRAGMA synchronous=NORMAL]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:32: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:32: ERROR: Error preparing Query [PRAGMA synchronous=NORMAL]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:33: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:33: ERROR: Error preparing Query [PRAGMA synchronous=NORMAL]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:34: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:34: ERROR: Error preparing Query [PRAGMA synchronous=NORMAL]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:35: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:35: ERROR: Error preparing Query [PRAGMA synchronous=NORMAL]: disk I/O error
2016-08-15 20:27:35: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:35: ERROR: Error preparing Query [PRAGMA cache_size = -2048]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:36: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:36: ERROR: Error preparing Query [PRAGMA cache_size = -2048]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:37: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:37: ERROR: Error preparing Query [PRAGMA cache_size = -2048]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:37: WARNING: SQLite: statement aborts at 27: [UPDATE backups SET running=CURRENT_TIMESTAMP WHERE id=?] disk I/O error errorcode: 522
2016-08-15 20:27:37: ERROR: Error in CQuery::Execute - disk I/O error Stmt: [UPDATE backups SET running=CURRENT_TIMESTAMP WHERE id=?]
2016-08-15 20:27:38: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:38: ERROR: Error preparing Query [PRAGMA cache_size = -2048]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:39: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:39: ERROR: Error preparing Query [PRAGMA cache_size = -2048]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:40: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:40: ERROR: Error preparing Query [PRAGMA cache_size = -2048]: disk I/O error
2016-08-15 20:27:40: WARNING: SQLite: statement aborts at 4: [ATTACH DATABASE ‘urbackup/backup_server_settings.db’ AS settings_db] disk I/O error errorcode: 522
2016-08-15 20:27:40: ERROR: Error in CQuery::Execute - disk I/O error Stmt: [ATTACH DATABASE ‘urbackup/backup_server_settings.db’ AS settings_db]
2016-08-15 20:27:40: ERROR: SQL: disk I/O error Stmt: [ATTACH DATABASE ‘urbackup/backup_server_settings.db’ AS settings_db]
2016-08-15 20:27:40: Starting full file backup…
2016-08-15 20:27:40: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:40: ERROR: Error preparing Query [SELECT indexing_time_ms, (strftime(’%s’,running)-strftime(’%s’,backuptime)) AS duration FROM backups WHERE clientid=? AND done=1 AND complete=1 AND incremental=0 AND resumed=0 ORDER BY b
ackuptime DESC LIMIT 1]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:41: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:41: ERROR: Error preparing Query [SELECT indexing_time_ms, (strftime(’%s’,running)-strftime(’%s’,backuptime)) AS duration FROM backups WHERE clientid=? AND done=1 AND complete=1 AND incremental=0 AND resumed=0 ORDER BY b
ackuptime DESC LIMIT 1]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:42: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:42: ERROR: Error preparing Query [SELECT indexing_time_ms, (strftime(’%s’,running)-strftime(’%s’,backuptime)) AS duration FROM backups WHERE clientid=? AND done=1 AND complete=1 AND incremental=0 AND resumed=0 ORDER BY b
ackuptime DESC LIMIT 1]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:43: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:43: ERROR: Error preparing Query [SELECT indexing_time_ms, (strftime(’%s’,running)-strftime(’%s’,backuptime)) AS duration FROM backups WHERE clientid=? AND done=1 AND complete=1 AND incremental=0 AND resumed=0 ORDER BY b
ackuptime DESC LIMIT 1]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:44: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:44: ERROR: Error preparing Query [SELECT indexing_time_ms, (strftime(’%s’,running)-strftime(’%s’,backuptime)) AS duration FROM backups WHERE clientid=? AND done=1 AND complete=1 AND incremental=0 AND resumed=0 ORDER BY b
ackuptime DESC LIMIT 1]: disk I/O error. Retrying in 1s…
2016-08-15 20:27:45: WARNING: SQLite: disk I/O error errorcode: 522
2016-08-15 20:27:45: ERROR: Error preparing Query [SELECT indexing_time_ms, (strftime(’%s’,running)-strftime(’%s’,backuptime)) AS duration FROM backups WHERE clientid=? AND done=1 AND complete=1 AND incremental=0 AND resumed=0 ORDER BY b
ackuptime DESC LIMIT 1]: disk I/O error
2016-08-15 21:01:52: Starting HTTP-Server on port 55414
2016-08-15 21:01:52: HTTP: Server started up successfully!
2016-08-15 21:01:52: Started UrBackup…
2016-08-15 21:01:52: Removing temporary files…
2016-08-15 21:01:53: UrBackup Server start up complete.
2016-08-15 21:01:53: Looking for old Sessions… 0 sessions
2016-08-15 21:01:53: Server started up successfully!
2016-08-15 21:01:57: Recreating temporary folder…

ich habe leider die nächsten 2 Wochen keine Zeit den Server neu zu installieren.
Manuell angestoßen und es läuft wieder!
Ich habe jetzt einen cronjob eingerichtet der vor dem Backup manuell ein remove unknown macht, mal sehen ob das wirkt.

Hallo Community und uroni,

eine halbe Stunde vor dem Backup lasse ich das über cron laufen

/etc/init.d# ./urbackupsrv stop
urbackupsrv remove-unknown
/etc/init.d# ./urbackupsrv start

keine Fehler, Sicherung läuft wir früher normal durch.
Sobald ich das Script abschalte, wieder die gleichen Fehler!
Ich hoffe auf die 2.0.33!
Danke.

Hallo Community and uroni,

same issue after update 2.0.33.
I’ll send you the log via email.

thanks

Thanks. Meanwhile I had a second report from someone with the same issue (also Ubuntu Linux).

As mentioned, this is probably not an UrBackup issue, but a SQLite issue. If you want to you could report it to this mailing list: http://sqlite.org:8080/cgi-bin/mailman/listinfo/sqlite-users (with the log messages + possibly strace).

UrBackup 2.0.33 uses SQlite version 3.13.0.

The error code 522 is SQLITE_IOERR_SHORT_READ. This means Linux did not read as many bytes as SQLite requested. Normally this only happens if you truncate the file. Idk why it sometimes happens for sqlite prepares… (I’ve seen it on FreeBSD as well, which is why it retries this five times now, which does not seem enough. You could try increasing the define SQLITE_PREPARE_RETRIES in the make file. But that is very much a “ghetto workaround”)

Thanks, Thanks, Thanks Uroni

Now I know where I stand. My sqlite Version is
sqlite3 SQLite version 3.8.2??? is perhaps the problem?
Either I’m doing a downgrade of urbackup or Realese upgrade to 16.04

thanks!!!

No, SQLite (version 3.13.0) is built into UrBackup. Could be the newer SQLite version in UrBackup 2.x has that problem or it is something else UrBackup 2.x is doing. The problem will not get solved without the SQLite developers getting involved and getting the appropriate information like an strace!

shi… :wink:
I need now quickly a working backup so I have to make a downgrade firstonce
sorry
What do you recommend for Distri?

thx