未解决
此帖子已超过 5 年
43 消息
0
1929
Avamar 6.1 VADP:经常因为'vm.vmx' (0 bytes)而自动取消备份
Avamar的备份日志
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.522+09:00 [7FE775407710 trivia 'transport'] Transport mode hotadd passed pre-flight checks. Adding to list of available transports.
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.522+09:00 [7FE775407710 trivia 'transport'] Checking transport mode nbdssl.
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.522+09:00 [7FE775407710 trivia 'transport'] Transport mode nbdssl passed pre-flight checks. Adding to list of available transports.
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.522+09:00 [7FE775407710 trivia 'transport'] Checking transport mode nbd.
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.522+09:00 [7FE775407710 trivia 'transport'] Transport mode nbd passed pre-flight checks. Adding to list of available transports.
2014-06-23 02:00:58 avvcbimage Info <9669>: VixDiskLib_ConnectEx returned VIX_OK
2014-06-23 02:00:58 avvcbimage Info <6686>: Process 25163 (/usr/local/avamarclient/bin/avtar) for workorder Daily-02-IAAS06-1403456400265 started
2014-06-23 02:00:58 avvcbimage Info <9704>: spawnp->get_stdio_fd(0) on avtar with pipe #18 on start
2014-06-23 02:00:58 avvcbimage Info <7252>: Generating PAX stream blocksize 512 to path ""
2014-06-23 02:00:58 avvcbimage Info <9706>: Adding file 'avamar vm configuration.xml' (5435 bytes)
2014-06-23 02:00:58 avvcbimage Info <9706>: Adding file 'snapshot description.xml' (15 bytes)
2014-06-23 02:00:58 avvcbimage Info <9706>: Adding file 'vm.ovf' (14494 bytes)
2014-06-23 02:00:58 avvcbimage Info <9706>: Adding file 'vm.vmx' (0 bytes)
2014-06-23 02:00:58 avvcbimage Error <12016>: vmx file is suspiciously small (under 30 bytes), please examine the log on the Avamar Administrator for root cause analysis
2014-06-23 02:00:58 avvcbimage Info <0000>: Starting graceful (staged) termination, The VMX file in the workorder was too small. (wrap-up stage)
2014-06-23 02:00:58 avvcbimage Info <9706>: Adding file 'vm.nvram' (2460 bytes)
2014-06-23 02:00:58 avvcbimage Error <9760>: Backup of VM metadata failed.
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.530+09:00 [7FE775407710 info 'Default'] Successfully released all resources.
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.530+09:00 [7FE775407710 trivia 'vmomi.soapStub[0]'] Sending soap request to [ ]: logout {}
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.530+09:00 [7FE775407710 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] Found pending connection to
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.530+09:00 [7FE775407710 trivia 'vmomi.soapStub[0]'] Request started [N7Vmacore4Http13UserAgentImpl22AsyncSendRequestHelperE:0x7fe769b68090]
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.535+09:00 [7FE76C9D0710 trivia 'vmomi.soapStub[0]'] Request completed [N7Vmacore4Http13UserAgentImpl22AsyncSendRequestHelperE:0x7fe769b68090]
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.535+09:00 [7FE775407710 trivia 'vmomi.soapStub[0]'] Received SOAP response from [ ]: logout
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.535+09:00 [7FE775407710 trivia 'HttpConnectionPool-000000'] [PopPendingConnection] No pending connections to
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.535+09:00 [7FE775407710 info 'vmomi.soapStub[0]'] Resetting stub adapter for server : Closed
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.535+09:00 [7FE76CA11710 trivia 'HttpConnectionPool-000000'] [DecConnectionCount] Number of connections to decremented to 0
2014-06-23 02:00:58 avvcbimage Info <9672>: Disconnected from VM
2014-06-23 02:00:58 avvcbimage Info <16055>: Sending cancel message to avtar so the backup is changed to a partial.
2014-06-23 02:00:58 avvcbimage Info <16041>: VDDK:2014-06-23T02:00:58.535+09:00 [7FE76CA93710 trivia 'HttpConnectionPool-000001'] [DecConnectionCount] Number of connections to decremented to 0
2014-06-23 02:00:58 avvcbimage Info <8701>: Closing pax stream
2014-06-23 02:00:58 avvcbimage Info <14692>: Login test is OK.
2014-06-23 02:00:58 avvcbimage Info <14642>: Deleting the snapshot 'Avamar-14034564414d68857fecf9c80304037dde12ebe99c1f1e6758', moref 'snapshot-39771'
2014-06-23 02:00:58 avvcbimage Info <14679>: Removing prior snapshot[0], 'Avamar-14034564414d68857fecf9c80304037dde12ebe99c1f1e6758'.
2014-06-23 02:00:58 avvcbimage Info <10684>: Setting ctl message version to 3 (from 1)
2014-06-23 02:00:58 avvcbimage Info <16136>: Setting ctl max message size to 268435456
2014-06-23 02:00:58 avvcbimage Info <6688>: Process 25163 (/usr/local/avamarclient/bin/avtar) finished (code 163: externally cancelled)
2014-06-23 02:00:58 avvcbimage Warning <6690>: CTL workorder "Daily-02-IAAS06-1403456400265" non-zero exit status 'code 163: externally cancelled'
2014-06-23 02:01:03 avvcbimage Info <15999>: The snapshot removal task for VM '[Prod-FAST-R5_115_N1] Win2003 Ent R2 32bit (30GB) (ea8a25bf-f2f4-4682-814f-8ad2d8477372)/Win2003 Ent R2 32bit (30GB) (ea8a25bf-f2f4-4682-814f-8ad2d8477372).vmx' has exceeded the wait time of 4 seconds, exiting wait.
2014-06-23 02:01:03 avvcbimage Error <9768>: Avtar exited with 'code 163: externally cancelled'
2014-06-23 02:01:03 avvcbimage Info <16041>: VDDK:VixDiskLibVimResolveHostName: Resolving IP address for hostname VBCdhv-011.sbgcf.local:443.
2014-06-23 02:01:03 avvcbimage Info <16038>: Final summary, cancelled/aborted 0, snapview 2, exitcode 157: miscellaneous error
2014-06-23 02:01:03 avvcbimage Info <16041>: VDDK:VixDiskLibVimResolveHostName: Resolved to 10.1.2.50.
2014-06-23 02:01:03 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVimLogin
2014-06-23 02:01:04 avvcbimage Info <16041>: VDDK:VixDiskLibVim: TicketFindVMByMoRef: vmxPath = -vm-36525-
2014-06-23 02:01:04 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVimLoadVM
2014-06-23 02:01:04 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVimLoadAuthMgr
2014-06-23 02:01:04 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVimLoadVMCb
2014-06-23 02:01:04 avvcbimage Info <16041>: VDDK:VixDiskLibVim: VixDiskLibVimLogout
2014-06-23 02:01:05 avvcbimage Info <0000>: VixDiskLib vMotion reservation successfully released
Jason_Zhou
1.2K 消息
0
2014年6月23日 19:00
关于Avamar的问题，帖子我先移动至 备份和恢复系统 版块内，方便懂这块技术的坛友们看到。
DELL-Leo
Community Manager
Community Manager
•
7.1K 消息
0
2014年6月24日 00:00
LZ，
你这个VM是不是位于 vApp pool里面啊？如果是的话，按下面KB内容操作：
https://emc--c.na5.visual.force.com/apex/KB_BreakFix_1?id=kA1700000000Vzd
Workaround:
Remove the VM from the vApp pool, to do this:
1. Open vSphere client to connect to the vCenter
2. Right click the affected VM and choose Edit Settings
3. Switch to the Options tab, find the vApp option and disable it
WCD
43 消息
0
2014年6月24日 01:00
不是在vApp Pool里面，我这个Case并不是一直出这个错备份不了。
而是偶尔出现在不同的VM的备份。手动重新执行一下就好了。
EMC KB里面几个相关的我都看了，也是一头雾水。
https://emc--c.na5.visual.force.com/apex/KB_BreakFix_1?id=kA1700000000T84
https://emc--c.na5.visual.force.com/apex/KB_BreakFix_1?id=kA1700000000VKP
另外VM那边的vmware.log，ESXis的vpxa.log, hostd.log, vmkernel.log都看了，也找到沙问题。
DELL-Leo
Community Manager
Community Manager
•
7.1K 消息
0
2014年6月24日 18:00
这种时断时续的备份失败是比较麻烦。你贴出的第一个KB里面的四种可能性，有没有去检查过？
像第一种可能的话，去检查 /usr/local/avamar/var/mc/server_log/mcserver.log 下面有没有 ”WARNING: FAILED TO GET VC CONNECTION“ 信息，有的话去按步骤尝试解决。
还有，检查哪里有没有特殊字符。如果ESX版本是4.0的话，加KB里提到的参数后再试试等等。
这种问题只能是一个一个去检查，然后排除问题了。
WCD
43 消息
0
2014年6月24日 22:00
恩，都看了。感觉都基本不相符。
实在不行就只能设定debug了，看看能不能找出问题所在
Yanhong1
1.6K 消息
0
2014年6月30日 00:00
怎么样，找到问题所在了吗？
WCD
43 消息
0
2014年6月30日 01:00
没有，在当前默认的日志水平下，只能看出有问题，看不出问什么出问题。
已经告诉可以提高日志等级，等再现的时候另行调查了
DELL-Leo
Community Manager
Community Manager
•
7.1K 消息
0
2014年6月30日 02:00
是啊，只能Debug开启后等待问题重现了，然后看看能不能抓到一些有用的信息。。