Learn how easy it is to sync an existing GitHub or Google Code repo to a SourceForge project! See Demo

Close

Investigating 'Operation not permitted...

Help
2011-01-22
2013-08-15
  • Omega Weapon
    Omega Weapon
    2011-01-22

    uname -a: Linux 2.6.35-24-server #42-Ubuntu SMP Thu Dec 2 03:58:11 UTC 2010 x86_64 GNU/Linux

    Whilst updating an ~8.6GB 12,664 file archive with the following:

    7z u "<archive>" -uq0 -m5=LZMA2 -mmt=12 -mhe=on -p<password> "<folder 1 path>" "<folder 2 path>"
    

    I got the following error:

    7-Zip 9.04 beta  Copyright (c) 1999-2009 Igor Pavlov  2009-05-30
    p7zip Version 9.04 (locale=en_GB.utf8,Utf16=on,HugeFiles=on,12 CPUs)
    Scanning
    Updating archive <archive>
          
    System error:
    Operation not permitted
    

    Previously I had fixed this error by applying a sensible file descriptor limit (via '/etc/security/limits.conf') from 1024 to 99999, however this has now started to happen again.

    I upgraded to v9.13 via Mefisto's PPA, unfortunately the error still occurs.

    I have confirmed that the problem still happens when sudo'd, so I assume it isn't a typical permissions issue. Any ideas on how I can debug this?

    Thanks for your help.

     
  • Igor Pavlov
    Igor Pavlov
    2011-01-22

    -m5=lzma2
    is bad switch.
    Use
    -m0=lzma2 instead.
    And remove old  (BAD) version of archive before that command.
    2) Use only latest 7-Zip 9.13

     
  • Omega Weapon
    Omega Weapon
    2011-02-02

    Shit, sorry I didn't reply when you posted this - I was relying on SourceForge to email me and it didn't.

    Thankyou - I will update the script and test this shortly.

    -m0=lzma2 instead.

    I reread the documentation - I had assumed the '{N}' bit was comparable to '-mx=N' - what does it mean?

    I guess since Normal compression (5) is default, I should leave it at '-m=LZMA2'.

     
  • Igor Pavlov
    Igor Pavlov
    2011-02-02

    omega_weapon:
    reread the documentation again and think about it more.

     
  • Omega Weapon
    Omega Weapon
    2011-02-02

    Right, I see what has happened here - in the '-m switch' documentation I went to the 7z section, then followed the '{N}={MethodID} … ' link straight to that section and read it. The '{N}' is documented a few items above this section.

    I understand 0 now - impressively involved tool you've made here ;)

     
  • Omega Weapon
    Omega Weapon
    2011-02-03

    Thanks for your help - I've just had a series of successful archive updates overnight :)

     
  • James Cuzella
    James Cuzella
    2013-07-28

    So what was the solution?

    I got this error, and the google result for this thread is essentially useless as it just points me to RTFM. The error message "System error: Operation not permitted" isn't very helpful if this problem is caused by an invalid command line argument.

    Operation not permitted makes me think that this is a filesystem permissions issue, or an issue with a permissions issue related to pam_limits resource limit (The OP mentions /etc/security/limits.conf).

    I don't mean sound like I'm complaining, I'm just trying to quickly compress some old files and am rather irked by the time-consuming learning curve and due to a lack of time that I had allocated to this task.

    7zip is an amazingly powerful tool, with very configurable and complex command line options, but a rather steep learning curve. (I'd compare it to ffmpeg or mencoder in it's sheer number of options and complexity of use to a newcomer). IMHO, the documentation is rather good, but could use some improvement. I'd recommend newcomers start with the peazip tool, as it provides a GUI to generate a command line for 7z and to see what options to use. However, I did precisely that and copied the command line (albeit from another OS platform) to use on linux, yet it did not work and gave me this apparent permissions error with a dead-end thread with no solution.

    Compounding matters, this tool (much like ffmpeg or mencoder) has the potential to do a lot of time consuming processing, making it rather frustrating for a user who carefully crafts a command line, leaves it running overnight, and then comes back to an error that isn't very helpful, especially for those with a time budget. @OP: Please post a solution, it will greatly help the community.

    </rant>

    Problem

    I run a p7zip command to compress files, and it only fails when I run it on a set of very large files. Running it on a smaller set of files works fine!

    Here's the command I ran:

    7z a -t7z -m0=LZMA -mmt=2 -mx9 -md=64m -mfb=64 -ms=4g "-w${WORKING_DIR}" ${TARGET_DIR}/${MY_FILENAME}.7z "${DIR_TO_COMPRESS}"
    

    Which gave me:

    p7zip Version 9.20 (locale=en_US.UTF-8,Utf16=on,HugeFiles=on,2 CPUs)
    Scanning
    
    Creating archive /media/my_drive/my_dir.7z
    
    Compressing  my_dir/my_file-00.rar
    Compressing  my_dir/my_file-01.rar
    Compressing  my_dir/my_file-02.rar
    Compressing  my_dir/my_file-03.rar
    Compressing  my_dir/my_file-04.rar
    Compressing  my_dir/my_file-05.rar
    Compressing  my_dir/my_file-06.rar
    Compressing  my_dir/my_file-07.rar
    Compressing  my_dir/my_file-08.rar
    Compressing  my_dir/my_file-09.rar
    Compressing  my_dir/my_file-10.rar
    Compressing  my_dir/my_file-11.rar
    Compressing  my_dir/my_file-12.rar
    Compressing  my_dir/my_file-13.rar
    Compressing  my_dir/my_file-14.rar
    Compressing  my_dir/my_file-15.rar
    Compressing  my_dir/my_file-16.rar
    Compressing  my_dir/my_file-17.rar
    
    System error:
    Operation not permitted
    

    (There were 32 rar files in this example)

    File permissions on both source, destination, and working dir look ok for the user running this command, yet I get Operation not permitted. When I run the command on a small set of test files, it works fine \(o_O)/

    # Create set of test files with 2048 bytes of random base64 text data:
    cd ${HOME} && mkdir my_dir && for n in $(seq -w 1 1 32); do openssl rand -base64 2048 > "my_dir/my_file-${n}.log"; done
    
    # Both of these work fine!
    7z a -t7z -m0=LZMA -mmt=2 -mx9 -md=64m -mfb=64 -ms=on -w${HOME} /media/my_drive/test.7z "${HOME}/my_dir"
    7z a -t7z -m0=LZMA2 -mmt=2 -mx9 -md=64m -mfb=64 -ms=on -w${HOME} /media/my_drive/test.7z "${HOME}/my_dir"
    

    Result:

    7-Zip [64] 9.20  Copyright (c) 1999-2010 Igor Pavlov  2010-11-18
    p7zip Version 9.20 (locale=en_US.UTF-8,Utf16=on,HugeFiles=on,2 CPUs)
    Scanning
    
    Creating archive /media/my_drive/test.7z
    
    Compressing  my_dir/my_file-01.log
    Compressing  my_dir/my_file-02.log
    Compressing  my_dir/my_file-03.log
    Compressing  my_dir/my_file-04.log
    Compressing  my_dir/my_file-05.log
    Compressing  my_dir/my_file-06.log
    Compressing  my_dir/my_file-07.log
    Compressing  my_dir/my_file-08.log
    Compressing  my_dir/my_file-09.log
    Compressing  my_dir/my_file-10.log
    Compressing  my_dir/my_file-11.log
    Compressing  my_dir/my_file-12.log
    Compressing  my_dir/my_file-13.log
    Compressing  my_dir/my_file-14.log
    Compressing  my_dir/my_file-15.log
    Compressing  my_dir/my_file-16.log
    Compressing  my_dir/my_file-17.log
    Compressing  my_dir/my_file-18.log
    Compressing  my_dir/my_file-19.log
    Compressing  my_dir/my_file-20.log
    Compressing  my_dir/my_file-21.log
    Compressing  my_dir/my_file-22.log
    Compressing  my_dir/my_file-23.log
    Compressing  my_dir/my_file-24.log
    Compressing  my_dir/my_file-25.log
    Compressing  my_dir/my_file-26.log
    Compressing  my_dir/my_file-27.log
    Compressing  my_dir/my_file-28.log
    Compressing  my_dir/my_file-29.log
    Compressing  my_dir/my_file-30.log
    Compressing  my_dir/my_file-31.log
    Compressing  my_dir/my_file-32.log
    
    Everything is Ok
    

    Other than running an strace, I don't see a way to find out what the real problem is with the large files. Help is always much appreciated!

    Thanks!

     
    Last edit: James Cuzella 2013-07-28
  • James Cuzella
    James Cuzella
    2013-08-15

    After running the 7z process again with strace, I was able to find out what the actual problem is!

    Debugging With Strace

    In order to troubleshoot the problem, I ran the command again using strace:

    $ strace -o /tmp/7zip_strace.log 7z a -t7z -m0=LZMA -mmt=2 -mx9 -md=64m -mfb=64 -ms=on -w${HOME} /media/my_drive/my_dir.7z "${HOME}/my_dir"
    
    7-Zip [64] 9.20  Copyright (c) 1999-2010 Igor Pavlov  2010-11-18
    p7zip Version 9.20 (locale=en_US.UTF-8,Utf16=on,HugeFiles=on,2 CPUs)
    Scanning
    
    Creating archive /media/my_drive/my_dir.7z
    
    Compressing  my_dir/my_file-00.rar
    Compressing  my_dir/my_file-01.rar
    Compressing  my_dir/my_file-02.rar
    Compressing  my_dir/my_file-03.rar
    Compressing  my_dir/my_file-04.rar
    Compressing  my_dir/my_file-05.rar
    Compressing  my_dir/my_file-06.rar
    Compressing  my_dir/my_file-07.rar
    Compressing  my_dir/my_file-08.rar
    Compressing  my_dir/my_file-09.rar
    Compressing  my_dir/my_file-10.rar
    Compressing  my_dir/my_file-11.rar
    Compressing  my_dir/my_file-12.rar
    Compressing  my_dir/my_file-13.rar
    Compressing  my_dir/my_file-14.rar
    Compressing  my_dir/my_file-15.rar
    Compressing  my_dir/my_file-16.rar
    Compressing  my_dir/my_file-17.rar
    Compressing  my_dir/my_file-18.rar
    
    System error:
    E_FAIL
    

    The error was rather unhelpful this time, just indicating some sort of failure or system error of some kind. At this point it wasn't clear to me why the compression process failed.

    Next, I looked at the strace output:

    Strace Output

    write(1, "\10\10\10\10\10\10   55%", 12) = 12
    futex(0x7fe1e3661224, FUTEX_CMP_REQUEUE_PRIVATE, 1, 2147483647, 0x7fe1e36611f8, 23756) = 1
    futex(0x7fe1e36611f8, FUTEX_WAKE_PRIVATE, 1) = 1
    write(3, "\374\341\324\376\r\300\370R\204\303T\321\307\36E\322\316%\372\352\341T?H\226\237\320s\372\352\332\313"..., 65536) = 30944
    write(3, "<\177$?\275{ge\2109$\356\362O0\31\1\7\343z\3461\243\325Q\205\202\24iz\331\350"..., 34592) = 8192
    write(3, "\212\253\1Oc\243\254\250\235p\240\35\365\36x\344(B\v\230G&\4\377\241gPB\325sNQ"..., 26400) = 4096
    write(3, "\2042Pg\35H\32\250\230$\275\10d\317\2211)M\355\302?\371\3\361|\312\207`\333eP\31"..., 22304) = 4096
    write(3, "Q\356\335-\354\375\310t'\246H\312w3CW\25R<XQ}\23\112z]\323\234{/\35\271"..., 18208) = 4096
    write(3, "\333\34JR\373U\301\321\337\32\310\351\\\364\201A\306\34\264\360$+(\342\361|\364<\251T`'"..., 14112) = 4096
    write(3, "q\242\246\211P\355\313\271\237K\237\270\373WL,\5\305\263\10o\2Di\312!p\313\243\316\362>"..., 10016) = 4096
    write(3, "w_Q\35%\341KU\321\309Z\21\232&\217\313\2\310|\t\337u`t\355\0340)X\243\367i"..., 5920) = -1 ENOSPC (No space left on device)
    futex(0x7fe1e3661224, FUTEX_CMP_REQUEUE_PRIVATE, 1, 2147483647, 0x7fe1e36611f8, 23758) = 1
    futex(0x7fe1e36611f8, FUTEX_WAKE_PRIVATE, 1) = 1
    futex(0x7fe1e36611bc, FUTEX_WAIT_PRIVATE, 7, NULL) = 0
    futex(0x7fe1e3661190, FUTEX_WAKE_PRIVATE, 1) = 0
    close(4)                                = 0
    futex(0x7fe1e3661414, FUTEX_CMP_REQUEUE_PRIVATE, 1, 2147483647, 0x7fe1e36613e8, 10) = 1
    futex(0x7fe1e36613e8, FUTEX_WAKE_PRIVATE, 1) = 1
    futex(0x7fe1e36610ec, FUTEX_CMP_REQUEUE_PRIVATE, 1, 2147483647, 0x7fe1e36610c0, 10) = 1
    futex(0x7fe1b87bf9d0, FUTEX_WAIT, 27273, NULL) = -1 EAGAIN (Resource temporarily unavailable)
    munmap(0x7fe1e3220000, 4460544)         = 0
    munmap(0x7fe1b8fc1000, 604250112)       = 0
    munmap(0x7fe1dd003000, 102879232)       = 0
    munmap(0x7fe1e3661000, 294912)          = 0
    close(3)                                = 0
    unlink("/home/jcuzella/my_dir.7z.tmp") = 0
    futex(0x7fe1e43291a4, FUTEX_WAKE_PRIVATE, 2147483647) = 0
    munmap(0x7fe1e36a9000, 3864224)         = 0
    write(1, "\10\10\10\10\10\10      \10\10\10\10\10\10\n", 19) = 19
    write(1, "\n", 1)                       = 1
    write(1, "System error:\n", 14)         = 14
    write(1, "E_FAIL                \n", 23) = 23
    rt_sigaction(SIGINT, {SIG_DFL, [INT], SA_RESTORER|SA_RESTART, 0x7fe1e3d8b4a0}, {0x4038ed, [INT], SA_RESTORER|SA_RESTART, 0x7fe1e3d8b4a0}, 8) = 0
    rt_sigaction(SIGTERM, {SIG_DFL, [TERM], SA_RESTORER|SA_RESTART, 0x7fe1e3d8b4a0}, {0x4038ed, [TERM], SA_RESTORER|SA_RESTART, 0x7fe1e3d8b4a0}, 8) = 0
    exit_group(2)                           = ?
    

    So from looking at this, I can see that 7z writes to a temporary file in it's working directory (And consulting the documentation I see this defaults to the same device that the uncompressed files resided. Though in my case I specified it explicitly to my home directory with -w${HOME}).

    The reason for the failure in my case was: the working directory was on a device that was close to full capacity. As I could see in the strace output, there was an ENOSPC (No space left on device) error being returned during an attempt to write to the drive: write(3, "w_Q\35%\341KU\321\309Z\21\232&\217\313\2\310|\t\337ut\355\0340)X\243\367i"..., 5920) = -1 ENOSPC (No space left on device)`

    However, the last failure returned by 7z was an E_FAIL System error. The output from 7z did not clearly indicate that the device was full, and it wasn't immediately clear to me that p7zip was going to write to a temporary file in the working dir. This misleading output made it a bit difficult (though not impossible ;-D) to figure out what the real problem was. These factors exacerbated the problem especially since my use case was to compress a set of large files in order to free space on a drive.

    To solve this problem I changed the working directory to the target drive I was creating the compressed file on:

    7z a -t7z -m0=LZMA -mmt=2 -mx9 -md=64m -mfb=64 -ms=on -w/media/my_drive/my_dir /media/my_drive/my_dir.7z "${HOME}/my_dir"
    
    Edit:

    So after getting & googling the E_FAIL (rather than the other mysterious System error: Operation not permitted)... I found this open Debian bug report. Seems I'm not the only one; the root cause was found independently by others.

     
    Last edit: James Cuzella 2013-08-15