Re: Out of memory: Killed process 707, UID 0, (amrecover). / Amanda-3.4.4

2017-06-05 Thread Bernhard Erdmann 

Well done, Jean-Louis!

Many thanks for the very quick patch. This patch solved my problem.

Now for the same recover procedure as before (same backup date, same 
directory to recover) the largest Amanda process (amidxtaped) did not 
grow beyond 233 MB virtual image size.



Am 05.06.17 um 18:00 schrieb Jean-Louis Martineau:

Bernhard,

Thanks for reporting this new issue.
I committed the attached patch

Jean-Louis

Re: Out of memory: Killed process 707, UID 0, (amrecover). / Amanda-3.4.4

2017-06-05 Thread Jean-Louis Martineau 

Bernhard,

Thanks for reporting this new issue.
I committed the attached patch

Jean-Louis

On 04/06/17 07:45 AM, Bernhard Erdmann wrote:

Hello,

after an upgrade to Amanda-3.4.4, I discovered that amrecover eats too 
much memory. Trying to recover a single directory from a huge GNU tar 
image (900 GB), amrecover gets killed because of memory constraints.


System is running CentOS 5.11 x86_64 using 8 GB RAM and 24 GB Swap 
available for several years using Amanda to backup to a 90 slot vTape 
iSCSI-attached.


Downgrade to Amanda-3.4.3 helped. The same recover procedure (same 
backup date, same directory to recover) works well using this version.


Last lines of amidxtaped.20170603173611.debug (timezone is CEST (GMT+2)):

Sat Jun 03 17:13:55.770129000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1699:info:490 
198642624 kb
Sat Jun 03 17:14:20.07357 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1699:info:490 
198645984 kb
Sat Jun 03 17:15:14.519889000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1699:info:490 
198646752 kb
Sat Jun 03 17:21:39.862161000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1699:info:490 
198647680 kb
Sat Jun 03 17:21:40.388673000 2017: pid 720: thd-0x20d85690: 
amidxtaped: xfer_cancel_with_error: Error writing to fd 8: Broken pipe
Sat Jun 03 17:21:40.388729000 2017: pid 720: thd-0x20d85690: 
amidxtaped: xfer_queue_message: MSG:  version=0>
Sat Jun 03 17:21:40.38890 2017: pid 720: thd-0x20d85690: 
amidxtaped: xfer_queue_message: MSG:  version=0>
Sat Jun 03 17:21:40.845451000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: Cancelling  -> )>
Sat Jun 03 17:21:40.922716000 2017: pid 720: thd-0x20d85690: 
amidxtaped: sending XMSG_CRC message 0x20d83010
Sat Jun 03 17:21:40.922777000 2017: pid 720: thd-0x20d85690: 
amidxtaped: pull_and_write CRC: 1b42fe0e  size 203415191552
Sat Jun 03 17:21:40.922793000 2017: pid 720: thd-0x20d85690: 
amidxtaped: xfer_queue_message: MSG:  version=0>
Sat Jun 03 17:21:40.922818000 2017: pid 720: thd-0x20d85690: 
amidxtaped: xfer_queue_message: MSG:  version=0>
Sat Jun 03 17:21:41.313146000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: dest_crc: 1b42fe0e:203415191552
Sat Jun 03 17:21:41.674875000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1893:info:4900012 
198647680 kb
Sat Jun 03 17:21:42.462789000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1921:error:4900055 Error 
writing to fd 8: Broken pipe
Sat Jun 03 17:21:42.958237000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:2138:error:4900068 Error 
writing to fd 8: Broken pipe
Sat Jun 03 17:21:43.406247000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: user_message feedback: Error writing to fd 8: Broken pipe
Sat Jun 03 17:21:44.597549000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: CTL >> MESSAGE Error writing to fd 8: Broken pipe
Sat Jun 03 17:21:46.940293000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: exiting with 1
Sat Jun 03 17:21:46.990525000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_utime   : 352
Sat Jun 03 17:21:46.990566000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_stime   : 463
Sat Jun 03 17:21:46.990576000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_maxrss  : 38984
Sat Jun 03 17:21:46.990595000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_ixrss   : 0
Sat Jun 03 17:21:46.990604000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_idrss   : 0
Sat Jun 03 17:21:46.990611000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_isrss   : 0
Sat Jun 03 17:21:46.990619000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_minflt  : 13614
Sat Jun 03 17:21:46.990627000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_majflt  : 2372
Sat Jun 03 17:21:46.990634000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_nswap   : 0
Sat Jun 03 17:21:46.990641000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_inblock : 0
Sat Jun 03 17:21:46.990649000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_oublock : 0
Sat Jun 03 17:21:46.990656000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_msgsnd  : 0
Sat Jun 03 17:21:46.990663000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_msgrcv  : 0
Sat Jun 03 17:21:46.99067 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_nsignals: 0
Sat Jun 03 17:21:46.990678000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_nvcsw   : 1477628
Sat Jun 03 17:21:46.990685000 2017: pid 720: thd-0x1f6147f0: 
amidxtaped: ru_nivcsw  : 4970121

Out of memory: Killed process 707, UID 0, (amrecover). / Amanda-3.4.4

2017-06-04 Thread Bernhard Erdmann 

Hello,

after an upgrade to Amanda-3.4.4, I discovered that amrecover eats too 
much memory. Trying to recover a single directory from a huge GNU tar 
image (900 GB), amrecover gets killed because of memory constraints.


System is running CentOS 5.11 x86_64 using 8 GB RAM and 24 GB Swap 
available for several years using Amanda to backup to a 90 slot vTape 
iSCSI-attached.


Downgrade to Amanda-3.4.3 helped. The same recover procedure (same 
backup date, same directory to recover) works well using this version.


Last lines of amidxtaped.20170603173611.debug (timezone is CEST (GMT+2)):

Sat Jun 03 17:13:55.770129000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1699:info:490 198642624 kb
Sat Jun 03 17:14:20.07357 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1699:info:490 198645984 kb
Sat Jun 03 17:15:14.519889000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1699:info:490 198646752 kb
Sat Jun 03 17:21:39.862161000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1699:info:490 198647680 kb
Sat Jun 03 17:21:40.388673000 2017: pid 720: thd-0x20d85690: amidxtaped: 
xfer_cancel_with_error: Error writing to fd 8: Broken pipe
Sat Jun 03 17:21:40.388729000 2017: pid 720: thd-0x20d85690: amidxtaped: 
xfer_queue_message: MSG:  version=0>
Sat Jun 03 17:21:40.38890 2017: pid 720: thd-0x20d85690: amidxtaped: 
xfer_queue_message: MSG:  version=0>
Sat Jun 03 17:21:40.845451000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
Cancelling  -> 
)>
Sat Jun 03 17:21:40.922716000 2017: pid 720: thd-0x20d85690: amidxtaped: 
sending XMSG_CRC message 0x20d83010
Sat Jun 03 17:21:40.922777000 2017: pid 720: thd-0x20d85690: amidxtaped: 
pull_and_write CRC: 1b42fe0e  size 203415191552
Sat Jun 03 17:21:40.922793000 2017: pid 720: thd-0x20d85690: amidxtaped: 
xfer_queue_message: MSG:  version=0>
Sat Jun 03 17:21:40.922818000 2017: pid 720: thd-0x20d85690: amidxtaped: 
xfer_queue_message: MSG:  version=0>
Sat Jun 03 17:21:41.313146000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
dest_crc: 1b42fe0e:203415191552
Sat Jun 03 17:21:41.674875000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1893:info:4900012 198647680 kb
Sat Jun 03 17:21:42.462789000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:1921:error:4900055 Error 
writing to fd 8: Broken pipe
Sat Jun 03 17:21:42.958237000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
/opt/amanda/lib/amanda/perl/Amanda/Restore.pm:2138:error:4900068 Error 
writing to fd 8: Broken pipe
Sat Jun 03 17:21:43.406247000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
user_message feedback: Error writing to fd 8: Broken pipe
Sat Jun 03 17:21:44.597549000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
CTL >> MESSAGE Error writing to fd 8: Broken pipe
Sat Jun 03 17:21:46.940293000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
exiting with 1
Sat Jun 03 17:21:46.990525000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_utime   : 352
Sat Jun 03 17:21:46.990566000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_stime   : 463
Sat Jun 03 17:21:46.990576000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_maxrss  : 38984
Sat Jun 03 17:21:46.990595000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_ixrss   : 0
Sat Jun 03 17:21:46.990604000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_idrss   : 0
Sat Jun 03 17:21:46.990611000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_isrss   : 0
Sat Jun 03 17:21:46.990619000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_minflt  : 13614
Sat Jun 03 17:21:46.990627000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_majflt  : 2372
Sat Jun 03 17:21:46.990634000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_nswap   : 0
Sat Jun 03 17:21:46.990641000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_inblock : 0
Sat Jun 03 17:21:46.990649000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_oublock : 0
Sat Jun 03 17:21:46.990656000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_msgsnd  : 0
Sat Jun 03 17:21:46.990663000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_msgrcv  : 0
Sat Jun 03 17:21:46.99067 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_nsignals: 0
Sat Jun 03 17:21:46.990678000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_nvcsw   : 1477628
Sat Jun 03 17:21:46.990685000 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
ru_nivcsw  : 4970121
Sat Jun 03 17:21:47.01036 2017: pid 720: thd-0x1f6147f0: amidxtaped: 
pid 720 finish time Sat Jun  3 17:21:47 2017


Lines from /var/log/messages: