Bug#706862: Database destroyed during upgrade from squeeze

Agustín Eijo aeijo at mpba.gov.ar
Mon May 13 13:44:57 UTC 2013


Sorry,

Had he made a mistake in the form of restore and The error is not "db4.7_recover: Build 
signature doesn't match environment"

Now I think the problem is in the script upgrade-db with the variable BERKELEY_DB_FOUND

The BERKELEY_DB_FOUND  is set into the while .. done but out of while BERKELEY_DB_FOUND  
is unset and then run:

             # Remove empty environment
             rm -rf $CONFIG_DIR/db

This is the output upgrade-db of  with -x

/usr/lib/cyrus/bin/upgrade-db
+ export PATH=/sbin:/usr/sbin:/bin:/usr/bin
+ LC_ALL=C gawk /^configdirectory:[[:blank:]]/ { print $2 }
+ CONFIG_DIR=/var/lib/cyrus
+ date +%Y%m%d-%H%M%S
+ BACKUP_DIR=/var/backup/cyrus-imapd/20130513-103004
+ mkdir -p /var/backup/cyrus-imapd/20130513-103004
+ upgradealldb /usr/lib/cyrus/cyrus-db-types.txt /usr/lib/cyrus/cyrus-db-types.active
+ OLD_LIST=/usr/lib/cyrus/cyrus-db-types.active
+ NEW_LIST=/usr/lib/cyrus/cyrus-db-types.txt
+ DO_UPGRADE_BDB=
+ sed -e s/BerkeleyDB//
+ LC_ALL=C gawk /^DBENGINE[[:blank:]]/ { print $2 } /usr/lib/cyrus/cyrus-db-types.active
+ OLD_DBVERSION=4.7
+ sed -e s/BerkeleyDB//
+ LC_ALL=C gawk /^DBENGINE[[:blank:]]/ { print $2 } /usr/lib/cyrus/cyrus-db-types.txt
+ NEW_DBVERSION=5.1
+ [ 4.7 != 5.1 ]
+ DO_UPGRADE_BDB=yes
+ DB_UTIL_NOT_FOUND=
+ [ ! -x /usr/bin/db4.7_recover ]
+ [ ! -x /usr/bin/db5.1_upgrade ]
+ [ -n  ]
+ BERKELEY_DB_FOUND=
+ read -r OLD_DBKEY OLD_DBVALUE
+ cat /usr/lib/cyrus/cyrus-db-types.active
+ LC_ALL=C gawk /^ANNOTATION[[:blank:]]/ { print $2 } /usr/lib/cyrus/cyrus-db-types.txt
+ NEW_DBVALUE=skiplist
+ [ -z skiplist ]
+ DO_UPGRADE_DB=
+ [ skiplist != skiplist ]
+ DBFILE=
+ DBFILE=annotations.db
+ [ -n  ]
+ [ -f /var/lib/cyrus/annotations.db ]
+ [ -n  -o -n yes ]
+ backupdb annotations.db skiplist 4.7
+ cp -a /var/lib/cyrus/annotations.db /var/backup/cyrus-imapd/20130513-103004
+ [ -n yes ]
+ [ -n  ]
+ read -r OLD_DBKEY OLD_DBVALUE
+ LC_ALL=C gawk /^DBENGINE[[:blank:]]/ { print $2 } /usr/lib/cyrus/cyrus-db-types.txt
+ NEW_DBVALUE=BerkeleyDB5.1
+ [ -z BerkeleyDB5.1 ]
+ DO_UPGRADE_DB=
+ [ BerkeleyDB5.1 != BerkeleyDB4.7 ]
+ DO_UPGRADE_DB=yes
+ DBFILE=
+ continue
+ read -r OLD_DBKEY OLD_DBVALUE
+ LC_ALL=C gawk /^DUPLICATE[[:blank:]]/ { print $2 } /usr/lib/cyrus/cyrus-db-types.txt
+ NEW_DBVALUE=skiplist
+ [ -z skiplist ]
+ DO_UPGRADE_DB=
+ [ skiplist != berkeley-nosync ]
+ DO_UPGRADE_DB=yes
+ DBFILE=
+ DBFILE=deliver.db
+ [ -n yes ]
+ [ -f /var/lib/cyrus/deliver.db ]
+ [ -n yes -o -n yes ]
+ backupdb deliver.db berkeley-nosync 4.7
+ cp -a /var/lib/cyrus/deliver.db /var/backup/cyrus-imapd/20130513-103004
+ [ ! -d /var/backup/cyrus-imapd/20130513-103004/db -a -d /var/lib/cyrus/db ]
+ mkdir -p /var/backup/cyrus-imapd/20130513-103004/db
+ su cyrus -c db4.7_recover -h /var/lib/cyrus/db
+ read log_file
+ su cyrus -c db4.7_archive -h /var/lib/cyrus/db -l
+ cp -a /var/lib/cyrus/db/log.0000000001 /var/backup/cyrus-imapd/20130513-103004/db
+ read log_file
+ [ -n yes ]
+ BERKELEY_DB_FOUND=yes
+ upgradebdb deliver.db 5.1
+ su cyrus -c db5.1_upgrade -h /var/lib/cyrus/db /var/lib/cyrus/deliver.db
+ [ -n yes ]
+ upgradedb deliver.db berkeley-nosync skiplist
+ mktemp /tmp/deliver.db.XXXXXXXX
+ TMPFILE=/tmp/deliver.db.mypy2OBF
+ /usr/sbin/cvt_cyrusdb /var/lib/cyrus/deliver.db berkeley-nosync /tmp/deliver.db.mypy2OBF 
skiplist
Converting from /var/lib/cyrus/deliver.db (berkeley-nosync) to /tmp/deliver.db.mypy2OBF 
(skiplist)
+ rm -f /var/lib/cyrus/deliver.db
+ mv /tmp/deliver.db.mypy2OBF /var/lib/cyrus/deliver.db
+ chown cyrus:mail /var/lib/cyrus/deliver.db
+ read -r OLD_DBKEY OLD_DBVALUE
+ LC_ALL=C gawk /^MBOX[[:blank:]]/ { print $2 } /usr/lib/cyrus/cyrus-db-types.txt
+ NEW_DBVALUE=skiplist
+ [ -z skiplist ]
+ DO_UPGRADE_DB=
+ [ skiplist != skiplist ]
+ DBFILE=
+ DBFILE=mailboxes.db
+ [ -n  ]
+ [ -f /var/lib/cyrus/mailboxes.db ]
+ [ -n  -o -n yes ]
+ backupdb mailboxes.db skiplist 4.7
+ cp -a /var/lib/cyrus/mailboxes.db /var/backup/cyrus-imapd/20130513-103004
+ [ -n yes ]
+ [ -n  ]
+ read -r OLD_DBKEY OLD_DBVALUE
+ LC_ALL=C gawk /^PTS[[:blank:]]/ { print $2 } /usr/lib/cyrus/cyrus-db-types.txt
+ NEW_DBVALUE=skiplist
+ [ -z skiplist ]
+ DO_UPGRADE_DB=
+ [ skiplist != berkeley ]
+ DO_UPGRADE_DB=yes
+ DBFILE=
+ [ -n yes ]
+ removedb ptscache.db
+ rm -f /var/lib/cyrus/ptscache.db
+ continue
+ read -r OLD_DBKEY OLD_DBVALUE
+ LC_ALL=C gawk /^QUOTA[[:blank:]]/ { print $2 } /usr/lib/cyrus/cyrus-db-types.txt
+ NEW_DBVALUE=quotalegacy
+ [ -z quotalegacy ]
+ DO_UPGRADE_DB=
+ [ quotalegacy != quotalegacy ]
+ DBFILE=
+ [ -n  ]
+ [ -n  ]
+ [ -f /var/lib/cyrus/ ]
+ read -r OLD_DBKEY OLD_DBVALUE
+ LC_ALL=C gawk /^SEEN[[:blank:]]/ { print $2 } /usr/lib/cyrus/cyrus-db-types.txt
+ NEW_DBVALUE=skiplist
+ [ -z skiplist ]
+ DO_UPGRADE_DB=
+ [ skiplist != skiplist ]
+ DBFILE=
+ [ -n  ]
+ [ -n  ]
+ [ -f /var/lib/cyrus/ ]
+ read -r OLD_DBKEY OLD_DBVALUE
+ LC_ALL=C gawk /^SUBS[[:blank:]]/ { print $2 } /usr/lib/cyrus/cyrus-db-types.txt
+ NEW_DBVALUE=flat
+ [ -z flat ]
+ DO_UPGRADE_DB=
+ [ flat != flat ]
+ DBFILE=
+ [ -n  ]
+ [ -n  ]
+ [ -f /var/lib/cyrus/ ]
+ read -r OLD_DBKEY OLD_DBVALUE
+ LC_ALL=C gawk /^TLS[[:blank:]]/ { print $2 } /usr/lib/cyrus/cyrus-db-types.txt
+ NEW_DBVALUE=skiplist
+ [ -z skiplist ]
+ DO_UPGRADE_DB=
+ [ skiplist != berkeley-nosync ]
+ DO_UPGRADE_DB=yes
+ DBFILE=
+ [ -n yes ]
+ removedb tls_sessions.db
+ rm -f /var/lib/cyrus/tls_sessions.db
+ continue
+ read -r OLD_DBKEY OLD_DBVALUE
+ [ -n yes -a -d /var/lib/cyrus/db ]
+ [ -n  ]
+ rm -rf /var/lib/cyrus/db
+ return 0
+ RET=0
+ [ 0 -eq 0 ]
+ cp -p /usr/lib/cyrus/cyrus-db-types.txt /usr/lib/cyrus/cyrus-db-types.active
+ exit 0

And this is my syslog error:

/etc/init.d/cyrus-imapd restart

May 13 10:31:54 tostadora master[30773]: attempting clean shutdown on SIGQUIT
May 13 10:31:54 tostadora cyrus/notify[30802]: recvfrom failed: Interrupted system call
May 13 10:31:54 tostadora master[30773]: process 30802 exited, status 71
May 13 10:31:54 tostadora master[30773]: All children have exited, closing down
May 13 10:31:54 tostadora master[31252]: process started
May 13 10:31:54 tostadora master[31254]: about to exec /usr/sbin/ctl_cyrusdb
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: DBERROR db5: /var/lib/cyrus/db: No 
such file or directory
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: DBERROR db5: 
/var/lib/cyrus/db/__db.001: No such file or directory
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: DBERROR db5: /var/lib/cyrus/db: No 
such file or directory
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: DBERROR db5: 
/var/lib/cyrus/db/__db.001: No such file or directory
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: DBERROR: dbenv->open 
'/var/lib/cyrus/db' failed: No such file or directory
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: DBERROR: init() on berkeley
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: DBERROR: writing 
/var/lib/cyrus/db/skipstamp: No such file or directory
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: DBERROR: init() on skiplist
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: recovering cyrus databases
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: skiplist: checkpointed 
/var/lib/cyrus/mailboxes.db (27 records, 2020 bytes) in 0 seconds
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: skiplist: checkpointed 
/var/lib/cyrus/annotations.db (0 records, 144 bytes) in 0 seconds
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31254]: done recovering cyrus databases
May 13 10:31:54 tostadora master[31274]: about to exec /usr/sbin/cyr_expire
May 13 10:31:54 tostadora cyrus/cyr_expire[31274]: DBERROR db5: 
/var/lib/cyrus/db/__db.001: No such file or directory
May 13 10:31:54 tostadora cyrus/cyr_expire[31274]: DBERROR: dbenv->open 
'/var/lib/cyrus/db' failed: No such file or directory
May 13 10:31:54 tostadora cyrus/cyr_expire[31274]: DBERROR: init() on berkeley
May 13 10:31:54 tostadora cyrus/cyr_expire[31274]: DBERROR: reading 
/var/lib/cyrus/db/skipstamp, assuming the worst: No such file or directory
May 13 10:31:54 tostadora cyrus/cyr_expire[31274]: skiplist: checkpointed 
/var/lib/cyrus/annotations.db (0 records, 144 bytes) in 0 seconds
May 13 10:31:54 tostadora cyrus/cyr_expire[31274]: skiplist: checkpointed 
/var/lib/cyrus/mailboxes.db (27 records, 2020 bytes) in 0 seconds
May 13 10:31:54 tostadora cyrus/cyr_expire[31274]: skiplist: checkpointed 
/var/lib/cyrus/deliver.db (13 records, 1448 bytes) in 0 seconds
May 13 10:31:54 tostadora cyrus/cyr_expire[31274]: Expunged 0 out of 345 messages from 27 
mailboxes
May 13 10:31:54 tostadora cyrus/cyr_expire[31274]: duplicate_prune: pruning back 3.00 days
May 13 10:31:54 tostadora cyrus/cyr_expire[31274]: duplicate_prune: purged 0 out of 13 entries
May 13 10:31:54 tostadora master[31277]: about to exec /usr/sbin/tls_prune
May 13 10:31:54 tostadora cyrus/tls_prune[31277]: DBERROR db5: /var/lib/cyrus/db/__db.001: 
No such file or directory
May 13 10:31:54 tostadora cyrus/tls_prune[31277]: DBERROR: dbenv->open '/var/lib/cyrus/db' 
failed: No such file or directory
May 13 10:31:54 tostadora cyrus/tls_prune[31277]: DBERROR: init() on berkeley
May 13 10:31:54 tostadora cyrus/tls_prune[31277]: DBERROR: reading 
/var/lib/cyrus/db/skipstamp, assuming the worst: No such file or directory
May 13 10:31:54 tostadora cyrus/tls_prune[31277]: DBERROR: opening 
/var/lib/cyrus/tls_sessions.db: cyrusdb error
May 13 10:31:54 tostadora master[31252]: process 31277 exited, status 1
May 13 10:31:54 tostadora master[31252]: unable to setsocketopt(IP_TOS): Operation not 
supported
May 13 10:31:54 tostadora master[31252]: unable to setsocketopt(IP_TOS): Operation not 
supported
May 13 10:31:54 tostadora master[31252]: ready for work
May 13 10:31:54 tostadora master[31281]: about to exec /usr/lib/cyrus/bin/notifyd
May 13 10:31:54 tostadora master[31280]: about to exec /usr/sbin/ctl_cyrusdb
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31280]: DBERROR db5: 
/var/lib/cyrus/db/__db.001: No such file or directory
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31280]: DBERROR: dbenv->open 
'/var/lib/cyrus/db' failed: No such file or directory
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31280]: DBERROR: init() on berkeley
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31280]: DBERROR: reading 
/var/lib/cyrus/db/skipstamp, assuming the worst: No such file or directory
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31280]: checkpointing cyrus databases
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31280]: archiving database file: 
/var/lib/cyrus/mailboxes.db
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31280]: archiving database file: 
/var/lib/cyrus/annotations.db
May 13 10:31:54 tostadora cyrus/ctl_cyrusdb[31280]: done checkpointing cyrus databases
May 13 10:31:54 tostadora master[31252]: process 31280 exited, status 0
May 13 10:31:54 tostadora cyrus/notify[31281]: DBERROR db5: /var/lib/cyrus/db/__db.001: No 
such file or directory
May 13 10:31:54 tostadora cyrus/notify[31281]: DBERROR: dbenv->open '/var/lib/cyrus/db' 
failed: No such file or directory
May 13 10:31:54 tostadora cyrus/notify[31281]: DBERROR: init() on berkeley
May 13 10:31:54 tostadora cyrus/notify[31281]: DBERROR: reading 
/var/lib/cyrus/db/skipstamp, assuming the worst: No such file or directory
May 13 10:31:54 tostadora cyrus/notify[31281]: executed


If hardset BERKELEY_DB_FOUND=yes before than:

     BERKELEY_DB_FOUND=yes
     # Create Berkeley DB checkpoint and remove old logs
     if [ -n "${DO_UPGRADE_BDB}" -a -d $CONFIG_DIR/db ]; then
         if [ -n "${BERKELEY_DB_FOUND}" ]; then
             # Create new checkpoint
             checkpointbdb $NEW_DBVERSION
         else
             # Remove empty environment
             rm -rf $CONFIG_DIR/db
         fi
     fi
     return 0

The syslog looks much better:

May 13 10:36:15 tostadora master[31319]: attempting clean shutdown on SIGQUIT
May 13 10:36:15 tostadora cyrus/notify[31348]: recvfrom failed: Interrupted system call
May 13 10:36:15 tostadora master[31319]: process 31348 exited, status 71
May 13 10:36:15 tostadora master[31319]: All children have exited, closing down
May 13 10:36:15 tostadora master[31439]: process started
May 13 10:36:16 tostadora master[31442]: about to exec /usr/sbin/ctl_cyrusdb
May 13 10:36:16 tostadora cyrus/ctl_cyrusdb[31442]: recovering cyrus databases
May 13 10:36:16 tostadora cyrus/ctl_cyrusdb[31442]: skiplist: checkpointed 
/var/lib/cyrus/mailboxes.db (27 records, 2020 bytes) in 0 seconds
May 13 10:36:16 tostadora cyrus/ctl_cyrusdb[31442]: skiplist: checkpointed 
/var/lib/cyrus/annotations.db (0 records, 144 bytes) in 0 seconds
May 13 10:36:16 tostadora cyrus/ctl_cyrusdb[31442]: done recovering cyrus databases
May 13 10:36:16 tostadora master[31461]: about to exec /usr/sbin/cyr_expire
May 13 10:36:16 tostadora cyrus/cyr_expire[31461]: skiplist: checkpointed 
/var/lib/cyrus/deliver.db (13 records, 1452 bytes) in 0 seconds
May 13 10:36:16 tostadora cyrus/cyr_expire[31461]: Expunged 0 out of 345 messages from 27 
mailboxes
May 13 10:36:16 tostadora cyrus/cyr_expire[31461]: duplicate_prune: pruning back 3.00 days
May 13 10:36:16 tostadora cyrus/cyr_expire[31461]: duplicate_prune: purged 0 out of 13 entries
May 13 10:36:16 tostadora master[31464]: about to exec /usr/sbin/tls_prune
May 13 10:36:16 tostadora cyrus/tls_prune[31464]: DBERROR: opening 
/var/lib/cyrus/tls_sessions.db: cyrusdb error
May 13 10:36:16 tostadora master[31439]: process 31464 exited, status 1
May 13 10:36:16 tostadora master[31439]: unable to setsocketopt(IP_TOS): Operation not 
supported
May 13 10:36:16 tostadora master[31439]: unable to setsocketopt(IP_TOS): Operation not 
supported
May 13 10:36:16 tostadora master[31439]: ready for work
May 13 10:36:16 tostadora master[31468]: about to exec /usr/lib/cyrus/bin/notifyd
May 13 10:36:16 tostadora cyrus/notify[31468]: executed
May 13 10:36:16 tostadora master[31467]: about to exec /usr/sbin/ctl_cyrusdb
May 13 10:36:16 tostadora cyrus/ctl_cyrusdb[31467]: checkpointing cyrus databases
May 13 10:36:16 tostadora cyrus/ctl_cyrusdb[31467]: archiving database file: 
/var/lib/cyrus/mailboxes.db
May 13 10:36:16 tostadora cyrus/ctl_cyrusdb[31467]: archiving database file: 
/var/lib/cyrus/annotations.db
May 13 10:36:16 tostadora cyrus/ctl_cyrusdb[31467]: done checkpointing cyrus databases
May 13 10:36:16 tostadora master[31439]: process 31467 exited, status 0

But I have two problems more:

May 13 10:36:16 tostadora cyrus/tls_prune[31464]: DBERROR: opening 
/var/lib/cyrus/tls_sessions.db: cyrusdb error

May 13 10:36:16 tostadora master[31439]: unable to setsocketopt(IP_TOS): Operation not 
supported

Thank, Agu.




--
Piense antes de imprimir. Ahorrar papel es cuidar el medio ambiente.



More information about the Pkg-Cyrus-imapd-Debian-devel mailing list