AVCTL Errors in Avamar Clients

CTL is the communication protocol that the Avamar agent and Avamar client binaries use to communicate. This protocol is also used for communication between agents when performing federated backups. For a more specific answer, you'll have to provide more specific information (e.g. log snippets).

Thanks Ian,

Please look at the error message we get,

87721:save: Using 'D:\BBTData' for 'D:\bbtdata'.

90029:save: Saving with deduplication enabled.

avtar Info <5008>: Logging to C:\Program Files\EMC NetWorker\nsr\dedup\logs\avtar_save_5504_23639499997184.log

61819:save:Saving data to de-duplication node wil-avamar01-utl

42923:save:AVCTL Service Log: nsravtar version 6.1.101-87 built on Dec 10 2012 19:06:00 running on Windows Server 2008 R2 Standard Server Edition Service Pack 1 64-bit

61187:save:De-Dup session established successfully

89422:save: Backup of BBTData\' was done previously, checkfile enabled

56487:save:Detected the end of the AVCTL connection.

60795:save:AVCTL connection closed abnormally

99123:save: Handling an abort while processing Windows backup.

nsravtar severed connection abruptly. Please refer to logfile C:\Program Files\EMC NetWorker\nsr\dedup\logs\avtar_save_5504_23639499997184.log for details

D:\bbtdata: retried 3 times.

You'll need to review the contents of the log file C:\Program Files\EMC NetWorker\nsr\dedup\logs\avtar_save_5504_23639499997184.log. If you don't immediately see the problem, I can review that log if you post it here.

It's a big file and it won't be good if I paste it here, but size is just 26KB. Is that possible to attach the file here?

You may be able to upload it as a document but I don't know if customers / partners can post documents in the Avamar space. I don't know of a way to attach files to discussion threads.

Hi Ian,

Please find the log file below

--------------------------------------------------------------------------------------------------------

-----  START avtar log 2016-09-15 14:55:41 Eastern Daylight Time  [6.1.101-87 Windows Server 2008 R2 Standard Server Edition Service Pack 1 64-bit-AMD64]

--------------------------------------------------------------------------------------------------------

2016-09-15 14:55:41 avtar Info <5008>: Logging to C:\Program Files\EMC NetWorker\nsr\dedup\logs\avtar_save_7480_32126355374080.log

2016-09-15 14:55:41 avtar Info <5551>: Command Line: C:\Program Files\EMC NetWorker\nsr\bin\nsravtar.exe --vardir="C:\Program Files\EMC NetWorker\nsr\dedup\cache" --logfile="C:\Program Files\EMC NetWorker\nsr\dedup\logs\avtar_save_7480_32126355374080.log" --bindir="C:\Program Files\EMC NetWorker\nsr\bin" --libavctl_path="C:\Program Files\EMC NetWorker\nsr\bin\libavctl.dll" --ctlcallip=127.0.0.1 --ctlcallport=53114 --stream=::127.0.0.1:53115 --xdrctl --x05=128 --xdrdata_conforming_stream=false --nostdout

2016-09-15 14:55:41 avtar Info <7977>: Starting at 2016-09-15 14:55:41 Eastern Daylight Time [avtar Dec 10 2012 19:06:00 6.1.101-87 Windows Server 2008 R2 Standard Server Edition Service Pack 1 64-bit-AMD64]

2016-09-15 14:55:41 avtar Info <6767>: Successfully connected to 127.0.0.1:53114

2016-09-15 14:55:43 avtar Info <8928>: Backup source path is 'E:\\wht-fs02'

2016-09-15 14:55:43 avtar Info <8517>: Starting log file maintenance in "C:\Program Files\EMC NetWorker\nsr\dedup\logs" and "C:\Program Files\EMC NetWorker\nsr\dedup\logs\clientlogs"

2016-09-15 14:55:43 avtar Info <6712>: Log file maintenance complete, 0 file(s) removed

2016-09-15 14:55:43 avtar Info <5900>: Workorder received (truncated):

2016-09-15 14:55:43 avtar Info <10793>: Single Instance Store Groveler Service NOT installed - WSS SIS Manager will be not started.

2016-09-15 14:55:43 avtar Info <5946>: File system character encoding is 65001 (UTF-8).

2016-09-15 14:55:43 avtar Info <8940>: Starting back up at 2016-09-15 14:55:43 Eastern Daylight Time as "NT AUTHORITY\SYSTEM" on "wht-fs02" (16 CPUs) [6.1.101-87]

2016-09-15 14:55:43 avtar Info <5730>: Entering include/exclude rules.

2016-09-15 14:55:43 avtar Info <5150>: Backing up a single file ""

2016-09-15 14:55:43 avtar Info <8474>: - Log file path: C:\Program Files\EMC NetWorker\nsr\dedup\logs\avtar_save_7480_32126355374080.log

2016-09-15 14:55:43 avtar Info <6555>: Initializing connection (Avamar Deduplication Engine v2.0.0)

2016-09-15 14:55:43 avtar Info <5552>: Connecting to Avamar Server (wil-avamar01-utl)

2016-09-15 14:55:43 avtar Info <5554>: Connecting to one node in each datacenter

2016-09-15 14:55:43 avtar Info <5993>: - Connect: Connected to 10.128.207.197:27000, Priv=0, TCP

2016-09-15 14:55:43 avtar Info <5559>: - Trying connection 10.128.207.195:27000

2016-09-15 14:55:43 avtar Info <5560>: - Connected to node 10.128.207.195:27000, Priv=0, TCP

2016-09-15 14:55:43 avtar Info <5583>: Login User: "MCUser", Domain: "default", Account: "/NetWorker/wil-leg02/wht-fs02"

2016-09-15 14:55:43 avtar Info <5580>: Logging in on connection 0 (server 0)

2016-09-15 14:55:43 avtar Info <5582>: Avamar Server login successful

2016-09-15 14:55:43 avtar Info <5018>: - Session ID: 0

2016-09-15 14:55:43 avtar Info <5550>: Successfully logged into Avamar Server [7.1.2-21] (Compression enabled)

2016-09-15 14:55:43 avtar Info <7563>: Back up of "" on server "wil-avamar01-utl" for /NetWorker/wil-leg02/wht-fs02

2016-09-15 14:55:44 avtar Info <5586>: Loading cache files from C:\Program Files\EMC NetWorker\nsr\dedup\cache

2016-09-15 14:55:44 avtar Info <8650>: Opening cache file C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 14:55:44 avtar Info <7324>: Volume Type for "C:\" is "NTFS", Supports Compression=1, Encryption=1, ACLS=1, DataStreams=1, Reparse=1, Sparse=1

2016-09-15 14:55:44 avtar Info <5573>: - Loaded cache file C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (184,549,920 bytes)

2016-09-15 14:55:44 avtar Info <8650>: Opening cache file C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_p_cache.dat

2016-09-15 14:55:44 avtar Info <5573>: - Loaded cache file C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_p_cache.dat (12,583,456 bytes)

2016-09-15 14:55:45 avtar Info <6426>: Done loading cache files

2016-09-15 14:55:45 avtar Info <6995>: Parsing 'savestream' stream format from path '::127.0.0.1:53115'

2016-09-15 14:55:45 avtar Info <10818>: Backstream creating root backstreamdir object

2016-09-15 15:10:56 avtar Info <8688>: Status 2016-09-15 15:10:56, 344.7 KB (144.4 KB, 41.90% new) 271MB  53% CPU  \d0\o2

2016-09-15 15:26:09 avtar Info <8688>: Status 2016-09-15 15:26:09, 344.7 KB (144.4 KB, 41.90% new) 307MB  76% CPU  \d0\o2

2016-09-15 15:41:21 avtar Info <8688>: Status 2016-09-15 15:41:21, 344.7 KB (144.4 KB, 41.90% new) 336MB  81% CPU  \d0\o2

2016-09-15 15:53:18 avtar Info <5548>: 2016-09-15 15:53:18 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 15:53:18 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 15:53:19 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 15:56:34 avtar Info <8688>: Status 2016-09-15 15:56:34, 35.00 MB (11.03 MB, 31.52% new) 363MB  79% CPU  \d0\oa4

2016-09-15 16:11:46 avtar Info <8688>: Status 2016-09-15 16:11:46, 36.98 MB (11.78 MB, 31.85% new) 381MB  83% CPU  \d0\oab

2016-09-15 16:26:02 avtar Info <5548>: 2016-09-15 16:26:02 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 16:26:02 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 16:26:03 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 16:26:59 avtar Info <8688>: Status 2016-09-15 16:26:59, 38.02 MB (12.01 MB, 31.60% new) 403MB  84% CPU  \d0\ob0

2016-09-15 16:42:12 avtar Info <8688>: Status 2016-09-15 16:42:12, 45.28 MB (13.50 MB, 29.81% new) 421MB  86% CPU  \d0\oc6

2016-09-15 16:46:07 avtar Info <5548>: 2016-09-15 16:46:07 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 16:46:07 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 16:46:08 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 16:57:24 avtar Info <8688>: Status 2016-09-15 16:57:24, 48.41 MB (14.87 MB, 30.72% new) 441MB  87% CPU  \d0\oe0

2016-09-15 17:07:01 avtar Info <5548>: 2016-09-15 17:07:01 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 17:07:01 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 17:07:01 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 17:12:37 avtar Info <8688>: Status 2016-09-15 17:12:37, 49.71 MB (15.22 MB, 30.61% new) 458MB  87% CPU  \d0\of1

2016-09-15 17:27:25 avtar Info <5548>: 2016-09-15 17:27:25 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 17:27:25 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 17:27:26 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 17:27:49 avtar Info <8688>: Status 2016-09-15 17:27:49, 50.00 MB (15.45 MB, 30.90% new) 476MB  88% CPU  \d0\of5

2016-09-15 17:43:02 avtar Info <8688>: Status 2016-09-15 17:43:02, 795.5 MB (18.44 MB, 2.32% new) 496MB  90% CPU  \d0\o116

2016-09-15 17:48:35 avtar Info <5548>: 2016-09-15 17:48:35 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 17:48:35 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 17:48:36 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 17:58:14 avtar Info <8688>: Status 2016-09-15 17:58:14, 906.7 MB (58.28 MB, 6.43% new) 521MB  89% CPU  \d0\o138

2016-09-15 18:13:27 avtar Info <8688>: Status 2016-09-15 18:13:27, 906.7 MB (58.28 MB, 6.43% new) 526MB  90% CPU  \d0\o139

2016-09-15 18:15:07 avtar Info <5548>: 2016-09-15 18:15:07 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 18:15:07 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 18:15:08 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 18:28:39 avtar Info <8688>: Status 2016-09-15 18:28:39, 907.9 MB (58.91 MB, 6.49% new) 540MB  88% CPU  \d0\o13e

2016-09-15 18:43:52 avtar Info <8688>: Status 2016-09-15 18:43:52, 907.9 MB (58.91 MB, 6.49% new) 553MB  89% CPU  \d0\o13e

2016-09-15 18:49:53 avtar Info <5548>: 2016-09-15 18:49:53 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 18:49:53 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 18:49:54 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 18:59:05 avtar Info <8688>: Status 2016-09-15 18:59:05, 908.2 MB (59.00 MB, 6.50% new) 567MB  91% CPU  \d0\o148

2016-09-15 19:10:12 avtar Info <5548>: 2016-09-15 19:10:12 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 19:10:12 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 19:10:13 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 19:14:17 avtar Info <8688>: Status 2016-09-15 19:14:17, 910.4 MB (60.00 MB, 6.59% new) 581MB  92% CPU  \d0\o17d

2016-09-15 19:29:30 avtar Info <8688>: Status 2016-09-15 19:29:30, 911.1 MB (60.19 MB, 6.61% new) 595MB  92% CPU  \d0\o186

2016-09-15 19:44:42 avtar Info <8688>: Status 2016-09-15 19:44:42, 911.1 MB (60.21 MB, 6.61% new) 608MB  92% CPU  \d0\o189

2016-09-15 19:59:55 avtar Info <8688>: Status 2016-09-15 19:59:55, 911.1 MB (60.21 MB, 6.61% new) 622MB  93% CPU  \d0\o189

2016-09-15 20:15:08 avtar Info <8688>: Status 2016-09-15 20:15:08, 911.1 MB (60.21 MB, 6.61% new) 633MB  87% CPU  \d0\o189

2016-09-15 20:22:31 avtar Info <5548>: 2016-09-15 20:22:31 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 20:22:31 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 20:22:32 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 20:30:20 avtar Info <8688>: Status 2016-09-15 20:30:20, 916.6 MB (65.68 MB, 7.17% new) 660MB  91% CPU  \d0\o18c

2016-09-15 20:45:33 avtar Info <8688>: Status 2016-09-15 20:45:33, 916.6 MB (65.68 MB, 7.17% new) 663MB  92% CPU  \d0\o18c

2016-09-15 20:52:19 avtar Info <5548>: 2016-09-15 20:52:19 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 20:52:19 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 20:52:20 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 21:00:45 avtar Info <8688>: Status 2016-09-15 21:00:45, 926.1 MB (71.67 MB, 7.74% new) 678MB  91% CPU  \d0\o1b9

2016-09-15 21:12:43 avtar Info <5548>: 2016-09-15 21:12:43 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 21:12:43 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 21:12:44 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 21:15:58 avtar Info <8688>: Status 2016-09-15 21:15:58, 927.2 MB (72.18 MB, 7.79% new) 680MB  86% CPU  \d0\o1c0

2016-09-15 21:31:11 avtar Info <8688>: Status 2016-09-15 21:31:11, 928.1 MB (72.94 MB, 7.86% new) 687MB  92% CPU  \d0\o1c9

2016-09-15 21:33:32 avtar Info <5548>: 2016-09-15 21:33:32 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 21:33:32 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 21:33:33 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 21:46:23 avtar Info <8688>: Status 2016-09-15 21:46:23, 928.2 MB (72.97 MB, 7.86% new) 696MB  91% CPU  \d0\o1ca

2016-09-15 21:56:39 avtar Info <5548>: 2016-09-15 21:56:39 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 21:56:39 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 21:56:40 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 22:01:36 avtar Info <8688>: Status 2016-09-15 22:01:36, 929.7 MB (74.06 MB, 7.97% new) 706MB  91% CPU  \d0\o1e8

2016-09-15 22:16:47 avtar Info <5548>: 2016-09-15 22:16:47 Eastern Daylight Time: Automatic cache flush of C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat

2016-09-15 22:16:47 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 22:16:48 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 22:16:48 avtar Info <8688>: Status 2016-09-15 22:16:48, 966.6 MB (75.90 MB, 7.85% new) 728MB  92% CPU  \d0\o21a

2016-09-15 22:31:00 avtar Warning <0000>: High memory consumption: Total:1234MB - Base:19MB - Hashcache:12MB - Filecache:176MB = 1027MB (excessive=2048MB)

2016-09-15 22:31:00 avtar Info <10528>: GComMgrQueue=0(0MB) max=16(1MB), Chunker=0(0MB) max=0MB, Pending=0 int + 0 ext msgs, Maxpending=40

2016-09-15 22:31:15 avtar Warning <0000>: High memory consumption: Total:1379MB - Base:19MB - Hashcache:12MB - Filecache:176MB = 1172MB (excessive=2048MB)

2016-09-15 22:31:15 avtar Info <10528>: GComMgrQueue=0(0MB) max=16(1MB), Chunker=0(0MB) max=0MB, Pending=0 int + 0 ext msgs, Maxpending=40

2016-09-15 22:31:31 avtar Warning <0000>: High memory consumption: Total:1514MB - Base:19MB - Hashcache:12MB - Filecache:176MB = 1307MB (excessive=2048MB)

2016-09-15 22:31:31 avtar Info <10528>: GComMgrQueue=0(0MB) max=16(1MB), Chunker=0(0MB) max=0MB, Pending=0 int + 0 ext msgs, Maxpending=40

2016-09-15 22:31:51 avtar Warning <0000>: High memory consumption: Total:1665MB - Base:19MB - Hashcache:12MB - Filecache:176MB = 1458MB (excessive=2048MB)

2016-09-15 22:31:51 avtar Info <10528>: GComMgrQueue=0(0MB) max=16(1MB), Chunker=0(0MB) max=0MB, Pending=0 int + 0 ext msgs, Maxpending=40

2016-09-15 22:32:01 avtar Info <8688>: Status 2016-09-15 22:32:01, 977.8 MB (78.23 MB, 8.00% new) 1731MB  93% CPU  \d0\o23e

2016-09-15 22:32:16 avtar Warning <0000>: High memory consumption: Total:1825MB - Base:19MB - Hashcache:12MB - Filecache:176MB = 1618MB (excessive=2048MB)

2016-09-15 22:32:16 avtar Info <10528>: GComMgrQueue=0(0MB) max=16(1MB), Chunker=0(0MB) max=0MB, Pending=0 int + 1 ext msgs, Maxpending=40

2016-09-15 22:32:47 avtar Warning <0000>: High memory consumption: Total:2002MB - Base:19MB - Hashcache:12MB - Filecache:176MB = 1795MB (excessive=2048MB)

2016-09-15 22:32:47 avtar Info <10528>: GComMgrQueue=0(0MB) max=16(1MB), Chunker=0(0MB) max=0MB, Pending=0 int + 0 ext msgs, Maxpending=40

2016-09-15 22:33:22 avtar Warning <0000>: High memory consumption: Total:2184MB - Base:19MB - Hashcache:12MB - Filecache:176MB = 1977MB (excessive=2048MB)

2016-09-15 22:33:22 avtar Info <10528>: GComMgrQueue=0(0MB) max=16(1MB), Chunker=0(0MB) max=0MB, Pending=0 int + 0 ext msgs, Maxpending=40

2016-09-15 22:34:08 avtar Warning <0000>: High memory consumption: Total:2401MB - Base:19MB - Hashcache:12MB - Filecache:176MB = 2194MB (excessive=2048MB)

2016-09-15 22:34:08 avtar Info <10528>: GComMgrQueue=0(0MB) max=16(1MB), Chunker=0(0MB) max=0MB, Pending=0 int + 0 ext msgs, Maxpending=40

2016-09-15 22:34:59 avtar Warning <0000>: High memory consumption: Total:2621MB - Base:19MB - Hashcache:12MB - Filecache:176MB = 2414MB (excessive=2048MB)

2016-09-15 22:34:59 avtar Info <10528>: GComMgrQueue=0(0MB) max=16(1MB), Chunker=0(0MB) max=0MB, Pending=0 int + 0 ext msgs, Maxpending=40

2016-09-15 22:35:44 avtar Warning <0000>: High memory consumption: Total:3160MB - Base:19MB - Hashcache:12MB - Filecache:176MB = 2953MB (excessive=2048MB)

2016-09-15 22:35:44 avtar Info <10528>: GComMgrQueue=0(0MB) max=16(1MB), Chunker=0(0MB) max=0MB, Pending=0 int + 0 ext msgs, Maxpending=40

2016-09-15 22:40:53 avtar Info <7324>: Volume Type for "\" is "NTFS", Supports Compression=1, Encryption=1, ACLS=1, DataStreams=1, Reparse=1, Sparse=1

2016-09-15 22:41:02 avtar Info <5163>: Backup complete, wrapping-up session with Server

2016-09-15 22:41:02 avtar Info <5156>: Backup #3272 timestamp 2016-09-15 22:41:02, 2,031,433 files, 1 folders, 977.8 MB (2,031,433 files, 78.23 MB, 8.00% new)

2016-09-15 22:41:02 avtar Info <7539>: Label "3755667116", no scheduled expiration

2016-09-15 22:41:02 avtar Info <6083>: Backed-up 977.8 MB in 465.35 minutes: 126 MB/hour (261,924 files/hour)

2016-09-15 22:41:02 avtar Info <5587>: Updating cache files in C:\Program Files\EMC NetWorker\nsr\dedup\cache

2016-09-15 22:41:02 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat"

2016-09-15 22:41:03 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_f_cache.dat (176.0MB of 1531MB max)

2016-09-15 22:41:03 avtar Info <5069>: - Writing cache file "C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_p_cache.dat"

2016-09-15 22:41:03 avtar Info <5546>: Cache update complete C:\Program Files\EMC NetWorker\nsr\dedup\cache\026901d9806606706e6815b051a3a3262afaf912_p_cache.dat (12.0MB of 765MB max)

2016-09-15 22:41:03 avtar Info <7883>: Finished at 2016-09-15 22:41:03 Eastern Daylight Time, Elapsed time: 0007h:45m:21s

2016-09-15 22:41:13 avtar Info <8468>: Sending wrapup message to parent

2016-09-15 22:41:13 avtar Info <5314>: Command completed (10 warnings, exit code 0: success)

--------------------------------------------------------------------------------------------------------

----- END avtar log 2016-09-15 22:41:47 Eastern Daylight Time  (10 warnings, 0 errors, 0 fatal errors)

--------------------------------------------------------------------------------------------------------

It's likely that the High Memory Usage messages are what's triggering the failure. I don't see anything else logged that could be causing it.

My first thought was your server was too busy

I see in your log a number of warnings about High Memory usage.

Is there something else big going on at that time on the server that it cannot handle the backups as well?

Might not be the issue, but something to look at.

Thanks J.H. - end user and Ian Andersontoo thought the same. But I am not aware of Avamar errors. Okay let me check with the client end for that.