A lot of the Orchestrator plug-ins use the Apache HTTP client to communicate with the target hosts. You may want to log the HTTP communications for many purposes:
- Understanding how vCO does the API calls
- Troubleshoot a problem with a target host
- Re-engineering an existing call with capturing it, changing it as you like and use it via the REST or SOAP plug-in
- Brag you have found an “Onyx” like functionality for most Orchestrated products
This article will guide you on how to log these calls to a file.
In a previous article I explained how the Orchestrator logs work and how to update the log4j configuration file.
Orchestrator leverages a powerful logging framework named log4j.
This framework can log the activity of the Apache HTTP client as documented here.
Log4j has two configuration files. A log4j.properties file and in the case of orchestrator is using a log4j.xml file. The Apache documentation only covers the first one but it is not hard to adapt it to the xml one with understanding the basics of log4j appenders and loggers.
The following modification is not supported in production. It will considerably slow down your Orchestrator server since it will log all the Apache HTTP traffic, all the headers and other information to a file. It is recommended to be used on a test / dev environment only. Also updating the log configuration from the Orchestrator web based configuration will overwrite the changes you will apply to log4j.
First ssh in your Orchestrator appliance (or open RDP on your Windows host).Locate the log4j.xml file (in /etc/vco/app-server in the appliance)
Edit log4j.xml (I use VI on the appliance - you may use another editor or transfer the file on your host, modify it and send it back)
Insert the highlighted lines.
1
2
3
4
5
6
7
8
9
10
11
12
13
14
|
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="true" reset="false" threshold="null">
<appender name="rolling" class="org.apache.log4j.DailyRollingFileAppender">
<param name="File" value="${catalina.base}/logs/http.log"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d [%t] %-5p %c:%L - %m%n"/>
</layout>
</appender>
<logger name="org.apache.http">
<level value="DEBUG"/>
<appender-ref ref="rolling"/>
</logger>
|
The appender define a new log target and the log format. It is going to be the file named http.log that will be located in the /var/log/vco/app-server in the appliance.
The logger defines what is logged. Here we log all Apache HTTP log.
Save and quit the file.
You can now watch all the HTTP traffic.
To do this on the appliance you can use tail -f /var/log/vco/app-server/http.log On windows you can use baretail
You may notice traffic being logged right away for the vCenter and SSO Identity server SOAP connections.
Now let’s say I want to know what request the NSX plug-in is doing to display its datacenter objects in the inventory. I have just to unfold the Datacenters object and watch the logs.
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
|
2015-04-15 22:00:10,426 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.headers:124 - http-outgoing-2 >> GET /api/2.0/services/usermgmt/scopingobjects HTTP/1.1
2015-04-15 22:00:10,427 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.headers:127 - http-outgoing-2 >> Accept: application/xml, text/xml, application/*+xml
2015-04-15 22:00:10,427 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.headers:127 - http-outgoing-2 >> Host: home.cdecanini.fr
2015-04-15 22:00:10,427 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.headers:127 - http-outgoing-2 >> Connection: Keep-Alive
2015-04-15 22:00:10,428 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.headers:127 - http-outgoing-2 >> User-Agent: Apache-HttpClient/4.3.3 (java 1.5)
2015-04-15 22:00:10,428 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.headers:127 - http-outgoing-2 >> Accept-Encoding: gzip,deflate
2015-04-15 22:00:10,429 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.headers:127 - http-outgoing-2 >> Authorization: Basic YSWERCtRaEWT
2015-04-15 22:00:10,429 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 >> "GET /api/2.0/services/usermgmt/scopingobjects HTTP/1.1[\r][\n]"
2015-04-15 22:00:10,429 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 >> "Accept: application/xml, text/xml, application/*+xml[\r][\n]"
2015-04-15 22:00:10,429 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 >> "Host: home.cdecanini.fr[\r][\n]"
2015-04-15 22:00:10,430 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 >> "Connection: Keep-Alive[\r][\n]"
2015-04-15 22:00:10,430 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 >> "User-Agent: Apache-HttpClient/4.3.3 (java 1.5)[\r][\n]"
2015-04-15 22:00:10,430 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 >> "Accept-Encoding: gzip,deflate[\r][\n]"
2015-04-15 22:00:10,431 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 >> "Authorization: Basic YSWERCtRaEWT[\r][\n]"
2015-04-15 22:00:10,432 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 >> "[\r][\n]"
2015-04-15 22:00:10,898 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "HTTP/1.1 200 OK[\r][\n]"
2015-04-15 22:00:10,899 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "Cache-Control: private[\r][\n]"
2015-04-15 22:00:10,899 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "Expires: Thu, 01 Jan 1970 00:00:00 GMT[\r][\n]"
2015-04-15 22:00:10,900 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "Server: [\r][\n]"
2015-04-15 22:00:10,900 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "Cache-Control: no-cache[\r][\n]"
2015-04-15 22:00:10,900 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "Set-Cookie: JSESSIONID=32B7A5CBF7E338498FCE36ABA5DD708B; Path=/[\r][\n]"
2015-04-15 22:00:10,901 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "Date: Wed, 15 Apr 2015 20:00:09 GMT[\r][\n]"
2015-04-15 22:00:10,901 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "Content-Type: application/xml[\r][\n]"
2015-04-15 22:00:10,901 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "Transfer-Encoding: chunked[\r][\n]"
2015-04-15 22:00:10,901 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "[\r][\n]"
2015-04-15 22:00:10,902 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "fbe[\r][\n]"
2015-04-15 22:00:10,902 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "<?xml version="1.0" encoding="UTF-8"?>[\n]"
2015-04-15 22:00:10,902 [http-bio-172.16.3.131-8281-exec-3] DEBUG org.apache.http.wire:72 - http-outgoing-2 << "<scopingObjects><object><objectId>network-39</objectId><objectTypeName>Network</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>33</revision><type><typeName>Network</typeName></type><name>VM Network</name><scope><id>datacenter-21</id><objectTypeName>Datacenter</objectTypeName><name>Homelab</name></scope><clientHandle></clientHandle><extendedAttributes/></object><object><objectId>edge-16</objectId><objectTypeName>Edge</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>4</revision><type><typeName>Edge</typeName></type><name>Christophe</name><description></description><clientHandle></clientHandle><extendedAttributes/></object><object><objectId>virtualwire-4</objectId><objectTypeName>VirtualWire</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>49</revision><type><typeName>VirtualWire</typeName></type><name>LS-TransitNetwork</name><description></description><clientHandle></clientHandle><extendedAttributes/></object><object><objectId>virtualwire-3</objectId><objectTypeName>VirtualWire</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>49</revision><type><typeName>VirtualWire</typeName></type><name>LS-DBTier</name><description></description><clientHandle></clientHandle><extendedAttributes/></object><object><objectId>virtualwire-2</objectId><objectTypeName>VirtualWire</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>49</revision><type><typeName>VirtualWire</typeName></type><name>LS-AppTier</name><description></description><clientHandle></clientHandle><extendedAttributes/></object><object><objectId>dvportgroup-58</objectId><objectTypeName>DistributedVirtualPortgroup</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>8</revision><type><typeName>DistributedVirtualPortgroup</typeName></type><name>dvPortGroup-Mgmt</name><scope><id>datacenter-21</id><objectTypeName>Datacenter</objectTypeName><name>Homelab</name></scope><clientHandle></clientHandle><extendedAttributes/></object><object><objectId>virtualwire-1</objectId><objectTypeName>VirtualWire</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>50</revision><type><typeName>VirtualWire</typeName></type><name>LS-WebTier</name><description></description><clientHandle></clientHandle><extendedAttributes/></object><object><objectId>edge-1</objectId><objectTypeName>Edge</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>43</revision><type><typeName>Edge</typeName></type><name>LDR-Lab</name><clientHandle></clientHandle><extendedAttributes/></object><object><objectId>edge-2</objectId><objectTypeName>Edge</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>220</revision><type><typeName>Edge</typeName></type><name>ESG-Lab</name><clientHandle></clientHandle><extendedAttributes/></object><object><objectId>datacenter-21</objectId><objectTypeName>Datacenter</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>5</revision><type><typeName>Datacenter</typeName></type><name>Homelab</name><scope><id>group-d1</id><objectTypeName>Folder</objectTypeName><name>Datacenters</name></scope><clientHandle></clientHandle><extendedAttributes/></object><object><objectId>network-131</objectId><objectTypeName>Network</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>12</revision><type><typeName>Network</typeName></type><name>none</name><scope><id>datacenter-21</id><objectTypeName>Datacenter</objectTypeName><name>Homelab</name></scope><clientHandle></clientHandle><extendedAttributes/></object><object><objectId>globalroot-0</objectId><objectTypeName>GlobalRoot</objectTypeName><vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid><revision>21</revision><type><typeName>GlobalRoot</typeName></type><name>Global</name><clientHandle></clientHandle><extendedAttributes/></object></scopingObjects>[\r][\n]"
|
The first highlighted line is the HTTP method and URL.
The second one the headers that were passed : XML is sent and recieved to from / NSX
Then the authorization type : basic with my encrypted password.
These are all the headers log. The next logs are the wire logs. Any HTTP traffic between Orchastrator Apache library and the remote system will appear here.
A line of interest is the 200 Status code meaning the request was successful and the response on the last line including a long XML string I have formatted below:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
|
<scopingObjects>
<object>
<objectId>network-39</objectId>
<objectTypeName>Network</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>33</revision>
<type>
<typeName>Network</typeName>
</type>
<name>VM Network</name>
<scope>
<id>datacenter-21</id>
<objectTypeName>Datacenter</objectTypeName>
<name>Homelab</name>
</scope>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
<object>
<objectId>edge-16</objectId>
<objectTypeName>Edge</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>4</revision>
<type>
<typeName>Edge</typeName>
</type>
<name>Christophe</name>
<description></description>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
<object>
<objectId>virtualwire-4</objectId>
<objectTypeName>VirtualWire</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>49</revision>
<type>
<typeName>VirtualWire</typeName>
</type>
<name>LS-TransitNetwork</name>
<description></description>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
<object>
<objectId>virtualwire-3</objectId>
<objectTypeName>VirtualWire</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>49</revision>
<type>
<typeName>VirtualWire</typeName>
</type>
<name>LS-DBTier</name>
<description></description>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
<object>
<objectId>virtualwire-2</objectId>
<objectTypeName>VirtualWire</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>49</revision>
<type>
<typeName>VirtualWire</typeName>
</type>
<name>LS-AppTier</name>
<description></description>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
<object>
<objectId>dvportgroup-58</objectId>
<objectTypeName>DistributedVirtualPortgroup</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>8</revision>
<type>
<typeName>DistributedVirtualPortgroup</typeName>
</type>
<name>dvPortGroup-Mgmt</name>
<scope>
<id>datacenter-21</id>
<objectTypeName>Datacenter</objectTypeName>
<name>Homelab</name>
</scope>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
<object>
<objectId>virtualwire-1</objectId>
<objectTypeName>VirtualWire</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>50</revision>
<type>
<typeName>VirtualWire</typeName>
</type>
<name>LS-WebTier</name>
<description></description>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
<object>
<objectId>edge-1</objectId>
<objectTypeName>Edge</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>43</revision>
<type>
<typeName>Edge</typeName>
</type>
<name>LDR-Lab</name>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
<object>
<objectId>edge-2</objectId>
<objectTypeName>Edge</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>220</revision>
<type>
<typeName>Edge</typeName>
</type>
<name>ESG-Lab</name>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
<object>
<objectId>datacenter-21</objectId>
<objectTypeName>Datacenter</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>5</revision>
<type>
<typeName>Datacenter</typeName>
</type>
<name>Homelab</name>
<scope>
<id>group-d1</id>
<objectTypeName>Folder</objectTypeName>
<name>Datacenters</name>
</scope>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
<object>
<objectId>network-131</objectId>
<objectTypeName>Network</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>12</revision>
<type>
<typeName>Network</typeName>
</type>
<name>none</name>
<scope>
<id>datacenter-21</id>
<objectTypeName>Datacenter</objectTypeName>
<name>Homelab</name>
</scope>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
<object>
<objectId>globalroot-0</objectId>
<objectTypeName>GlobalRoot</objectTypeName>
<vsmUuid>42022E92-A37C-259D-962A-947649CEDBA7</vsmUuid>
<revision>21</revision>
<type>
<typeName>GlobalRoot</typeName>
</type>
<name>Global</name>
<clientHandle></clientHandle>
<extendedAttributes/>
</object>
</scopingObjects>
|
The highlighted text shows the information that is used to be displayed in the inventory tree : The homelab datacenter. The plug-in had to pull all this XML just to get this piece of information.
With this log I can now do a lot more. For example the NSX plug-in has several workflows applying changes on NSX. I can capture the traffic and include similar operations in my NSX Dynamic Type plug-in or slightly different ones with checking the API documentation and changing some of the parameters.
I can also do the same thing with the vCAC plug-in to get a good understanding on how the REST API is leveraged. I could push it to do some custom SOAP calls to vCenter if I really wanted. There are also several third parties plug-ins to control storage, network, IPAM, CMDB, ticketing systems that I could learn just by running their workflows and possibly extend creating my own HTTP REST or SOAP requests. I can also understand how the communication to the identity appliance is working.
The possibilities are endless and the knowledge to get from using this logging enormous.
