我试图弄清楚为什么我的测试应用程序在负载测试 Azure 表存储插入时使用 100%。
在 100% cpu 下，我在一个小实例上获得大约 230 次插入/秒。我不确定这个数字是否可以，但即便如此我认为 cpu 使用率太高了。
我的应用程序基本上就是这样做的：
function insert(id)
{
var task={ PartitionKey: id, RowKey: "1", Description: "bench bench bench" };
pending.inc();
var ts=azure.createTableService();
ts.insertEntity("bench", task, function (err)
{
pending.dec();
if (err) return console.log("error", err);
reqStats.mark();
});
}
如果挂起低于 250，则添加另外 250 个插入（对于此测试，没有记录错误）。
我用 --prof 运行了节点，但我不确定如何解释输出：
Code move event for unknown code: 0x3fe5b8c0
Statistical profiling result from v8.log, (7703 ticks, 1 unaccounted, 0 excluded).
[Unknown]:
ticks total nonlib name
1 0.0%
[Shared libraries]:
ticks total nonlib name
4003 52.0% 0.0% D:\Windows\SYSTEM32\ntdll.dll
3347 43.5% 0.0% F:\approot\node.exe
47 0.6% 0.0% D:\Windows\SYSTEM32\KERNEL32.DLL
44 0.6% 0.0% D:\Windows\SYSTEM32\KERNELBASE.dll
3 0.0% 0.0% D:\Windows\system32\mswsock.dll
1 0.0% 0.0% D:\Windows\SYSTEM32\WS2_32.dll
[JavaScript]:
ticks total nonlib name
14 0.2% 5.4% Stub: CEntryStub
12 0.2% 4.7% Function: write F:\approot\node_modules\azure\node_modules\xml2js\node_modules\sax\lib\sax.js:883
10 0.1% 3.9% Function: EventEmitter.addListener events.js:138
7 0.1% 2.7% KeyedLoadIC: A keyed load IC from the snapshot
7 0.1% 2.7% Function: ~Request.init F:\approot\node_modules\azure\node_modules\request\main.js:108
7 0.1% 2.7% Function: ~ClientRequest http.js:1254
6 0.1% 2.3% Stub: StringAddStub
5 0.1% 1.9% Stub: RegExpExecStub
5 0.1% 1.9% LazyCompile: *urlParse url.js:92
5 0.1% 1.9% LazyCompile: *match native string.js:182
5 0.1% 1.9% Function: ~XMLFragment.toString F:\approot\node_modules\azure\node_modules\xmlbuilder\lib\XMLFragment.js:287
4 0.1% 1.6% LazyCompile: stringify native json.js:307
4 0.1% 1.6% LazyCompile: *formatProperty util.js:338
4 0.1% 1.6% LazyCompile: *formatPrimitive util.js:289
4 0.1% 1.6% LazyCompile: *EventEmitter.emit events.js:54
4 0.1% 1.6% Function: ~store http.js:571
4 0.1% 1.6% CallMegamorphic: args_count: 1
3 0.0% 1.2% Stub: SubStringStub
3 0.0% 1.2% LazyCompile: IN native runtime.js:354
3 0.0% 1.2% LazyCompile: APPLY_PREPARE native runtime.js:438
3 0.0% 1.2% LazyCompile: *GetOwnProperty native v8natives.js:637
3 0.0% 1.2% LazyCompile: *FromPropertyDescriptor native v8natives.js:373
3 0.0% 1.2% LazyCompile: *Encode native uri.js:179
3 0.0% 1.2% LazyCompile: *BuildResultFromMatchInfo native regexp.js:130
3 0.0% 1.2% Function: ~StorageServiceClient._buildRequestOptions F:\approot\node_modules\azure\lib\services\core\storageserviceclient.js:192
3 0.0% 1.2% Function: ~AtomHandler._writeAtomEntryValue F:\approot\node_modules\azure\lib\util\atomhandler.js:205
3 0.0% 1.2% Function: formatValue util.js:189
3 0.0% 1.2% CallMegamorphic: args_count: 3
3 0.0% 1.2% Builtin: A builtin from the snapshot {2}
2 0.0% 0.8% Stub: KeyedStoreElementStub {1}
2 0.0% 0.8% Stub: FastNewClosureStub
2 0.0% 0.8% Stub: CompareStub
2 0.0% 0.8% RegExp: ^"([a-zA-Z_][a-zA-Z_0-9]*)"$
2 0.0% 0.8% RegExp: Content-Length
2 0.0% 0.8% LazyCompile: join native array.js:410
2 0.0% 0.8% LazyCompile: ToString native runtime.js:550
2 0.0% 0.8% LazyCompile: ConvertToString native array.js:195
2 0.0% 0.8% LazyCompile: *toLowerCase native string.js:739
2 0.0% 0.8% LazyCompile: *socketOnData http.js:1480
2 0.0% 0.8% LazyCompile: *slice native string.js:510
2 0.0% 0.8% LazyCompile: *indexOf native string.js:118
2 0.0% 0.8% LazyCompile: *exports.stringStartsWith F:\approot\node_modules\azure\lib\util\util.js:131
2 0.0% 0.8% LazyCompile: *XMLFragment F:\approot\node_modules\azure\node_modules\xmlbuilder\lib\XMLFragment.js:8
2 0.0% 0.8% LazyCompile: *IsDataDescriptor native v8natives.js:354
2 0.0% 0.8% LazyCompile: *EventEmitter events.js:25
2 0.0% 0.8% Function: ~XMLFragment.element F:\approot\node_modules\azure\node_modules\xmlbuilder\lib\XMLFragment.js:18
2 0.0% 0.8% Function: ~Request.init F:\approot\node_modules\azure\node_modules\request\main.js:362
2 0.0% 0.8% Function: ~OutgoingMessage.end http.js:794
2 0.0% 0.8% Function: ~Logger.log F:\approot\node_modules\azure\lib\diagnostics\logger.js:68
2 0.0% 0.8% Builtin: A builtin from the snapshot {3}
2 0.0% 0.8% Builtin: A builtin from the snapshot {1}
1 0.0% 0.4% Stub: ToBooleanStub_String
1 0.0% 0.4% Stub: ToBooleanStub
1 0.0% 0.4% Stub: StoreArrayLiteralElementStub
1 0.0% 0.4% Stub: RecordWriteStub {1}
1 0.0% 0.4% Stub: RecordWriteStub
1 0.0% 0.4% Stub: NumberToStringStub
1 0.0% 0.4% Stub: KeyedStoreElementStub
1 0.0% 0.4% Stub: JSEntryStub
1 0.0% 0.4% Stub: InstanceofStub
1 0.0% 0.4% Stub: CallFunctionStub_Args0
1 0.0% 0.4% Stub: CallConstructStub_Recording
1 0.0% 0.4% Stub: CallConstructStub
1 0.0% 0.4% Stub: BinaryOpStub_ADD_OverwriteRight_BothStrings
1 0.0% 0.4% Stub: BinaryOpStub_ADD_OverwriteLeft_SMI
1 0.0% 0.4% Stub: BinaryOpStub_ADD_OverwriteLeft_BothStrings
1 0.0% 0.4% RegExp: [^A-Za-z0-9_-]
1 0.0% 0.4% RegExp: Date
1 0.0% 0.4% RegExp: (^"|"$)
1 0.0% 0.4% LazyCompile: toString native v8natives.js:223
1 0.0% 0.4% LazyCompile: Join native array.js:119
1 0.0% 0.4% LazyCompile: FILTER_KEY native runtime.js:398
1 0.0% 0.4% LazyCompile: *test native regexp.js:220
1 0.0% 0.4% LazyCompile: *startup.processNextTick.process.nextTick node.js:254
1 0.0% 0.4% LazyCompile: *startup.processNextTick.process._tickCallback node.js:233
1 0.0% 0.4% LazyCompile: *split native string.js:554
1 0.0% 0.4% LazyCompile: *replace native string.js:221
1 0.0% 0.4% LazyCompile: *onread net.js:377
1 0.0% 0.4% LazyCompile: *map native array.js:1190
1 0.0% 0.4% LazyCompile: *isRegExp util.js:427
1 0.0% 0.4% LazyCompile: *isArray native array.js:1463
1 0.0% 0.4% LazyCompile: *indexOf native array.js:1236
1 0.0% 0.4% LazyCompile: *freeParser http.js:1385
1 0.0% 0.4% LazyCompile: *forEach native array.js:1062
1 0.0% 0.4% LazyCompile: *copy F:\approot\node_modules\azure\node_modules\request\main.js:72
1 0.0% 0.4% LazyCompile: *afterConnect net.js:719
1 0.0% 0.4% LazyCompile: *insert F:\approot\server.js:1949
1 0.0% 0.4% LazyCompile: *UseSparseVariant native array.js:111
1 0.0% 0.4% LazyCompile: *TwoDigitString native date.js:213
1 0.0% 0.4% LazyCompile: *TableService.insertEntity F:\approot\node_modules\azure\lib\services\table\tableservice.js:500
1 0.0% 0.4% LazyCompile: *StringSplitOnRegExp native string.js:591
1 0.0% 0.4% LazyCompile: *Socket._write net.js:515
1 0.0% 0.4% LazyCompile: *Socket net.js:131
1 0.0% 0.4% LazyCompile: *ServiceClient.performRequest F:\approot\node_modules\azure\lib\services\core\serviceclient.js:161
1 0.0% 0.4% LazyCompile: *Request.end F:\approot\node_modules\azure\node_modules\request\main.js:952
1 0.0% 0.4% LazyCompile: *PropertyDescriptor native v8natives.js:482
1 0.0% 0.4% LazyCompile: *OutgoingMessage.write http.js:731
1 0.0% 0.4% LazyCompile: *CookieJar.get F:\approot\node_modules\azure\node_modules\request\vendor\cookie\jar.js:46
1 0.0% 0.4% LazyCompile: *AtomHandler._convertToAtomPropertyText F:\approot\node_modules\azure\lib\util\atomhandler.js:279
1 0.0% 0.4% LazyCompile: *Agent.addRequest http.js:1170
1 0.0% 0.4% LazyCompile: *$Array.configurable_ native v8natives.js:540
1 0.0% 0.4% Function: ~onanswer dns.js:116
1 0.0% 0.4% Function: ~forEach F:\approot\node_modules\lodash\dist\lodash.js:2325
1 0.0% 0.4% Function: ~exports.Parser.Parser.reset.saxParser.onopentag F:\approot\node_modules\azure\node_modules\xml2js\lib\xml2js.js:108
1 0.0% 0.4% Function: ~exports.Parser.Parser.reset.saxParser.onclosetag F:\approot\node_modules\azure\node_modules\xml2js\lib\xml2js.js:135
1 0.0% 0.4% Function: ~asyncCallback dns.js:65
1 0.0% 0.4% Function: ~WebResource.getQueryStringValues F:\approot\node_modules\azure\lib\http\webresource.js:204
1 0.0% 0.4% Function: ~WebResource.getQueryString F:\approot\node_modules\azure\lib\http\webresource.js:223
1 0.0% 0.4% Function: ~Socket.connect net.js:687
1 0.0% 0.4% Function: ~Socket.connect net.js:651
1 0.0% 0.4% Function: ~ServiceClient._performRequest.self._buildRequestOptions.requestStream.end F:\approot\node_modules\azure\lib\services\core\serviceclient.js:239
1 0.0% 0.4% Function: ~ServiceClient._performRequest.self._buildRequestOptions.operation F:\approot\node_modules\azure\lib\services\core\serviceclient.js:216
1 0.0% 0.4% Function: ~Request.write F:\approot\node_modules\azure\node_modules\request\main.js:948
1 0.0% 0.4% Function: ~Request.start.self.req.self.httpModule.request.response.on.self._ended F:\approot\node_modules\azure\node_modules\request\main.js:617
1 0.0% 0.4% Function: ~Request F:\approot\node_modules\azure\node_modules\request\main.js:84
1 0.0% 0.4% Function: ~EventEmitter.addListener events.js:138
1 0.0% 0.4% Function: ~AtomHandler.serialize F:\approot\node_modules\azure\lib\util\atomhandler.js:174
1 0.0% 0.4% CallNormal: args_count: 0
1 0.0% 0.4% CallMegamorphic: args_count: 2
1 0.0% 0.4% Builtin: A builtin from the snapshot {5}
1 0.0% 0.4% Builtin: A builtin from the snapshot {4}
1 0.0% 0.4% Builtin: A builtin from the snapshot
[C++]:
ticks total nonlib name
[GC]:
ticks total nonlib name
268 3.5%
[Bottom up (heavy) profile]:
Note: percentage shows a share of a particular caller in the total
amount of its parent calls.
Callers occupying less than 2.0% are not shown.
ticks parent name
4003 52.0% D:\Windows\SYSTEM32\ntdll.dll
97 2.4% LazyCompile: *connect net.js:614
97 100.0% Function: ~Socket.connect net.js:687
97 100.0% Function: ~asyncCallback dns.js:65
97 100.0% Function: ~onanswer dns.js:116
3347 43.5% F:\approot\node.exe
533 15.9% Function: exports.Parser.Parser.parseString F:\approot\node_modules\azure\node_modules\xml2js\lib\xml2js.js:205
533 100.0% Function: ~__bind F:\approot\node_modules\azure\node_modules\xml2js\lib\xml2js.js:6
533 100.0% Function: ServiceClient._parseResponse F:\approot\node_modules\azure\lib\services\core\serviceclient.js:499
516 96.8% LazyCompile: *ServiceClient._processResponse F:\approot\node_modules\azure\lib\services\core\serviceclient.js:307
516 100.0% Function: ~ServiceClient._performRequest.self._buildRequestOptions.processResponseCallback F:\approot\node_modules\azure\lib\services\core\serviceclient.js:219
17 3.2% Function: ~ServiceClient._processResponse F:\approot\node_modules\azure\lib\services\core\serviceclient.js:307
17 100.0% Function: ~ServiceClient._performRequest.self._buildRequestOptions.processResponseCallback F:\approot\node_modules\azure\lib\services\core\serviceclient.js:219
258 7.7% LazyCompile: *socketOnData http.js:1480
172 66.7% LazyCompile: *onread net.js:377
7 2.7% Function: ~onread net.js:377
196 5.9% LazyCompile: *is F:\approot\node_modules\azure\node_modules\xml2js\node_modules\sax\lib\sax.js:275
196 100.0% Function: write F:\approot\node_modules\azure\node_modules\xml2js\node_modules\sax\lib\sax.js:883
196 100.0% Function: exports.Parser.Parser.parseString F:\approot\node_modules\azure\node_modules\xml2js\lib\xml2js.js:205
196 100.0% Function: ~__bind F:\approot\node_modules\azure\node_modules\xml2js\lib\xml2js.js:6
196 100.0% Function: ServiceClient._parseResponse F:\approot\node_modules\azure\lib\services\core\serviceclient.js:499
161 4.8% Function: write F:\approot\node_modules\azure\node_modules\xml2js\node_modules\sax\lib\sax.js:883
161 100.0% Function: exports.Parser.Parser.parseString F:\approot\node_modules\azure\node_modules\xml2js\lib\xml2js.js:205
161 100.0% Function: ~__bind F:\approot\node_modules\azure\node_modules\xml2js\lib\xml2js.js:6
161 100.0% Function: ServiceClient._parseResponse F:\approot\node_modules\azure\lib\services\core\serviceclient.js:499
156 96.9% LazyCompile: *ServiceClient._processResponse F:\approot\node_modules\azure\lib\services\core\serviceclient.js:307
5 3.1% Function: ~ServiceClient._processResponse F:\approot\node_modules\azure\lib\services\core\serviceclient.js:307
90 2.7% Function: ~ClientRequest.onSocket http.js:1617
86 95.6% LazyCompile: *startup.processNextTick.process._tickCallback node.js:233
4 4.4% Function: ~startup.processNextTick.process._tickCallback node.js:233
85 2.5% LazyCompile: *EventEmitter.emit events.js:54
29 34.1% Function: <anonymous> F:\approot\node_modules\azure\node_modules\request\main.js:636
29 100.0% LazyCompile: *EventEmitter.emit events.js:54
29 100.0% Function: ~Request.start.self.req.self.httpModule.request.buffer F:\approot\node_modules\azure\node_modules\request\main.js:621
29 100.0% LazyCompile: *EventEmitter.emit events.js:54
23 27.1% Function: ~Socket._destroy.destroyed net.js:357
23 100.0% LazyCompile: *startup.processNextTick.process._tickCallback node.js:233
17 20.0% Function: EventEmitter.addListener events.js:138
7 41.2% Function: ~<anonymous> F:\approot\node_modules\azure\node_modules\request\main.js:519
7 100.0% Function: ~g events.js:190
7 100.0% LazyCompile: *EventEmitter.emit events.js:54
5 29.4% Function: ~Request.start F:\approot\node_modules\azure\node_modules\request\main.js:503
5 100.0% Function: ~Request.write F:\approot\node_modules\azure\node_modules\request\main.js:948
5 100.0% Function: ~Request.init F:\approot\node_modules\azure\node_modules\request\main.js:362
2 11.8% LazyCompile: *Agent.createSocket http.js:1189
2 100.0% LazyCompile: *Agent.addRequest http.js:1170
2 100.0% Function: ~ClientRequest http.js:1254
1 5.9% LazyCompile: *parserOnIncomingClient http.js:1531
1 100.0% LazyCompile: *socketOnData http.js:1480
1 5.9% LazyCompile: *EventEmitter.once events.js:184
1 100.0% Function: ~<anonymous> F:\approot\node_modules\azure\node_modules\request\main.js:519
1 100.0% Function: ~g events.js:190
1 5.9% Function: ~Request.init F:\approot\node_modules\azure\node_modules\request\main.js:108
1 100.0% Function: ~Request F:\approot\node_modules\azure\node_modules\request\main.js:84
1 100.0% LazyCompile: *request F:\approot\node_modules\azure\node_modules\request\main.js:983
4 4.7% LazyCompile: *parserOnMessageComplete http.js:127
4 100.0% LazyCompile: *socketOnData http.js:1480
3 75.0% LazyCompile: *onread net.js:377
3 3.5% LazyCompile: *responseOnEnd http.js:1591
3 100.0% LazyCompile: *EventEmitter.emit events.js:54
2 66.7% LazyCompile: *IncomingMessage._emitEnd http.js:364
2 100.0% Function: ~parserOnMessageComplete http.js:127
1 33.3% LazyCompile: *parserOnMessageComplete http.js:127
1 100.0% LazyCompile: *socketOnData http.js:1480
2 2.4% Function: ~Request.start.self.req.self.httpModule.request.buffer F:\approot\node_modules\azure\node_modules\request\main.js:621
2 100.0% LazyCompile: *EventEmitter.emit events.js:54
1 50.0% Function: ~parserOnMessageComplete http.js:127
1 100.0% LazyCompile: *socketOnData http.js:1480
1 50.0% Function: ~IncomingMessage._emitEnd http.js:364
1 100.0% Function: ~parserOnMessageComplete http.js:127
2 2.4% Function: ~Agent.createSocket.onFree http.js:1209
2 100.0% LazyCompile: *EventEmitter.emit events.js:54
2 100.0% LazyCompile: *responseOnEnd http.js:1591
2 100.0% LazyCompile: *EventEmitter.emit events.js:54
74 2.2% LazyCompile: *replace native string.js:221
44 59.5% LazyCompile: *formatPrimitive util.js:289
29 65.9% LazyCompile: *formatValue util.js:189
29 100.0% LazyCompile: *formatProperty util.js:338
29 100.0% Function: <anonymous> util.js:278
15 34.1% Function: formatValue util.js:189
15 100.0% LazyCompile: *formatProperty util.js:338
15 100.0% Function: <anonymous> util.js:278
26 35.1% LazyCompile: *formatProperty util.js:338
26 100.0% Function: <anonymous> util.js:278
26 100.0% LazyCompile: *map native array.js:1190
16 61.5% LazyCompile: *formatValue util.js:189
10 38.5% Function: formatValue util.js:189
3 4.1% LazyCompile: *Agent.createSocket http.js:1189
3 100.0% LazyCompile: *Agent.addRequest http.js:1170
3 100.0% Function: ~ClientRequest http.js:1254
3 100.0% Function: ~exports.request http.js:1718
显然在exports.Parser.Parser.parseString 上花费了很多时间（对吗？） - 但为什么该函数只列在自下而上的表中？
为什么一半的时间花在了ntdll上？
这是 azure-sdk-for-node 的问题，还是 node.js 本身的问题，还是我的期望太高了？