vcenter 问题排查--vcenter api上传文件至虚拟机报500错误

vcenter 问题排查–vcenter api上传文件至虚拟机报500错误

1. 问题背景

vcenter由5.5升级到6.0后,向esxi下的windows10虚拟机上传文件,vcenter api反馈500,但向同esxi下的windows7虚拟机上传文件是成功的。

2. 问题排查记录

  • 1.问题定位
    • 500错误首先可以排除上传脚本本身问题,上传文件是通过vcenter api获取上传文件的url,然后以POST方式将文件上传至虚拟机中。
    • 上传文件的url为:https://1.1.1.159:443/guestFile?id=83&token=52a90eee-5c9e-004f-7cba-4ae79949830c83其中1.1.1.159为esxi IP,所以初步定位是esxi内的服务发生了错误。
  • 2.进入esxi中进一步排查
    • 登录esxi,打开ssh远程连接选项
      ![avatar][open_ssh_of_esxi]
    • ssh进入esxi中,尝试用netstat -apn | grep 443查找出服务信息,但esxi中没有netstat命令,查看常见的web服务进程ps | grep nginx, ps | grep apache, ps | grep http, 发现一个http代理进程:
      [root@localhost:~] ps | grep  http
      33904   33890  rhttpproxy-work
      33905   33890  rhttpproxy-work
      33914   33890  rhttpproxy-poll
      34452   33890  rhttpproxy-work
      35247   33890  rhttpproxy-work 
      
    • 查看/etc/init.d/rhttpproxy文件,发现存在日志路径:/var/log/vmware
      #!/bin/sh                   
      # chkconfig: on 18 82         
                
      export PATH=/bin:/sbin         
      RHTTPPROXY_UPGRADE_CONFIG=/usr/lib/vmware/rhttpproxy/bin/upgrade-config.py  
      RHTTPPROXY_TAG=rhttpproxy
      RHTTPPROXY_LOGDIR=/var/log/vmware
      RHTTPPROXY_SRV_NAME="VMware HTTP reverse proxy"
      RHTTPPROXY_KILL_SIGNAL=15                  
      ISRUNNING="${RHTTPPROXY_SRV_NAME} is running."
      ISNOTRUNNING="${RHTTPPROXY_SRV_NAME} is not running."
      RHTTPPROXY_PID="$(pidof -s $RHTTPPROXY_TAG)"
      
      /var/log/vmware为一空目录,同时发现/var/log/目录下存在rhttpproxy.log:
      [root@localhost:/var/log] ls -l
      total 292
      lrwxrwxrwx    1 root     root            21 May  9 08:40 Xorg.log -> /scratch/log/Xorg.log
      lrwxrwxrwx    1 root     root            21 May  9 08:40 auth.log -> /scratch/log/auth.log
      -rw-rw-rw-    1 root     root         51407 May  9 08:40 boot.gz
      lrwxrwxrwx    1 root     root            22 May  9 08:40 clomd.log -> /scratch/log/clomd.log
      -rw-r--r--    1 root     root         23206 May  9 08:49 configRP.log
      lrwxrwxrwx    1 root     root            25 May  9 08:40 dhclient.log -> /scratch/log/dhclient.log
      lrwxrwxrwx    1 root     root            20 May  9 08:40 epd.log -> /scratch/log/epd.log
      -rw-r--r--    1 root     root             0 May  9 08:40 esxcli.log
      lrwxrwxrwx    1 root     root            26 May  9 08:40 esxupdate.log -> /scratch/log/esxupdate.log
      lrwxrwxrwx    1 root     root            20 May  9 08:40 fdm.log -> /scratch/log/fdm.log
      -rw-r--r--    1 root     root         19512 May 14 09:43 hostd-live-34084-0001.dmp
      lrwxrwxrwx    1 root     root            28 May  9 08:40 hostd-probe.log -> /scratch/log/hostd-probe.log
      lrwxrwxrwx    1 root     root            22 May  9 08:40 hostd.log -> /scratch/log/hostd.log
      lrwxrwxrwx    1 root     root            33 May  9 08:40 hostprofiletrace.log -> /scratch/log/hostprofiletrace.log
      lrwxrwxrwx    1 root     root            28 May  9 08:40 iofiltervpd.log -> /scratch/log/iofiltervpd.log
      drwxr-xr-x    1 root     root           512 May  9 08:41 ipmi
      -rw-r--r--    1 root     root          3118 May  9 08:40 jumpstart-stdout.log
      lrwxrwxrwx    1 root     root            21 May  9 08:40 lacp.log -> /scratch/log/lacp.log
      lrwxrwxrwx    1 root     root            21 May  9 08:40 nfcd.log -> /scratch/log/nfcd.log
      lrwxrwxrwx    1 root     root            22 May  9 08:40 osfsd.log -> /scratch/log/osfsd.log
      lrwxrwxrwx    1 root     root            30 May  9 08:40 rabbitmqproxy.log -> /scratch/log/rabbitmqproxy.log
      lrwxrwxrwx    1 root     root            27 May  9 08:40 rhttpproxy.log -> /scratch/log/rhttpproxy.log
      lrwxrwxrwx    1 root     root            29 May  9 08:40 sdrsinjector.log -> /scratch/log/sdrsinjector.log
      lrwxrwxrwx    1 root     root            22 May  9 08:40 shell.log -> /scratch/log/shell.log
      -rw-------    1 root     root          3599 May 14 09:45 smbios.bin
      lrwxrwxrwx    1 root     root            26 May  9 08:40 storagerm.log -> /scratch/log/storagerm.log
      lrwxrwxrwx    1 root     root            25 May  9 08:40 swapobjd.log -> /scratch/log/swapobjd.log
      -rw-------    1 root     root          9361 May  9 08:40 sysboot.log
      lrwxrwxrwx    1 root     root            23 May  9 08:40 syslog.log -> /scratch/log/syslog.log
      -rw-------    1 root     root         32064 May 14 09:50 tallylog
      lrwxrwxrwx    1 root     root            20 May  9 08:40 usb.log -> /scratch/log/usb.log
      lrwxrwxrwx    1 root     root            24 May  9 08:40 vmauthd.log -> /scratch/log/vmauthd.log
      lrwxrwxrwx    1 root     root            26 May  9 08:40 vmkdevmgr.log -> /scratch/log/vmkdevmgr.log
      lrwxrwxrwx    1 root     root            25 May  9 08:40 vmkernel.log -> /scratch/log/vmkernel.log
      lrwxrwxrwx    1 root     root            26 May  9 08:40 vmkeventd.log -> /scratch/log/vmkeventd.log
      lrwxrwxrwx    1 root     root            27 May  9 08:40 vmksummary.log -> /scratch/log/vmksummary.log
      lrwxrwxrwx    1 root     root            27 May  9 08:40 vmkwarning.log -> /scratch/log/vmkwarning.log
      drwxr-xr-x    1 root     root           512 May 14 09:43 vmware
      lrwxrwxrwx    1 root     root            21 May  9 08:40 vobd.log -> /scratch/log/vobd.log
      lrwxrwxrwx    1 root     root            23 May  9 08:40 vprobe.log -> /scratch/log/vprobe.log
      lrwxrwxrwx    1 root     root            24 May  9 08:40 vprobed.log -> /scratch/log/vprobed.log
      lrwxrwxrwx    1 root     root            21 May  9 08:40 vpxa.log -> /scratch/log/vpxa.log
      lrwxrwxrwx    1 root     root            24 May  9 08:40 vsanvpd.log -> /scratch/log/vsanvpd.log
      lrwxrwxrwx    1 root     root            22 May  9 08:40 vvold.log -> /scratch/log/vvold.log
      
    • 观察rhttpproxy.log,发现在上传成功和上传失败时的日志不同点:
      • 上传文件至windows10时失败的日志:
        2019-05-14T08:57:31.285Z verbose rhttpproxy[32D40B70] [Originator@6876 sub=Proxy Req 41558] New proxy client <SSL(<io_obj p:0xffb13e4c, h:24, <TCP '1.1.1.159:443'>, <TCP '1.1.1.31:57193'>>)>
        2019-05-14T08:57:31.288Z verbose rhttpproxy[32F40B70] [Originator@6876 sub=Proxy Req 41558] Resolved endpoint : [N7Vmacore4Http16LocalServiceSpecE:0xffaa22b0] _serverNamespace = /guestFile _isRedirect = false _port = 8309
        2019-05-14T08:57:31.289Z verbose rhttpproxy[32D40B70] [Originator@6876 sub=Proxy Req 41558] Connected to localhost : 8309 over <io_obj p:0xffc9f2fc, h:25, <TCP '127.0.0.1:32429'>, <TCP '127.0.0.1:8309'>>
        2019-05-14T08:57:31.291Z verbose rhttpproxy[32D40B70] [Originator@6876 sub=Proxy Req 41558] Server localhost : 8309 disconnected
        2019-05-14T08:57:32.857Z verbose rhttpproxy[FFE02B70] [Originator@6876 sub=Proxy Req 01743] Resolved endpoint : [N7Vmacore4Http16LocalServiceSpecE:0x32c40820] _serverNamespace = /sdk _isRedirect = true _port = 8307
        
      • 上传文件至windows7时成功的日志:
        2019-05-14T08:59:31.280Z verbose rhttpproxy[32F40B70] [Originator@6876 sub=Proxy Req 41572] New proxy client <SSL(<io_obj p:0xffc04234, h:24, <TCP '1.1.1.159:443'>, <TCP '1.1.1.31:57322'>>)>
        2019-05-14T08:59:31.283Z verbose rhttpproxy[32D40B70] [Originator@6876 sub=Proxy Req 41572] Resolved endpoint : [N7Vmacore4Http16LocalServiceSpecE:0xffaa22b0] _serverNamespace = /guestFile _isRedirect = false _port = 8309
        2019-05-14T08:59:31.283Z verbose rhttpproxy[32F40B70] [Originator@6876 sub=Proxy Req 41572] Connected to localhost : 8309 over <io_obj p:0xffb1ce1c, h:25, <TCP '127.0.0.1:41733'>, <TCP '127.0.0.1:8309'>>
        2019-05-14T08:59:31.287Z verbose rhttpproxy[32D40B70] [Originator@6876 sub=Proxy Req 01743] Resolved endpoint : [N7Vmacore4Http16LocalServiceSpecE:0x32c40820] _serverNamespace = /sdk _isRedirect = true _port = 8307
        2019-05-14T08:59:31.289Z verbose rhttpproxy[32F40B70] [Originator@6876 sub=Proxy Req 01743] Resolved endpoint : [N7Vmacore4Http16LocalServiceSpecE:0x32c40820] _serverNamespace = /sdk _isRedirect = true _port = 8307
        2019-05-14T08:59:31.389Z verbose rhttpproxy[32F40B70] [Originator@6876 sub=Proxy Req 41572] The client closed the stream, not unexpectedly.
        2019-05-14T08:59:32.917Z verbose rhttpproxy[FFE02B70] [Originator@6876 sub=Proxy Req 01743] Resolved endpoint : [N7Vmacore4Http16LocalServiceSpecE:0x32c40820] _serverNamespace = /sdk _isRedirect = true _port = 8307
        
      可以看到在上传文件时是与esxi上的8309端口服务建立的连接,但上传失败时该连接disconnect了,并且日志中没有反馈出具体的错误原因;
    • 观察/var/log目录发现,rhttpproxy.log/scratch/log/rhttpproxy.log的软链,同时/var/log还存在大量/scratch/log/目录下的日志软链,可推断出这些日志属于同一个服务,当前使用背景是向虚拟机中上传文件,将观察重点放在以下三个日志中:
      lrwxrwxrwx    1 root     root            28 May  9 08:40 hostd-probe.log -> /scratch/log/hostd-probe.log
      lrwxrwxrwx    1 root     root            22 May  9 08:40 hostd.log -> /scratch/log/hostd.log
      lrwxrwxrwx    1 root     root            33 May  9 08:40 hostprofiletrace.log -> /scratch/log/hostprofiletrace.log
      
      再次试验上传文件,在hostd.log中发现了相关日志:
      • 上传文件至windows10时失败的日志:
        2019-05-14T09:23:20.325Z info hostd[809F2B70] [Originator@6876 sub=Guestsvc.GuestFileHandler] GetGuestFileTransferParameters, token is 529424a0-7820-1b3a-ca99-2ff0a6dcfed383
        2019-05-14T09:23:20.325Z info hostd[809F2B70] [Originator@6876 sub=Guestsvc.GuestFileHandler] GetGuestFileTransferParameters: vmmoid is 83
        2019-05-14T09:23:20.325Z info hostd[809F2B70] [Originator@6876 sub=Guestsvc.GuestFileHandler] Guest File Path is C:\123.py
        2019-05-14T09:23:20.326Z info hostd[809F2B70] [Originator@6876 sub=Libs] HGFileCopy_TransferFileUsingReader: Error, cannot convert C:\123.py to CPName
        2019-05-14T09:23:20.326Z info hostd[809F2B70] [Originator@6876 sub=Libs] Vix: [34484 vmGuestOps.cpp:5377]: Error VIX_E_FAIL in CopyFileDoneCallback(): Unknown error
        2019-05-14T09:23:20.326Z error hostd[809F2B70] [Originator@6876 sub=Guestsvc.GuestFileHandler] GuestFileCompleteFunc() job failed with 22
        2019-05-14T09:23:20.326Z error hostd[809F2B70] [Originator@6876 sub=Guestsvc.GuestFileHandler] GuestFileCompleteFunc() throwing InternalServerError
        2019-05-14T09:23:57.819Z info hostd[82381B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5b863a1c-9c2eda01-7eba-20040fe62a62/6saVXPY8U9O2/6saVXPY8U9O2.vmx opID=5f1409c4-bb-0f4b user=vpxuser:Administrator] State Transition (VM_STATE_ON -> VM_STATE_GUEST_OPERATION)
        2019-05-14T09:23:57.894Z info hostd[82880B70] [Originator@6876 sub=Vimsvc.ha-eventmgr] Event 1481 : Guest operation Start Program performed on Virtual machine 6saVXPY8U9O2.
        2019-05-14T09:23:57.896Z info hostd[82880B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5b863a1c-9c2eda01-7eba-20040fe62a62/6saVXPY8U9O2/6saVXPY8U9O2.vmx] State Transition (VM_STATE_GUEST_OPERATION -> VM_STATE_ON)
        
      • 上传文件至windows7时成功的日志:
        2019-05-14T09:36:42.961Z info hostd[82181B70] [Originator@6876 sub=Guestsvc.GuestFileHandler] GetGuestFileTransferParameters, token is 52b097a7-eb63-1efe-914c-703cfef0aa6a78
        2019-05-14T09:36:42.961Z info hostd[82181B70] [Originator@6876 sub=Guestsvc.GuestFileHandler] GetGuestFileTransferParameters: vmmoid is 78
        2019-05-14T09:36:42.961Z info hostd[82181B70] [Originator@6876 sub=Guestsvc.GuestFileHandler] Guest File Path is C:\123.py
        2019-05-14T09:36:43.004Z info hostd[821C2B70] [Originator@6876 sub=Libs] HGFileCopyCreateSessionCB: Successfully created the session.
        2019-05-14T09:36:49.335Z info hostd[82340B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5b863a1c-9c2eda01-7eba-20040fe62a62/windows7_test/windows7_test.vmx opID=5a367cb8-24-1fa5 user=vpxuser:Administrator] State Transition (VM_STATE_ON -> VM_STATE_GUEST_OPERATION)
        2019-05-14T09:36:49.351Z info hostd[821C2B70] [Originator@6876 sub=Vimsvc.ha-eventmgr] Event 1514 : Guest operation List Files performed on Virtual machine windows7_test.
        2019-05-14T09:36:49.352Z info hostd[821C2B70] [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/5b863a1c-9c2eda01-7eba-20040fe62a62/windows7_test/windows7_test.vmx] State Transition (VM_STATE_GUEST_OPERATION -> VM_STATE_ON)
        
      • 可以看到,成功向windows7虚拟机上传文件时,日志显示
        HGFileCopyCreateSessionCB: Successfully created the session.
        
      • 上传到windows10失败时显示
        GuestFileCompleteFunc() job failed with 22
        
      • 显然esxi上8309端口的服务尝试与windows10虚拟机通过22端口创建连接上传文件,因此失败
    • 查看虚拟机信息:
      ![avatar][failed_win10_open]
      avatar
      可以看到上传文件失败的win10在开启和关闭电源的情况下,都未正确识别出操作系统,同时虚拟机模板也是未能正确识别出操作系统。但win7虚拟机是正确识别出操作系统的。
    • 重新创建虚拟机,要求虚拟机在开启和关闭电源的情况下都正确识别出操作系统:
      avatar
      avatar
    • 向正确识别操作系统的虚拟机上传文件,上传成功;
  • vcenter5.5中创建虚拟机不支持选择windows10系统,但vcenter6.0中支持将虚拟机设定为windows10系统:
    avatar
  • 0
    点赞
  • 0
    收藏
    觉得还不错? 一键收藏
  • 0
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值