本文首发于泊浮目的专栏：https://segmentfault.com/blog/camile

在前文 ZStack源码剖析之二次开发——可扩展框架中，我们大概的了解了如何在ZStack中进行二次开发。在本文，笔者将和大家一起了解一下常用debug管理节点的方法，用于更好的了解运行时的情况。

使用日志来debug

阅读日志可以算是最为轻量级的手段了——同理，在大多数情况下，我们最好通过打印日志来观察我们的程序。我们以创建VM为例，看看如何在日志中跟踪它的Trace。
ZStack源码剖析之二次开发——Debug的常用技巧 - 图1
当创建VM以后，我们可以从右上角查看消息记录。如：

请求: {
    "type": "post",
    "path": "vm-instances",
    "body": {
        "params": {
            "name": "vm1",
            "description": "",
            "instanceOfferingUuid": "aee8b43d672e4b019e76471d3767e93a",
            "imageUuid": "e588b839d3013f4fa1490695bc5cd5fb",
            "l3NetworkUuids": [
                "62dc48a48f964e73b463dad1a86089df"
            ],
            "dataDiskOfferingUuids": [],
            "systemTags": [
                "usbRedirect::false",
                "vmConsoleMode::vnc"
            ]
        }
    },
    "sessionUuid": "5bcb2d86e1c64c8ea2568a2d311a90ed",
    "jobUuid": "84d99d2d663856dea44c6eb1a80f9599"
}
返回: {
    "inventory": {
        "uuid": "557c0ee1abeb4cd7929675cf0a239610",
        "name": "vm1",
        "description": "",
        "zoneUuid": "04d920c5dd9342f3bbf7da6a6ece3270",
        "clusterUuid": "627ef14b478d4547ba8c3ef5df65e14f",
        "imageUuid": "e588b839d3013f4fa1490695bc5cd5fb",
        "hostUuid": "3cd0c0d21feb4b5bbf2d962494aa2747",
        "lastHostUuid": "3cd0c0d21feb4b5bbf2d962494aa2747",
        "instanceOfferingUuid": "aee8b43d672e4b019e76471d3767e93a",
        "rootVolumeUuid": "725fbcd4f29e4c7eb584dc83d444c9c3",
        "platform": "Linux",
        "defaultL3NetworkUuid": "62dc48a48f964e73b463dad1a86089df",
        "type": "UserVm",
        "hypervisorType": "KVM",
        "memorySize": 1073741824,
        "cpuNum": 1,
        "cpuSpeed": 0,
        "allocatorStrategy": "LeastVmPreferredHostAllocatorStrategy",
        "createDate": "Mar 13, 2018 10:02:58 PM",
        "lastOpDate": "Mar 13, 2018 10:03:03 PM",
        "state": "Running",
        "internalId": 9,
        "vmNics": [
            {
                "uuid": "1537216f71d6439dab7e27d2c90e78ef",
                "vmInstanceUuid": "557c0ee1abeb4cd7929675cf0a239610",
                "usedIpUuid": "b9dc65ad184f3d8aae43e8082ee86705",
                "l3NetworkUuid": "62dc48a48f964e73b463dad1a86089df",
                "ip": "10.107.100.84",
                "mac": "fa:97:15:73:da:00",
                "netmask": "255.0.0.0",
                "gateway": "10.0.0.1",
                "internalName": "vnic9.0",
                "deviceId": 0,
                "createDate": "Mar 13, 2018 10:02:58 PM",
                "lastOpDate": "Mar 13, 2018 10:02:58 PM"
            }
        ],
        "allVolumes": [
            {
                "uuid": "725fbcd4f29e4c7eb584dc83d444c9c3",
                "name": "ROOT-for-vm1",
                "description": "Root volume for VM[uuid:557c0ee1abeb4cd7929675cf0a239610]",
                "primaryStorageUuid": "53967115ef324a85b634ceb27e84952f",
                "vmInstanceUuid": "557c0ee1abeb4cd7929675cf0a239610",
                "rootImageUuid": "e588b839d3013f4fa1490695bc5cd5fb",
                "installPath": "/opt/zstack/nfsprimarystorage/prim-53967115ef324a85b634ceb27e84952f/rootVolumes/acct-36c27e8ff05c4780bf6d2fa65700f22e/vol-725fbcd4f29e4c7eb584dc83d444c9c3/725fbcd4f29e4c7eb584dc83d444c9c3.qcow2",
                "type": "Root",
                "format": "qcow2",
                "size": 12682240,
                "actualSize": 7995392,
                "deviceId": 0,
                "state": "Enabled",
                "status": "Ready",
                "createDate": "Mar 13, 2018 10:02:58 PM",
                "lastOpDate": "Mar 13, 2018 10:03:00 PM",
                "isShareable": false
            }
        ]
    },
    "jobUuid": "84d99d2d663856dea44c6eb1a80f9599",
    "success": true,
    "sessionUuid": "5bcb2d86e1c64c8ea2568a2d311a90ed"
}

在这里可以看到jobUuid为84d99d2d663856dea44c6eb1a80f9599。那么我们用这个关键字对MN的日志进行grep：

[root@test-mn-ceph ~]# grep 84d99d2d663856dea44c6eb1a80f9599 /usr/local/zstack/apache-tomcat/logs/management-server.log
2018-03-13 22:02:58,545 TRACE [request] {} [ID: 41F5004148EA6A7A4D0DC1FF7E5120B4, Method: POST] Request from 127.0.0.1 (to /zstack/v1/vm-instances),  Headers: {"accept":["text/plain, text/plain, application/json, application/*+json, */*, */*"],"content-type":["application/json;charset\u003dutf-8"],"authorization":["OAuth 5bcb2d86e1c64c8ea2568a2d311a90ed"],"x-job-uuid":["84d99d2d663856dea44c6eb1a80f9599"],"x-web-hook":["http://0.0.0.0:5000/webhook"],"accept-charset":["big5, big5-hkscs, cesu-8, euc-jp, euc-kr, gb18030, gb2312, gbk, ibm-thai, ibm00858, ibm01140, ibm01141, ibm01142, ibm01143, ibm01144, ibm01145, ibm01146, ibm01147, ibm01148, ibm01149, ibm037, ibm1026, ibm1047, ibm273, ibm277, ibm278, ibm280, ibm284, ibm285, ibm290, ibm297, ibm420, ibm424, ibm437, ibm500, ibm775, ibm850, ibm852, ibm855, ibm857, ibm860, ibm861, ibm862, ibm863, ibm864, ibm865, ibm866, ibm868, ibm869, ibm870, ibm871, ibm918, iso-2022-cn, iso-2022-jp, iso-2022-jp-2, iso-2022-kr, iso-8859-1, iso-8859-13, iso-8859-15, iso-8859-2, iso-8859-3, iso-8859-4, iso-8859-5, iso-8859-6, iso-8859-7, iso-8859-8, iso-8859-9, jis_x0201, jis_x0212-1990, koi8-r, koi8-u, shift_jis, tis-620, us-ascii, utf-16, utf-16be, utf-16le, utf-32, utf-32be, utf-32le, utf-8, windows-1250, windows-1251, windows-1252, windows-1253, windows-1254, windows-1255, windows-1256, windows-1257, windows-1258, windows-31j, x-big5-hkscs-2001, x-big5-solaris, x-compound_text, x-euc-jp-linux, x-euc-tw, x-eucjp-open, x-ibm1006, x-ibm1025, x-ibm1046, x-ibm1097, x-ibm1098, x-ibm1112, x-ibm1122, x-ibm1123, x-ibm1124, x-ibm1166, x-ibm1364, x-ibm1381, x-ibm1383, x-ibm300, x-ibm33722, x-ibm737, x-ibm833, x-ibm834, x-ibm856, x-ibm874, x-ibm875, x-ibm921, x-ibm922, x-ibm930, x-ibm933, x-ibm935, x-ibm937, x-ibm939, x-ibm942, x-ibm942c, x-ibm943, x-ibm943c, x-ibm948, x-ibm949, x-ibm949c, x-ibm950, x-ibm964, x-ibm970, x-iscii91, x-iso-2022-cn-cns, x-iso-2022-cn-gb, x-iso-8859-11, x-jis0208, x-jisautodetect, x-johab, x-macarabic, x-maccentraleurope, x-maccroatian, x-maccyrillic, x-macdingbat, x-macgreek, x-machebrew, x-maciceland, x-macroman, x-macromania, x-macsymbol, x-macthai, x-macturkish, x-macukraine, x-ms932_0213, x-ms950-hkscs, x-ms950-hkscs-xp, x-mswin-936, x-pck, x-sjis_0213, x-utf-16le-bom, x-utf-32be-bom, x-utf-32le-bom, x-windows-50220, x-windows-50221, x-windows-874, x-windows-949, x-windows-950, x-windows-iso2022jp"],"user-agent":["Java/1.8.0_102"],"host":["localhost:8080"],"connection":["keep-alive"],"content-length":["285"]}, Body: {"params":{"name":"vm1","description":"","instanceOfferingUuid":"aee8b43d672e4b019e76471d3767e93a","imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","l3NetworkUuids":["62dc48a48f964e73b463dad1a86089df"],"dataDiskOfferingUuids":[],"systemTags":["usbRedirect::false","vmConsoleMode::vnc"]}}
2018-03-13 22:02:58,571 TRACE [CloudBusImpl2] {} [msg send]: {"org.zstack.header.vm.APICreateVmInstanceMsg":{"name":"vm1","instanceOfferingUuid":"aee8b43d672e4b019e76471d3767e93a","imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","l3NetworkUuids":["62dc48a48f964e73b463dad1a86089df"],"dataDiskOfferingUuids":[],"description":"","strategy":"InstantStart","session":{"uuid":"5bcb2d86e1c64c8ea2568a2d311a90ed"},"timeout":-1,"systemTags":["usbRedirect::false","vmConsoleMode::vnc"],"headers":{"correlationId":"84d99d2d663856dea44c6eb1a80f9599","replyTo":"zstack.message.cloudbus.d40422d825634e3392e51e3ec488e2a3","noReply":"false","schema":{},"task-context":{}},"id":"84d99d2d663856dea44c6eb1a80f9599","serviceId":"api.portal","createdTime":1520949778545}}
2018-03-13 22:02:58,571 TRACE [request] {} [ID: 41F5004148EA6A7A4D0DC1FF7E5120B4] Response to 127.0.0.1 (/zstack/v1/vm-instances), Status Code: 202, Body: {"location":"http://10.0.50.236:8080/zstack/v1/api-jobs/84d99d2d663856dea44c6eb1a80f9599"}
2018-03-13 22:02:58,578 TRACE [CloudBusImpl2] {} [msg received]: {"org.zstack.header.vm.APICreateVmInstanceMsg":{"name":"vm1","instanceOfferingUuid":"aee8b43d672e4b019e76471d3767e93a","imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","l3NetworkUuids":["62dc48a48f964e73b463dad1a86089df"],"dataDiskOfferingUuids":[],"description":"","strategy":"InstantStart","session":{"uuid":"5bcb2d86e1c64c8ea2568a2d311a90ed"},"timeout":-1,"systemTags":["usbRedirect::false","vmConsoleMode::vnc"],"headers":{"correlationId":"84d99d2d663856dea44c6eb1a80f9599","replyTo":"zstack.message.cloudbus.d40422d825634e3392e51e3ec488e2a3","noReply":"false","schema":{},"task-context":{}},"id":"84d99d2d663856dea44c6eb1a80f9599","serviceId":"api.portal","createdTime":1520949778545}}
2018-03-13 22:02:58,587 TRACE [CloudBusImpl2] {api=84d99d2d663856dea44c6eb1a80f9599} [msg send]: {"org.zstack.header.vm.APICreateVmInstanceMsg":{"name":"vm1","instanceOfferingUuid":"aee8b43d672e4b019e76471d3767e93a","imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","l3NetworkUuids":["62dc48a48f964e73b463dad1a86089df"],"type":"UserVm","dataDiskOfferingUuids":[],"description":"","defaultL3NetworkUuid":"62dc48a48f964e73b463dad1a86089df","strategy":"InstantStart","session":{"uuid":"5bcb2d86e1c64c8ea2568a2d311a90ed","accountUuid":"36c27e8ff05c4780bf6d2fa65700f22e","userUuid":"36c27e8ff05c4780bf6d2fa65700f22e","expiredDate":"Mar 14, 2018 12:02:44 AM","createDate":"Mar 13, 2018 10:02:44 PM"},"timeout":1800000,"systemTags":["usbRedirect::false","vmConsoleMode::vnc"],"headers":{"correlationId":"84d99d2d663856dea44c6eb1a80f9599","replyTo":"zstack.message.cloudbus.d40422d825634e3392e51e3ec488e2a3","noReply":"false","schema":{},"task-context":{"task-name":"org.zstack.header.vm.APICreateVmInstanceMsg","api":"84d99d2d663856dea44c6eb1a80f9599"}},"id":"84d99d2d663856dea44c6eb1a80f9599","serviceId":"vmInstance.d40422d825634e3392e51e3ec488e2a3","createdTime":1520949778545}}
2018-03-13 22:02:58,588 TRACE [CloudBusImpl2] {} [msg received]: {"org.zstack.header.vm.APICreateVmInstanceMsg":{"name":"vm1","instanceOfferingUuid":"aee8b43d672e4b019e76471d3767e93a","imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","l3NetworkUuids":["62dc48a48f964e73b463dad1a86089df"],"type":"UserVm","dataDiskOfferingUuids":[],"description":"","defaultL3NetworkUuid":"62dc48a48f964e73b463dad1a86089df","strategy":"InstantStart","session":{"uuid":"5bcb2d86e1c64c8ea2568a2d311a90ed","accountUuid":"36c27e8ff05c4780bf6d2fa65700f22e","userUuid":"36c27e8ff05c4780bf6d2fa65700f22e","expiredDate":"Mar 14, 2018 12:02:44 AM","createDate":"Mar 13, 2018 10:02:44 PM"},"timeout":1800000,"systemTags":["usbRedirect::false","vmConsoleMode::vnc"],"headers":{"correlationId":"84d99d2d663856dea44c6eb1a80f9599","replyTo":"zstack.message.cloudbus.d40422d825634e3392e51e3ec488e2a3","noReply":"false","schema":{},"task-context":{"task-name":"org.zstack.header.vm.APICreateVmInstanceMsg","api":"84d99d2d663856dea44c6eb1a80f9599"}},"id":"84d99d2d663856dea44c6eb1a80f9599","serviceId":"vmInstance.d40422d825634e3392e51e3ec488e2a3","createdTime":1520949778545}}
2018-03-13 22:02:58,609 TRACE [CloudBusImpl2] {api=84d99d2d663856dea44c6eb1a80f9599} [msg send]: {"org.zstack.header.vm.StartNewCreatedVmInstanceMsg":{"vmInstanceInventory":{"uuid":"557c0ee1abeb4cd7929675cf0a239610","name":"vm1","description":"","zoneUuid":"04d920c5dd9342f3bbf7da6a6ece3270","imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","instanceOfferingUuid":"aee8b43d672e4b019e76471d3767e93a","platform":"Linux","defaultL3NetworkUuid":"62dc48a48f964e73b463dad1a86089df","type":"UserVm","memorySize":1073741824,"cpuNum":1,"cpuSpeed":0,"allocatorStrategy":"LeastVmPreferredHostAllocatorStrategy","createDate":"Mar 13, 2018 10:02:58 PM","lastOpDate":"Mar 13, 2018 10:02:58 PM","state":"Created","internalId":9,"vmNics":[],"allVolumes":[]},"l3NetworkUuids":["62dc48a48f964e73b463dad1a86089df"],"dataDiskOfferingUuids":[],"timeout":10800000,"headers":{"correlationId":"87d14852288b422cb927ea608d9407b4","replyTo":"zstack.message.cloudbus.d40422d825634e3392e51e3ec488e2a3","noReply":"false","schema":{"vmInstanceInventory":"org.zstack.header.vm.VmInstanceInventory"},"task-context":{"task-name":"org.zstack.header.vm.APICreateVmInstanceMsg","api":"84d99d2d663856dea44c6eb1a80f9599"}},"id":"87d14852288b422cb927ea608d9407b4","serviceId":"vmInstance.d40422d825634e3392e51e3ec488e2a3","createdTime":1520949778609}}
2018-03-13 22:02:58,611 TRACE [CloudBusImpl2] {} [msg received]: {"org.zstack.header.vm.StartNewCreatedVmInstanceMsg":{"vmInstanceInventory":{"uuid":"557c0ee1abeb4cd7929675cf0a239610","name":"vm1","description":"","zoneUuid":"04d920c5dd9342f3bbf7da6a6ece3270","imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","instanceOfferingUuid":"aee8b43d672e4b019e76471d3767e93a","platform":"Linux","defaultL3NetworkUuid":"62dc48a48f964e73b463dad1a86089df","type":"UserVm","memorySize":1073741824,"cpuNum":1,"cpuSpeed":0,"allocatorStrategy":"LeastVmPreferredHostAllocatorStrategy","createDate":"Mar 13, 2018 10:02:58 PM","lastOpDate":"Mar 13, 2018 10:02:58 PM","state":"Created","internalId":9,"vmNics":[],"allVolumes":[]},"l3NetworkUuids":["62dc48a48f964e73b463dad1a86089df"],"dataDiskOfferingUuids":[],"timeout":10800000,"headers":{"correlationId":"87d14852288b422cb927ea608d9407b4","replyTo":"zstack.message.cloudbus.d40422d825634e3392e51e3ec488e2a3","noReply":"false","schema":{"vmInstanceInventory":"org.zstack.header.vm.VmInstanceInventory"},"task-context":{"task-name":"org.zstack.header.vm.APICreateVmInstanceMsg","api":"84d99d2d663856dea44c6eb1a80f9599"}},"id":"87d14852288b422cb927ea608d9407b4","serviceId":"vmInstance.d40422d825634e3392e51e3ec488e2a3","createdTime":1520949778609}}
2018-03-13 22:02:58,630 DEBUG [VmInstanceBase] {api=84d99d2d663856dea44c6eb1a80f9599} vm[uuid:557c0ee1abeb4cd7929675cf0a239610] changed state from Created to Starting in db
2018-03-13 22:02:58,631 TRACE [CloudBusImpl2] {api=84d99d2d663856dea44c6eb1a80f9599} [event publish]: {"org.zstack.core.cloudbus.CanonicalEvent":{"path":"/vm/state/change","content":{"vmUuid":"557c0ee1abeb4cd7929675cf0a239610","oldState":"Created","newState":"Starting","inventory":{"uuid":"557c0ee1abeb4cd7929675cf0a239610","name":"vm1","description":"","zoneUuid":"04d920c5dd9342f3bbf7da6a6ece3270","imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","instanceOfferingUuid":"aee8b43d672e4b019e76471d3767e93a","platform":"Linux","defaultL3NetworkUuid":"62dc48a48f964e73b463dad1a86089df","type":"UserVm","memorySize":1073741824,"cpuNum":1,"cpuSpeed":0,"allocatorStrategy":"LeastVmPreferredHostAllocatorStrategy","createDate":"Mar 13, 2018 10:02:58 PM","state":"Starting","internalId":9,"vmNics":[],"allVolumes":[]},"date":"Mar 13, 2018 10:02:58 PM"},"managementNodeId":"d40422d825634e3392e51e3ec488e2a3","headers":{"schema":{"content":"org.zstack.header.vm.VmCanonicalEvents$VmStateChangedData","content.inventory":"org.zstack.header.vm.VmInstanceInventory"},"task-context":{"task-name":"org.zstack.header.vm.APICreateVmInstanceMsg","api":"84d99d2d663856dea44c6eb1a80f9599"}},"id":"2f47da70661040f18091964eb7a48d5b","createdTime":1520949778630}}
2018-03-13 22:02:58,632 DEBUG [SchedulerFacadeImpl] {api=84d99d2d663856dea44c6eb1a80f9599} vm [uuid:557c0ee1abeb4cd7929675cf0a239610] not set any scheduler
2018-03-13 22:02:58,633 DEBUG [SimpleFlowChain] {api=84d99d2d663856dea44c6eb1a80f9599} [FlowChain(FCID_ac2d695b): create-vm-557c0ee1abeb4cd7929675cf0a239610] starts
2018-03-13 22:02:58,633 TRACE [CloudBusImpl2] {} [event received]: {"org.zstack.core.cloudbus.CanonicalEvent":{"path":"/vm/state/change","content":{"vmUuid":"557c0ee1abeb4cd7929675cf0a239610","oldState":"Created","newState":"Starting","inventory":{"uuid":"557c0ee1abeb4cd7929675cf0a239610","name":"vm1","description":"","zoneUuid":"04d920c5dd9342f3bbf7da6a6ece3270","imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","instanceOfferingUuid":"aee8b43d672e4b019e76471d3767e93a","platform":"Linux","defaultL3NetworkUuid":"62dc48a48f964e73b463dad1a86089df","type":"UserVm","memorySize":1073741824,"cpuNum":1,"cpuSpeed":0,"allocatorStrategy":"LeastVmPreferredHostAllocatorStrategy","createDate":"Mar 13, 2018 10:02:58 PM","state":"Starting","internalId":9,"vmNics":[],"allVolumes":[]},"date":"Mar 13, 2018 10:02:58 PM"},"managementNodeId":"d40422d825634e3392e51e3ec488e2a3","type":{"_name":"key.event.LOCAL.canonicalEvent"},"headers":{"schema":{"content":"org.zstack.header.vm.VmCanonicalEvents$VmStateChangedData","content.inventory":"org.zstack.header.vm.VmInstanceInventory"},"task-context":{"task-name":"org.zstack.header.vm.APICreateVmInstanceMsg","api":"84d99d2d663856dea44c6eb1a80f9599"}},"id":"2f47da70661040f18091964eb7a48d5b","createdTime":1520949778630}}
2018-03-13 22:02:58,633 TRACE [SimpleFlowChain] {api=84d99d2d663856dea44c6eb1a80f9599} execution path:
2018-03-13 22:02:58,633 DEBUG [SimpleFlowChain] {api=84d99d2d663856dea44c6eb1a80f9599} [FlowChain(FCID_ac2d695b): create-vm-557c0ee1abeb4cd7929675cf0a239610] start executing flow[VmImageSelectBackupStorageFlow.java:VmImageSelectBackupStorageFlow]
2018-03-13 22:02:58,636 DEBUG [SimpleFlowChain] {api=84d99d2d663856dea44c6eb1a80f9599} [FlowChain(FCID_ac2d695b): create-vm-557c0ee1abeb4cd7929675cf0a239610] successfully executed flow[VmImageSelectBackupStorageFlow.java:VmImageSelectBackupStorageFlow]
2018-03-13 22:02:58,636 DEBUG [SimpleFlowChain] {api=84d99d2d663856dea44c6eb1a80f9599} [FlowChain(FCID_ac2d695b): create-vm-557c0ee1abeb4cd7929675cf0a239610] start executing flow[VmAllocateHostFlow.java:VmAllocateHostFlow]
2018-03-13 22:02:58,639 TRACE [CloudBusImpl2] {api=84d99d2d663856dea44c6eb1a80f9599} [msg send]: {"org.zstack.header.allocator.DesignatedAllocateHostMsg":{"zoneUuid":"04d920c5dd9342f3bbf7da6a6ece3270","cpuCapacity":1,"memoryCapacity":1073741824,"diskSize":12682240,"allocatorStrategy":"LeastVmPreferredHostAllocatorStrategy","avoidHostUuids":[],"l3NetworkUuids":["62dc48a48f964e73b463dad1a86089df"],"vmInstance":{"uuid":"557c0ee1abeb4cd7929675cf0a239610","name":"vm1","description":"","zoneUuid":"04d920c5dd9342f3bbf7da6a6ece3270","imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","instanceOfferingUuid":"aee8b43d672e4b019e76471d3767e93a","platform":"Linux","defaultL3NetworkUuid":"62dc48a48f964e73b463dad1a86089df","type":"UserVm","memorySize":1073741824,"cpuNum":1,"cpuSpeed":0,"allocatorStrategy":"LeastVmPreferredHostAllocatorStrategy","createDate":"Mar 13, 2018 10:02:58 PM","lastOpDate":"Mar 13, 2018 10:02:58 PM","state":"Created","internalId":9,"vmNics":[],"allVolumes":[]},"image":{"uuid":"e588b839d3013f4fa1490695bc5cd5fb","name":"Image-1","description":"","state":"Enabled","status":"Ready","size":12682240,"actualSize":7995392,"md5Sum":"f0fde821df71aaec63063bef1fb0a46a231e5a3fbb37ed5671eabee7563eb3f8","url":"file:///opt/zstack-dvd/zstack-image-1.4.qcow2","mediaType":"RootVolumeTemplate","type":"zstack","platform":"Linux","format":"qcow2","system":false,"createDate":"Mar 9, 2018 8:09:53 PM","lastOpDate":"Mar 9, 2018 8:09:53 PM","backupStorageRefs":[{"id":13,"imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","backupStorageUuid":"c18ea1ae1df742449b8a1d5a3527e96e","installPath":"zstore://e588b839d3013f4fa1490695bc5cd5fb/07c5391ad7028e098762f9e3f4005e739576df33","status":"Ready","createDate":"Mar 9, 2018 8:09:53 PM","lastOpDate":"Mar 9, 2018 8:09:53 PM"}]},"vmOperation":"NewCreate","isDryRun":false,"diskOfferings":[],"allowNoL3Networks":false,"listAllHosts":false,"requiredBackupStorageUuid":"c18ea1ae1df742449b8a1d5a3527e96e","timeout":3600000,"headers":{"correlationId":"7150a9f7925c4ac9b11d818cc233cf98","replyTo":"zstack.message.cloudbus.d40422d825634e3392e51e3ec488e2a3","noReply":"false","schema":{"image":"org.zstack.header.image.ImageInventory","image.backupStorageRefs[0]":"org.zstack.header.image.ImageBackupStorageRefInventory","vmInstance":"org.zstack.header.vm.VmInstanceInventory"},"task-context":{"api":"84d99d2d663856dea44c6eb1a80f9599","task-name":"org.zstack.header.vm.APICreateVmInstanceMsg","progress-enabled":"true"}},"id":"7150a9f7925c4ac9b11d818cc233cf98","serviceId":"host.allocator.d40422d825634e3392e51e3ec488e2a3","createdTime":1520949778638}}
2018-03-13 22:02:58,642 TRACE [CloudBusImpl2] {} [msg received]: {"org.zstack.header.allocator.DesignatedAllocateHostMsg":{"zoneUuid":"04d920c5dd9342f3bbf7da6a6ece3270","cpuCapacity":1,"memoryCapacity":1073741824,"diskSize":12682240,"allocatorStrategy":"LeastVmPreferredHostAllocatorStrategy","avoidHostUuids":[],"l3NetworkUuids":["62dc48a48f964e73b463dad1a86089df"],"vmInstance":{"uuid":"557c0ee1abeb4cd7929675cf0a239610","name":"vm1","description":"","zoneUuid":"04d920c5dd9342f3bbf7da6a6ece3270","imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","instanceOfferingUuid":"aee8b43d672e4b019e76471d3767e93a","platform":"Linux","defaultL3NetworkUuid":"62dc48a48f964e73b463dad1a86089df","type":"UserVm","memorySize":1073741824,"cpuNum":1,"cpuSpeed":0,"allocatorStrategy":"LeastVmPreferredHostAllocatorStrategy","createDate":"Mar 13, 2018 10:02:58 PM","lastOpDate":"Mar 13, 2018 10:02:58 PM","state":"Created","internalId":9,"vmNics":[],"allVolumes":[]},"image":{"uuid":"e588b839d3013f4fa1490695bc5cd5fb","name":"Image-1","description":"","state":"Enabled","status":"Ready","size":12682240,"actualSize":7995392,"md5Sum":"f0fde821df71aaec63063bef1fb0a46a231e5a3fbb37ed5671eabee7563eb3f8","url":"file:///opt/zstack-dvd/zstack-image-1.4.qcow2","mediaType":"RootVolumeTemplate","type":"zstack","platform":"Linux","format":"qcow2","system":false,"createDate":"Mar 9, 2018 8:09:53 PM","lastOpDate":"Mar 9, 2018 8:09:53 PM","backupStorageRefs":[{"id":13,"imageUuid":"e588b839d3013f4fa1490695bc5cd5fb","backupStorageUuid":"c18ea1ae1df742449b8a1d5a3527e96e","installPath":"zstore://e588b839d3013f4fa1490695bc5cd5fb/07c5391ad7028e098762f9e3f4005e739576df33","status":"Ready","createDate":"Mar 9, 2018 8:09:53 PM","lastOpDate":"Mar 9, 2018 8:09:53 PM"}]},"vmOperation":"NewCreate","isDryRun":false,"diskOfferings":[],"allowNoL3Networks":false,"listAllHosts":false,"requiredBackupStorageUuid":"c18ea1ae1df742449b8a1d5a3527e96e","timeout":3600000,"headers":{"correlationId":"7150a9f7925c4ac9b11d818cc233cf98","replyTo":"zstack.message.cloudbus.d40422d825634e3392e51e3ec488e2a3","noReply":"false","schema"
篇幅问题，这里不再多贴相关的日志

这样，我们就可以得知一个API到底在MN中做了什么事了。在/var/log/zstack还有agent相关的日志，有兴趣的读者可以自行搜索。

使用Test Case来定位问题

在读本节前，希望读者能够读过以下文章：

小谈自动化测试：从ZStack Integration Test谈起
ZStack的IntergrationTest
我们先将GitHub上的ZStack Clone到自己的机器上来，如图：

并执行mvn compile，这里理应编译成功：
ZStack源码剖析之二次开发——Debug的常用技巧 - 图4

好，我们切换到test目录下：

[root@10-0-86-20 zstack-openresource]# cd test
[root@10-0-86-20 test]# ls
pom.xml  src  target  zstack-integration-test-result
[root@10-0-86-20 test]#

使用mvn test -Dtest=YOUR_TEST_CASE_NAME来跑相应的case，如mvn test -Dtest=VmGCCase。

如果没什么问题，一般是成功的：
ZStack源码剖析之二次开发——Debug的常用技巧 - 图5

小Tips：如果你仅仅修改了groovy的case，那是不需要编译的。但如果你修改了一行Java代码，并想使其生效，请记得编译。

挂断点

在挂断点之前，请确定自己的iptables开放了相应的端口。

真实环境

为了方便起见，我们先在家目录的bashrc中添加如下命令：

alias opendebug="zstack-ctl setenv CATALINA_OPTS='-Xdebug -Xrunjdwp:transport=dt_socket,server=y,suspend=y,address=5005 -Xnoagent -Djava.compiler=NONE'"
alias closedebug="zstack-ctl unsetenv CATALINA_OPTS"
alias mvndebug='mvn -Dmaven.surefire.debug="-Xdebug -Xrunjdwp:transport=dt_socket,server=y,suspend=y,address=8000 -Xnoagent -Djava.compiler=NONE"'

然后关闭管理节点，opendebug，再开启管理节点。这时可以使用IDE配置remote debug连上去，接下来就可以debug了。debug之后记得使用closedebug关掉。

Test Case

在测试目录下，参考以下命令：

mvn -Dmaven.surefire.debug -Dtest=YOUR_TEST_CASE test

这样，它会等待你的断点挂上去后再跑里面的测试。