mainstoreBackup - Support: sr #110611, checkDevicesBS is ignore and write...

 
 

sr #110611: checkDevicesBS is ignore and write allway 65536 in Debian 11

Submitter:  Jörg <joersch>
Submitted:  Tue 15 Feb 2022 05:15:27 PM UTC
   
 
Category:  None Priority:  5 - Normal
Severity:  3 - Normal Status:  None
Privacy:  Public Assigned to:  None
Open/Closed:  Open Operating System:  GNU/Linux
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Tue 10 May 2022 09:42:03 PM UTC, comment #17: 


>
> what is wrong? Thank for help.
> Jörg


issue solved in storeBackup version 3.5.2

Heinz-Josef Claes <hjclaes>
Group administrator
Sat 19 Feb 2022 03:37:59 PM UTC, comment #16: 

i try initialize the $n variable at some lines.
all i get the same uninitialized value error.
now i initialize it direct before length($buffer)

4031 $fileIn->sysread($buffer, $blockSize);
4032 my $n = 0;
4033 $n = length($buffer);
4043 print "-2b- n = $n\n";

console:
-2a- blockSize = 10485760
Use of uninitialized value $n in concatenation (.) or string at /opt/storeBackup/bin/storeBackup.pl line 4034.
-2b- n =

comment out the line 4033, the output shows 0 for $n
it looks like the length($buffer); return the uninitialized value.

Jörg <joersch>
Sat 19 Feb 2022 02:25:09 PM UTC, comment #15: 

$n is defined and set to  zero several lines before:
my ($statSizeOrig, $statSizeNew, $statNoForksCP, $statNoForksCompress,
$statNoLateLinks, $n) = (0, 0, 0, 0, 0, 0)

Strange.

maybe you can try (add $n = 0):

while ($jobToDo > 0 or $parForkToDo > 0)
{
   $n = 0;

or


while ($jobToDo > 0 or $parForkToDo > 0)
{
   my $n = 0;


or


Heinz-Josef Claes <hjclaes>
Group administrator
Sat 19 Feb 2022 01:58:12 PM UTC, comment #14: 

i get a uninitialized value error with this code:

-13-
-14-
-18-
-23-
direct = <0>
--- jobToDo=1 -- parForkToDo=0 ---
jobToDo = <1>, freeEntries = <5>
-2a- blockSize = 10485760
Use of uninitialized value $n in concatenation (.) or string at /opt/storeBackup/bin/storeBackup.pl line 4033.
-2b- n =
setting allMD5
allMD5 = d41d8cd98f00b204e9800998ecf8427e, statSourceSize = 0, statStbuSize = 0
statNoForksCP = 0, statNoForksCompress = 1
statNoBlocks = 0, statNoLateLinks = 0
noWarnings = 0, noErrors = 0
noBlockComprCheckCompr = 0, noBlockComprCheckCp = 0
-25-
-14-
-18-
-23-
-25-


line 4033 is the logline
4029 if ($fileIn)
4030 {
4031 $fileIn->sysread($buffer, $blockSize);
4032 $n = length($buffer);
4033 print "-2b- n = $n\n";

Jörg <joersch>
Sat 19 Feb 2022 12:30:41 PM UTC, comment #13: 

I think about the following:

1. Try with a blocksize of 65536 instead of 10 Million in storeBackup file storeBackup.pl on the command line or in the configration file where you had the fault.
If this works, replace:

    if ($fileIn)
    {
$n = $fileIn->sysread($buffer, $blockSize);
print "-2b- n = $n\n";
    }
    else
    {
$n = sysread(FILE, $buffer, $blockSize);
print "-2c- n = $n\n";
    }


replace with


    if ($fileIn)
    {
$fileIn->sysread($buffer, $blockSize);
$n = length($buffer);
print "-2b- n = $n\n";
    }
    else
    {
sysread(FILE, $buffer, $blockSize);
$n = length($buffer);
print "-2c- n = $n\n";
    }!?!
I didn't test it - so hopefully it fixes or avoids the bug?!


Heinz-Josef Claes <hjclaes>
Group administrator
Sat 19 Feb 2022 11:57:09 AM UTC, comment #12: 

i dont know what exacly you mean with "tried with a blocksize of 65536".
lower blockzize are posible, and the maximum is 65536, and grather blocksize is limit on 65536.


root@pmg:/opt/storeBackup/lib# ./test-forkReadPipe.pl /bin/busybox /tmp/bb '32768'
---------------------copying file------
blockSize = <32768> ==> <32768>
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=32768 len=32768
bs=32768        n=27352 len=27352

root@pmg:/opt/storeBackup/lib# ./test-forkReadPipe.pl /bin/busybox /tmp/bb '65536'
---------------------copying file------
blockSize = <65536> ==> <65536>
bs=65536        n=65536 len=65536
bs=65536        n=65536 len=65536
bs=65536        n=65536 len=65536
bs=65536        n=65536 len=65536
bs=65536        n=65536 len=65536
bs=65536        n=65536 len=65536
bs=65536        n=65536 len=65536
bs=65536        n=65536 len=65536
bs=65536        n=65536 len=65536
bs=65536        n=65536 len=65536
bs=65536        n=60120 len=60120
root@pmg:/opt/storeBackup/lib# ./test-forkReadPipe.pl /bin/busybox /tmp/bb '131072'
---------------------copying file------
blockSize = <131072> ==> <131072>
bs=131072       n=65536 len=65536
bs=131072       n=65536 len=65536
bs=131072       n=65536 len=65536
bs=131072       n=65536 len=65536
bs=131072       n=65536 len=65536
bs=131072       n=65536 len=65536
bs=131072       n=65536 len=65536
bs=131072       n=65536 len=65536
bs=131072       n=65536 len=65536
bs=131072       n=65536 len=65536
bs=131072       n=60120 len=60120

Jörg <joersch>
Sat 19 Feb 2022 11:38:49 AM UTC, comment #11: 

Have you ever tried with a blocksize of 65536?

Heinz-Josef Claes <hjclaes>
Group administrator
Sat 19 Feb 2022 11:02:33 AM UTC, comment #10: 

Hi Heinz-Josef, thank you so much for your help.
your first script i name it: test-forkReadPipe.pl
your second script with inline copy function i name it: test-forkReadPipe2.pl

the console output is:
root@pmg:/opt/storeBackup/lib# ./test-forkReadPipe.pl /bin/busybox /tmp/bb '1024**2'
---------------------copying file------
blockSize = <1024**2> ==> <1048576>
bs=1048576      n=65536 len=65536
bs=1048576      n=65536 len=65536
bs=1048576      n=65536 len=65536
bs=1048576      n=65536 len=65536
bs=1048576      n=65536 len=65536
bs=1048576      n=65536 len=65536
bs=1048576      n=65536 len=65536
bs=1048576      n=65536 len=65536
bs=1048576      n=65536 len=65536
bs=1048576      n=65536 len=65536
bs=1048576      n=60120 len=60120
root@pmg:/opt/storeBackup/lib# diff /bin/busybox /tmp/bb
root@pmg:/opt/storeBackup/lib#

root@pmg:/tmp# ls -l
total 9996
-rwx------ 1 root root  715480 Feb 19 11:42 bb


root@pmg:/opt/storeBackup/lib# ./test-forkReadPipe2.pl /bin/busybox /tmp/bb '1024**2'
---------------------copying file------
blockSize = <1024**2> ==> <1048576>
file </bin/busybox> has size 715480
bs=1048576      n=715480        len=715480
root@pmg:/opt/storeBackup/lib# diff /bin/busybox /tmp/bb
root@pmg:/opt/storeBackup/lib#
root@pmg:/tmp# ls -l
total 10696
-rw-r--r-- 1 root root  715480 Feb 19 11:44 bb


And the same, i do it in my production system with debian 10:

root@xxx /opt/storeBackup/lib # ./test-forkReadPipe.pl /bin/busybox /tmp/bb '1024**2'
---------------------copying file------
blockSize = <1024**2> ==> <1048576>
bs=1048576      n=131072        len=131072
bs=1048576      n=131072        len=131072
bs=1048576      n=131072        len=131072
bs=1048576      n=131072        len=131072
bs=1048576      n=131072        len=131072
bs=1048576      n=51928 len=51928
root@xxx /opt/storeBackup/lib # diff /bin/busybox /tmp/bb


yes, the first one write blocks with 65536 bytes, the second writes it in one block.
But what can we do?

Jörg

Jörg <joersch>
Sat 19 Feb 2022 09:43:24 AM UTC, comment #9: 

To isolate the problem, I wrote the following little script:


#! /usr/bin/env perl

use Fcntl qw(O_RDWR O_CREAT);
use Fcntl ':mode';
use POSIX;


unshift @INC, '.';

use strict;


require './forkProc.pl';


my $prLog = printLog->new('-kind' => ['E:Error',
      'W:Warning'
      ],
  '-multiprint' => 'yes',
  '-file' => '/tmp/log');

print "---------------------copying file------\n";
if (@ARGV != 3)
{
    print "usage: $0 sourceFile targetFile blockSize\n";
    exit 0;
}
my $blockSize = $ARGV[2];
chomp $blockSize;
my $bs = eval "$blockSize";
my $sourceFile = $ARGV[0];
my $targetFile = $ARGV[1];

print "blockSize = <$blockSize> ==> <$bs>\n";

my $ptf = pipeFromFork->new('-exec' => 'cat',
    '-param' => [],
    '-stdin' => $sourceFile,
#     '-stderr' => '/tmp/STDERR',
    '-outRandom' => '/tmp/pipeToFork-',
    '-prLog' => $prLog);

local *OUT;
unless (sysopen(OUT, $targetFile, O_CREAT|O_WRONLY, 0700))
{
    die "cannot open <$targetFile>";
}
my ($buffer, $n);
while ($n = $ptf->sysread(\$buffer, $bs))
{
    print "bs=$bs\tn=$n\tlen=", length($buffer), "\n";
    unless (syswrite(OUT, $buffer))
    {
die "cannot write to <$targetFile>";
    }
}
    my $out = $ptf->getSTDERR();
if (@$out)
{
    print "STDERR:\n";
    print "@$out\n";
    exit 1;
}

$ptf->close();    # close also cleans stderr
close(OUT);
exit 0;

To start it, write a copy of it into storeBackups "lib" directory and cd into the lib directory with the name  test-forkReadPipe.pl  Then start:
./test-forkReadPipe.pl /bin/busybox /tmp/bb '1024**2'

This will copy file busybox to /tmp/bb with a blocksize of 1024^1´2  (= 1Mbyte). I have other perl versions than you installed, but the output on   my boxes depends on the perl version and / or the "use Fcntl" stuff. Please test with your versions.
And also check the copy:
diff /bin/busybox /tmp/bb

This script includes the forkProc.p code from storeBackup/lib. If we look there, we find
# ATTENTION: if prLog write to STDOUT, messages are also piped!
package pipeFromFork

and the below method
sub sysread

which is nothing else than a call of the build in function sysread:
sub sysread
{
    my ($self, $buffer, $blockSize) = @_;

    return sysread $self->{'fd'}, $$buffer, $blockSize;
}

Now, to see what the sysread function is doing I wrote the following script to copy a file (the same way as with the script before).


#! /usr/bin/perl

use Fcntl qw(O_RDWR O_CREAT);
use Fcntl ':mode';
use POSIX;


unshift @INC, '.';

use strict;


require './forkProc.pl';


my $prLog = printLog->new('-kind' => ['E:Error',
      'W:Warning'
      ],
  '-multiprint' => 'yes',
  '-file' => '/tmp/log');

print "---------------------copying file------\n";
if (@ARGV != 3)
{
    print "usage: $0 sourceFile targetFile blockSize\n";
    exit 0;
}
my $blockSize = $ARGV[2];
chomp $blockSize;
my $bs = eval "$blockSize";
my $sourceFile = $ARGV[0];
my $targetFile = $ARGV[1];

print "blockSize = <$blockSize> ==> <$bs>\n";

&::_copyFile($sourceFile, $targetFile, $prLog, $bs);

exit 0;

# copies a file
# returns:
#          1: ok
#          0: error
############################################################
sub _copyFile
{
    my $source = shift;
    my $target = shift;
    my $prLog = shift;
    my $bs = shift;

    local *SOURCE;
    local *TARGET;
    unless (sysopen(SOURCE, $source, O_RDONLY))
    {
$prLog->print('-kind' => 'E',
      '-str' => ["cannot open <$source> for reading"]);
return 0;
    }
    my $sizeSource = (stat($source))[7];
    print "file <$source> has size $sizeSource\n";
    unless (sysopen(TARGET, $target, O_CREAT | O_WRONLY))
    {
$prLog->print('-kind' => 'E',
      '-str' => ["cannot create <$target> for writing"]);
return 0;
    }
    my $buffer;
    my $n;
    while ($n = sysread(SOURCE, $buffer, $bs))
    {
print "bs=$bs\tn=$n\tlen=", length($buffer), "\n";
unless (syswrite(TARGET, $buffer))
{
    $prLog->print('-kind' => 'E',
  '-str' => [$!]);
    return 0;
}
    }

    close(TARGET);
    close(SOURCE);

    return 1;
}


Jörg, what are your results?

Heinz-Josef Claes <hjclaes>
Group administrator
Fri 18 Feb 2022 06:20:58 PM UTC, comment #8: 

Sorry, it will be tomorrow

Heinz-Josef Claes <hjclaes>
Group administrator
Fri 18 Feb 2022 08:51:12 AM UTC, comment #7: 

I'll be back with same news in the afternoon.

Heinz-Josef Claes <hjclaes>
Group administrator
Wed 16 Feb 2022 08:52:41 PM UTC, comment #6: 

Oh I thought the slash was a mistake and I removed it. Sorry, I'm not the Perl guru. :-(
I write it back and the uninitialized value error is gone. But the main problem still remains. The console output is:
--- jobToDo=1 -- parForkToDo=0 ---
jobToDo = <1>, freeEntries = <5>
-2a- blockSize = 10485760
-2b- n = 65536
-2- 0000000001 -> digest = 7024fa1dc8262a290567407c3826d89b (65536 bytes)
--- jobToDo=1 -- parForkToDo=1 ---
jobToDo = <1>, freeEntries = <4>
-2a- blockSize = 10485760
-2b- n = 65536
-2- 0000000002 -> digest = 84200b2328cad0ef044b91e570eddc0b (65536 bytes)
--- jobToDo=1 -- parForkToDo=2 ---
jobToDo = <1>, freeEntries = <3>
-2a- blockSize = 10485760
-2b- n = 65536
-2- 0000000003 -> digest = f91c36edbc635df95876277d787a4cf0 (65536 bytes)


Jörg <joersch>
Wed 16 Feb 2022 08:25:46 PM UTC, comment #5: 

In your code below, you have:

    if ($fileIn)
    {
$n = $fileIn->sysread($buffer, $blockSize);
print "-2b- n = $n\n";
    }
    else
    {
$n = sysread(FILE, $buffer, $blockSize);
print "-2c- n = $n\n";
    }

----------------------------------------------------
I had a look in 3.4.1 and in 3.5.1 on my server and it's unchanged:
    if ($fileIn)
    {
$n = $fileIn->sysread(\$buffer, $blockSize);
    }
    else
    {
$n = sysread(FILE, $buffer, $blockSize);
    }

Is this a cut and past error? The backslash is missing in your copy.

Heinz-Josef Claes <hjclaes>
Group administrator
Wed 16 Feb 2022 06:20:18 PM UTC, comment #4: 

i have two hosts (Proxmox/Debian) on that i need the store backup. One of these i upgrate it to Debian 11, the other one is now Debian 10.

before i migrate the first one, storeBackup 3.4.1 was installed.
Then i have this problem and i upgrade the storeBackup to 3.5.1.
I get it from:
http://download.savannah.nongnu.org/releases/storebackup/storeBackup-3.5.1.tar.bz2

currently i have a test-vm on this i can testing.

thks


Jörg <joersch>
Wed 16 Feb 2022 05:47:15 PM UTC, comment #3: 

Let's collect some information:

debain 10 perl: 5.28.1-6+deb10u1
debian 11 perl: 5.32.1-4+deb11u2

So you use the same or different  storeBackup versions? (storeBackup.pl -V).

Do you use the Debian version or the tar files from savanah?

Heinz-Josef Claes <hjclaes>
Group administrator
Wed 16 Feb 2022 01:23:14 PM UTC, comment #2: 

Hi Heinz Josef,
thanks for for answer. I tell you what is happen. I upgrade my proxmox host 6.4 (Debian 10) to Proxmox 7 (Debian 11).
The backuptime for an LV-backup with (blockzise 10M) is 3 times slower as in Debian 10 system before. Then i investigate them.
In a 10GB Backup source series, the ammount of files in Debian 10 is 1024. This is correct. 10MB*1024=10GB
In the new Debian 11 based system, is the ammount of bz2 files is 163840. 65536 byte * 163840 files = 10GB
I look in the source and found the line i describe in my first post before.
I log some more debug information and found the sysread command reads only maximal 65536 bytes into the buffer. (Lower blocksize is posible, higher not).
This buffer with the 65536 bytes is write into the bz2 file and then the result is so much more files.

my additional logline is:

print "jobToDo = <$jobToDo>, freeEntries = <", $paralFork->getNoFreeEntries(), ">\n";
if ($jobToDo > 0 and $paralFork->getNoFreeEntries() > 0)
{
print "-2a- blockSize = $blockSize\n";

    if ($fileIn)
    {
$n = $fileIn->sysread($buffer, $blockSize);
print "-2b- n = $n\n";
    }
    else
    {
$n = sysread(FILE, $buffer, $blockSize);
print "-2c- n = $n\n";
    }


line 4047...
my $digest = md5_hex($buffer);
$md5All->add($buffer);


The result is:
--- jobToDo=1 -- parForkToDo=0 ---
jobToDo = <1>, freeEntries = <5>
-2a- blockSize = 10485760
-2b- n = 65536
Use of uninitialized value in subroutine entry at /opt/storeBackup/bin/storeBackup.pl line 4047.
Use of uninitialized value in subroutine entry at /opt/storeBackup/bin/storeBackup.pl line 4048.
-2- 0000000001 -> digest = d41d8cd98f00b204e9800998ecf8427e (65536 bytes)



I see the $blockSize is 10485760 the result is 65536 and the buffer is uninitialized, (see line 4047)
The digest in all is the same (d41d8cd98f00b204e9800998ecf8427e)
(my linenumber differs of yours, i have some more lines included)

i try to use perlbrew and switch zu perl version 5.28.1, as the same debian 10 use, but it dont solve the problem. It is the same.

can you see what is happen? What can i do to find the solution?

beste regards
Jörg

Jörg <joersch>
Wed 16 Feb 2022 08:04:34 AM UTC, comment #1: 

Hi,

Is the value in $blockSize different from that in $n (except possibly on the last pass of the loop)?

Regards, Heinz Josef

Heinz-Josef Claes <hjclaes>
Group administrator
Tue 15 Feb 2022 05:15:27 PM UTC, original submission:  

Hi,
since debian 11 the backupscript doesnt work correct. I set the paramater --checkDevicesBS0 10M
And the script writes only 65536 bytes to the block.
I search a little bit and i found in storeBackup.pl version 3.5.1
line 4027: $n = $fileIn->sysread(\$buffer, $blockSize);

this line reads in debian 10 correct $n = 10485760 bytes
but in debian 11 reads $n = 65536 bytes.

debain 10 perl: 5.28.1-6+deb10u1
debian 11 perl: 5.32.1-4+deb11u2

what is wrong? Thank for help.
Jörg

Jörg <joersch>

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

No files currently attached

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by hjclaes (Posted a comment)
  • -email is unavailable- added by joersch (Submitted the item)
  •  

    There are 0 votes so far. Votes easily highlight which items people would like to see resolved in priority, independently of the priority of the item set by tracker managers.

    Only logged-in users can vote.

     

    No changes have been made to this item

    Back to the top

    Powered by Savane 3.13-758e.
    Corresponding source code