Bug 913783 - [abrt] rdiff-backup-1.2.8-8.fc18: log.py:129:log_to_file:IOError: [Errno 30] Read-only file system
Summary: [abrt] rdiff-backup-1.2.8-8.fc18: log.py:129:log_to_file:IOError: [Errno 30] ...
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Fedora
Classification: Fedora
Component: rdiff-backup
Version: 18
Hardware: i686
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Kevin Fenzi
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: abrt_hash:27096347971ae0604d4d3e024f3...
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-02-22 03:08 UTC by wdouglascampbell
Modified: 2013-02-27 04:52 UTC (History)
1 user (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2013-02-27 04:52:39 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
File: backtrace (2.28 KB, text/plain)
2013-02-22 03:08 UTC, wdouglascampbell
no flags Details
File: core_backtrace (1.66 KB, text/plain)
2013-02-22 03:08 UTC, wdouglascampbell
no flags Details
File: environ (143 bytes, text/plain)
2013-02-22 03:08 UTC, wdouglascampbell
no flags Details
File: smolt_data (2.64 KB, text/plain)
2013-02-22 03:09 UTC, wdouglascampbell
no flags Details

Description wdouglascampbell 2013-02-22 03:08:49 UTC
Description of problem:
I have no idea.  I just recently updated from Fedora 16 to 18.  I actually do not know what error is occuring but this notification said there was an error.

Version-Release number of selected component:
rdiff-backup-1.2.8-8.fc18

Additional info:
cmdline:        /usr/bin/python /usr/bin/rdiff-backup --include-globbing-filelist /home/swbackup/rdiff_backup_includes.txt --exclude / scooby::/ /data/scooby-backup
executable:     /usr/bin/rdiff-backup
kernel:         3.7.8-202.loopAES.fc18.i686.PAE
uid:            501

Truncated backtrace:
log.py:129:log_to_file:IOError: [Errno 30] Read-only file system

Traceback (most recent call last):
  File "/usr/bin/rdiff-backup", line 30, in <module>
    rdiff_backup.Main.error_check_Main(sys.argv[1:])
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 304, in error_check_Main
    try: Main(arglist)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 324, in Main
    take_action(rps)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 280, in take_action
    elif action == "backup": Backup(rps[0], rps[1])
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 343, in Backup
    backup.Mirror_and_increment(rpin, rpout, incdir)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/backup.py", line 51, in Mirror_and_increment
    DestS.patch_and_increment(dest_rpath, source_diffiter, inc_rpath)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/backup.py", line 243, in patch_and_increment
    ITR(diff.index, diff)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/rorpiter.py", line 281, in __call__
    last_branch.fast_process(*args)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/backup.py", line 694, in fast_process
    increment.Increment, (tf, mirror_rp, inc_prefix))
  File "/usr/lib/python2.7/site-packages/rdiff_backup/robust.py", line 39, in check_common_error
    if error_handler: return error_handler(exc, *args)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/robust.py", line 91, in error_handler
    log.ErrorLog.write_if_open(error_type, rp, exc)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/log.py", line 255, in write_if_open
    if cls.isopen(): cls.write(error_type, rp, exc)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/log.py", line 236, in write
    Log(s, 2)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/log.py", line 120, in __call__
    if verbosity <= self.verbosity: self.log_to_file(message)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/log.py", line 129, in log_to_file
    self.logfp.flush()
IOError: [Errno 30] Read-only file system

Local variables in innermost frame:
message: 'UpdateError data/secure/Finance/Solomon/Backups/Solapplication Backups/rdiff-backup.tmp.26145 [Errno 5] Input/output error'
self: <rdiff_backup.log.Logger instance at 0xb75d03ac>

Potential duplicate: bug 726366

Comment 1 wdouglascampbell 2013-02-22 03:08:54 UTC
Created attachment 700967 [details]
File: backtrace

Comment 2 wdouglascampbell 2013-02-22 03:08:56 UTC
Created attachment 700968 [details]
File: core_backtrace

Comment 3 wdouglascampbell 2013-02-22 03:08:59 UTC
Created attachment 700969 [details]
File: environ

Comment 4 wdouglascampbell 2013-02-22 03:09:02 UTC
Created attachment 700970 [details]
File: smolt_data

Comment 5 Kevin Fenzi 2013-02-22 05:53:37 UTC
The place you are trying to save your backup to seems to be read-only? 

What kind of filesystem is /data/scooby-backup ? 

Any errors on it in dmesg or is it showing as ro in /proc/mounts ?

Comment 6 wdouglascampbell 2013-02-23 03:36:10 UTC
There may have been two problems.  One is that my filesystem mounted at /data/scooby-backup may have not been mounted at the time of backup and its mountpoint is normally read only to the user swbackup.  Two is that I found that I seemed to lose power to the hard drive yesterday when I was testing and that may have occured when I got this error.

Right now, I am running the backup again and it seems to be taking a long time as it is saying that it is "regressing the destination now".

I have another backup on the same system trying to run to another mountpoint.  I can confirm the mounted filesystem has 1.1TB of space available but yet when I run:

rdiff-backup --include-globbing-filelist /home/swbackup/rdiff_backup2_includes.txt --exclude / scooby::/ /data-2.0TB/scooby-backup

I get the following output:

Exception '[Errno 28] No space left on device' raised of class '<type 'exceptions.IOError'>':
  File "/usr/lib/python2.7/site-packages/rdiff_backup/robust.py", line 32, in check_common_error
    try: return function(*args)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/restore.py", line 462, in get_fp
    current_fp = self.get_first_fp()
  File "/usr/lib/python2.7/site-packages/rdiff_backup/restore.py", line 499, in get_first_fp
    rpath.copyfileobj(fp, current_fp)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/rpath.py", line 64, in copyfileobj
    outputfp.write(inbuf)

Exception '[Errno 28] No space left on device' raised of class '<type 'exceptions.IOError'>':
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 304, in error_check_Main
    try: Main(arglist)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 324, in Main
    take_action(rps)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 280, in take_action
    elif action == "backup": Backup(rps[0], rps[1])
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 337, in Backup
    backup_final_init(rpout)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 501, in backup_final_init
    checkdest_if_necessary(rpout)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 920, in checkdest_if_necessary
    dest_rp.conn.regress.Regress(dest_rp)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/regress.py", line 71, in Regress
    for rf in iterate_meta_rfs(mirror_rp, inc_rpath): ITR(rf.index, rf)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/rorpiter.py", line 281, in __call__
    last_branch.fast_process(*args)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/regress.py", line 268, in fast_process
    if rf.metadata_rorp.isreg(): self.restore_orig_regfile(rf)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/regress.py", line 296, in restore_orig_regfile
    rf.mirror_rp.write_from_fileobj(rf.get_restore_fp())
  File "/usr/lib/python2.7/site-packages/rdiff_backup/restore.py", line 488, in get_restore_fp
    return robust.check_common_error(error_handler, get_fp)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/robust.py", line 32, in check_common_error
    try: return function(*args)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/restore.py", line 462, in get_fp
    current_fp = self.get_first_fp()
  File "/usr/lib/python2.7/site-packages/rdiff_backup/restore.py", line 499, in get_first_fp
    rpath.copyfileobj(fp, current_fp)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/rpath.py", line 64, in copyfileobj
    outputfp.write(inbuf)

Traceback (most recent call last):
  File "/usr/bin/rdiff-backup", line 30, in <module>
    rdiff_backup.Main.error_check_Main(sys.argv[1:])
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 304, in error_check_Main
    try: Main(arglist)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 324, in Main
    take_action(rps)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 280, in take_action
    elif action == "backup": Backup(rps[0], rps[1])
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 337, in Backup
    backup_final_init(rpout)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 501, in backup_final_init
    checkdest_if_necessary(rpout)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/Main.py", line 920, in checkdest_if_necessary
    dest_rp.conn.regress.Regress(dest_rp)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/regress.py", line 71, in Regress
    for rf in iterate_meta_rfs(mirror_rp, inc_rpath): ITR(rf.index, rf)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/rorpiter.py", line 281, in __call__
    last_branch.fast_process(*args)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/regress.py", line 268, in fast_process
    if rf.metadata_rorp.isreg(): self.restore_orig_regfile(rf)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/regress.py", line 296, in restore_orig_regfile
    rf.mirror_rp.write_from_fileobj(rf.get_restore_fp())
  File "/usr/lib/python2.7/site-packages/rdiff_backup/restore.py", line 488, in get_restore_fp
    return robust.check_common_error(error_handler, get_fp)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/robust.py", line 32, in check_common_error
    try: return function(*args)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/restore.py", line 462, in get_fp
    current_fp = self.get_first_fp()
  File "/usr/lib/python2.7/site-packages/rdiff_backup/restore.py", line 499, in get_first_fp
    rpath.copyfileobj(fp, current_fp)
  File "/usr/lib/python2.7/site-packages/rdiff_backup/rpath.py", line 64, in copyfileobj
    outputfp.write(inbuf)
IOError: [Errno 28] No space left on device
Fatal Error: Lost connection to the remote system


This is the result of df -h:

Filesystem                     Size  Used Avail Use% Mounted on
devtmpfs                       2.0G     0  2.0G   0% /dev
tmpfs                          2.0G  152K  2.0G   1% /dev/shm
tmpfs                          2.0G  4.0M  2.0G   1% /run
tmpfs                          2.0G     0  2.0G   0% /sys/fs/cgroup
/dev/mapper/vg_hotpot-lv_root  267G   25G  229G  10% /
/dev/sdb1                      984M   89M  844M  10% /boot
/dev/loop2                     2.0G  3.1M  1.9G   1% /tmp
/dev/loop0                     1.8T  259G  1.5T  15% /data
/dev/loop1                     1.4T  558G  748G  43% /data-1.5TB
/dev/loop3                     1.8T  616G  1.1T  36% /data-2.0TB

Comment 7 wdouglascampbell 2013-02-23 03:45:00 UTC
The following from the messages log might also be of interest:

Feb 23 11:43:38 hotpot abrt: detected unhandled Python exception in '/usr/bin/rdiff-backup'
Feb 23 11:43:39 hotpot abrtd: New client connected
Feb 23 11:43:40 hotpot abrtd: Directory 'pyhook-2013-02-23-11:43:40-4952' creation detected
Feb 23 11:43:40 hotpot abrt-server[4968]: Saved problem directory of pid 4952 to '/var/spool/abrt/pyhook-2013-02-23-11:43:40-4952'
Feb 23 11:43:40 hotpot abrtd: BDB2053 Freeing read locks for locker 0x6c: 4862/3077723968
Feb 23 11:43:40 hotpot abrtd: BDB2053 Freeing read locks for locker 0x6d: 4862/3077723968
Feb 23 11:43:40 hotpot abrtd: BDB2053 Freeing read locks for locker 0x6e: 4862/3077723968
Feb 23 11:43:40 hotpot abrtd: BDB2053 Freeing read locks for locker 0x6f: 4862/3077723968
Feb 23 11:43:41 hotpot abrtd: Duplicate: core backtrace
Feb 23 11:43:41 hotpot abrtd: DUP_OF_DIR: /var/spool/abrt/pyhook-2013-02-22-13:23:33-11784
Feb 23 11:43:41 hotpot abrtd: Deleting problem directory pyhook-2013-02-23-11:43:40-4952 (dup of pyhook-2013-02-22-13:23:33-11784)

Comment 8 Kevin Fenzi 2013-02-23 21:07:39 UTC
How about 'df -i' ?

Comment 9 wdouglascampbell 2013-02-26 14:37:31 UTC
Filesystem                       Inodes   IUsed     IFree IUse% Mounted on
devtmpfs                         207176     459    206717    1% /dev
tmpfs                            211895       9    211886    1% /dev/shm
tmpfs                            211895     641    211254    1% /run
tmpfs                            211895      12    211883    1% /sys/fs/cgroup
/dev/mapper/vg_hotpot-lv_root  17760256  556120  17204136    4% /
/dev/sdb1                        260096     371    259725    1% /boot
/dev/loop2                       128000      61    127939    1% /tmp
/dev/loop0                    122101760 1001574 121100186    1% /data
/dev/loop1                     91578368  143818  91434550    1% /data-1.5TB
/dev/loop3                    122101760   43736 122058024    1% /data-2.0TB

Comment 10 Kevin Fenzi 2013-02-26 17:57:54 UTC
ok, that looks fine. 

So, anything in dmesg about that filesystem?

If you do a --check-destination-dir on that directory does it correctly check the backups as ok?

Does it work again after a check-destination-dir?

Comment 11 wdouglascampbell 2013-02-26 19:42:35 UTC
Okay.  I think I figured out some of what is happening.

It is regressing the data backup to a previous date and it is working on a 4+ GB file.

I just noticed as it was working on restoring that file that my /tmp filesystem was getting filled up.  It isn't more than 2GB in size.

That is what is running out of space.

Is there something I need to do to not have /tmp used or do I just need to make sure my /tmp has at least as much space as the largest file in my backup for cases where I need to have the backup regressed?

Comment 12 Kevin Fenzi 2013-02-26 22:46:19 UTC
Yeah, see --tempdir in the man page. You can also set TMPDIR env...

Comment 13 wdouglascampbell 2013-02-27 04:52:39 UTC
Cool.  Thanks so much for your help!


Note You need to log in before you can comment on or make changes to this bug.