javascript - recibir - sockets en java cliente servidor netbeans

El servidor de eco de nodo degrada 10x cuando se utilizan conductos de flujo sobre almacenamiento en búfer

Question

En el nodo v8.1.4 y v6.11.1

Comencé con la siguiente implementación de servidor de eco, a la que me referiré como pipe.js o pipe .

const http = require(''http'');

const handler = (req, res) => req.pipe(res);
http.createServer(handler).listen(3001);

Y lo wrk con wrk y el siguiente guión lua (abreviado por brevedad) que enviará un pequeño cuerpo como carga útil.

wrk.method = "POST"
wrk.body   = string.rep("a", 10)

Con 2k solicitudes por segundo y 44 ms de latencia promedio, el rendimiento no es excelente.

Así que escribí otra implementación que usa búferes intermedios hasta que la solicitud finaliza y luego escribe esos búferes. Me referiré a esto como buffer.js o buffer .

const http = require(''http'');

const handler = (req, res) => {
  let buffs = [];
  req.on(''data'', (chunk) => {
    buffs.push(chunk);
  });
  req.on(''end'', () => {
    res.write(Buffer.concat(buffs));
    res.end();
  });
};
http.createServer(handler).listen(3001);

El rendimiento cambió drásticamente con el servicio de buffer.js 20k solicitudes por segundo a 4ms de latencia promedio.

Visualmente, el siguiente gráfico muestra el número promedio de solicitudes atendidas en 5 ejecuciones y varios percentiles de latencia (p50 es la mediana).

Entonces, el buffer es un orden de magnitud mejor en todas las categorías. Mi pregunta es por qué?

Lo que sigue a continuación son mis notas de investigación, ojalá sean al menos educativas.

Comportamiento de respuesta

Ambas implementaciones se han diseñado para que den la misma respuesta exacta devuelta por curl -D - --raw . Si se les da un cuerpo de 10 d''s, ambos devolverán la misma respuesta (con tiempo modificado, por supuesto):

HTTP/1.1 200 OK
Date: Thu, 20 Jul 2017 18:33:47 GMT
Connection: keep-alive
Transfer-Encoding: chunked

a
dddddddddd
0

Ambos emiten 128 bytes (recuerda esto).

La mera realidad del almacenamiento en búfer

Semánticamente, la única diferencia entre las dos implementaciones es que pipe.js escribe datos mientras que la solicitud no ha finalizado. Esto podría hacer sospechar que podría haber múltiples eventos de data en buffer.js . Esto no es verdad.

req.on(''data'', (chunk) => {
  console.log(`chunk length: ${chunk.length}`);
  buffs.push(chunk);
});
req.on(''end'', () => {
  console.log(`buffs length: ${buffs.length}`);
  res.write(Buffer.concat(buffs));
  res.end();
});

Empíricamente:

• La longitud del trozo siempre será 10
• La longitud de los búferes siempre será 1

Como solo habrá un trozo, lo que sucederá si eliminamos el almacenamiento en búfer e implementamos el conducto de un hombre pobre:

const http = require(''http'');

const handler = (req, res) => {
  req.on(''data'', (chunk) => res.write(chunk));
  req.on(''end'', () => res.end());
};
http.createServer(handler).listen(3001);

Resulta que esto tiene un rendimiento tan abismal como pipe.js. Encuentro esto interesante porque el mismo número de llamadas res.write y res.end se realizan con los mismos parámetros. Mi mejor estimación hasta ahora es que las diferencias de rendimiento se deben al envío de datos de respuesta una vez que los datos de solicitud han finalizado.

Perfilado

Hice un perfil de ambas aplicaciones usando la guía de perfil simple (--prof) .

He incluido solo las líneas relevantes:

pipe.js

 [Summary]:
   ticks  total  nonlib   name
   2043   11.3%   14.1%  JavaScript
  11656   64.7%   80.7%  C++
     77    0.4%    0.5%  GC
   3568   19.8%          Shared libraries
    740    4.1%          Unaccounted

 [C++]:
   ticks  total  nonlib   name
   6374   35.4%   44.1%  syscall
   2589   14.4%   17.9%  writev

buffer.js

 [Summary]:
   ticks  total  nonlib   name
   2512    9.0%   16.0%  JavaScript
  11989   42.7%   76.2%  C++
    419    1.5%    2.7%  GC
  12319   43.9%          Shared libraries
   1228    4.4%          Unaccounted

 [C++]:
   ticks  total  nonlib   name
   8293   29.6%   52.7%  writev
    253    0.9%    1.6%  syscall

Vemos que en ambas implementaciones, C ++ domina el tiempo; sin embargo, las funciones que dominan se intercambian. Los syscalls representan casi la mitad del tiempo para el conducto , pero solo el 1% para el almacenamiento intermedio (perdonen mi redondeo). El siguiente paso, ¿qué syscalls son los culpables?

Strace Here We Come

Invocar strace como strace -c node pipe.js nos dará un resumen de las llamadas de sistema. Aquí están los mejores syscalls:

pipe.js

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 43.91    0.014974           2      9492           epoll_wait
 25.57    0.008720           0    405693           clock_gettime
 20.09    0.006851           0     61748           writev
  6.11    0.002082           0     61803       106 write

buffer.js

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 42.56    0.007379           0    121374           writev
 32.73    0.005674           0    617056           clock_gettime
 12.26    0.002125           0    121579           epoll_ctl
 11.72    0.002032           0    121492           read
  0.62    0.000108           0      1217           epoll_wait

El syscall superior para tubería ( epoll_wait ) con el 44% del tiempo es solo el 0.6% del tiempo para el buffer (un aumento de 140x). Si bien hay una gran discrepancia de tiempo, la cantidad de veces que se invoca epoll_wait es menos desequilibrada con la llamada a la línea epoll_wait ~ 8x más a menudo. Podemos derivar un par de bits de información útil de esa declaración, de tal manera que pipe llama a epoll_wait constantemente y, en promedio, estas llamadas son más pesadas que epoll_wait para el buffer .

Para el búfer , el syscall superior es writev , que se espera teniendo en cuenta que la mayor parte del tiempo se debe dedicar a escribir datos en un socket.

Lógicamente, el siguiente paso es echar un vistazo a estas declaraciones epoll_wait con regular strace, que mostró que el buffer siempre contenía epoll_wait con 100 eventos (que representan las cien conexiones utilizadas con wrk ) y que pipe tenía menos de 100 la mayor parte del tiempo. Al igual que:

pipe.js

epoll_wait(5, [.16 snip.], 1024, 0) = 16

buffer.js

epoll_wait(5, [.100 snip.], 1024, 0) = 100

Gráficamente:

Esto explica por qué hay más epoll_wait en pipe , ya que epoll_wait no da servicio a todas las conexiones en un bucle de evento. ¡El epoll_wait para cero eventos hace que parezca que el bucle de evento está inactivo! Todo esto no explica por qué epoll_wait toma más tiempo para pipe , ya que desde la página man indica que epoll_wait debe regresar inmediatamente:

especificando un tiempo de espera igual a cero causa que epoll_wait () regrese inmediatamente, incluso si no hay eventos disponibles.

Mientras que la página man dice que la función regresa inmediatamente, ¿podemos confirmar esto? strace -T al rescate:

Además de admitir que el búfer tiene menos llamadas, también podemos ver que casi todas las llamadas tomaron menos de 100ns. Pipe tiene una distribución mucho más interesante que muestra que, aunque la mayoría de las llamadas tienen menos de 100ns, una cantidad no despreciable toma más tiempo y aterriza en la tierra de microsegundos.

Strace encontró otra rareza, y eso es con writev . El valor de retorno es la cantidad de bytes escritos.

pipe.js

writev(11, [{"HTTP/1.1 200 OK/r/nDate: Thu, 20 J"..., 109},
  {"/r/n", 2}, {"dddddddddd", 10}, {"/r/n", 2}], 4) = 123

buffer.js

writev(11, [{"HTTP/1.1 200 OK/r/nDate: Thu, 20 J"..., 109},
  {"/r/n", 2}, {"dddddddddd", 10}, {"/r/n", 2}, {"0/r/n/r/n", 5}], 5) = 128

¿Recuerdas cuando dije que ambos daban como resultado 128 bytes? Bueno, writev devolvió 123 bytes para pipe y 128 para buffer . La diferencia de cinco bytes para la tubería se concilia en una llamada de write posterior para cada writev .

write(44, "0/r/n/r/n", 5)

Y si no me equivoco, write syscalls está bloqueando.

Conclusión

Si tengo que hacer una conjetura, diría que la canalización cuando la solicitud no está terminada provoca llamadas de write . Estas llamadas de bloqueo reducen significativamente el rendimiento parcialmente a través de declaraciones epoll_wait más frecuentes. Por qué write se llama en lugar de una sola writev que se ve en el búfer está más allá de mí. ¿Alguien puede explicar por qué está sucediendo todo lo que vi?

¿El pateador? En la guía oficial de Node.js puedes ver cómo la guía comienza con la implementación del buffer y luego se mueve a pipe. Si la implementación de la tubería está en la guía oficial, no debería haber tal impacto de rendimiento, ¿verdad?

Aparte: las implicaciones del rendimiento en el mundo real de esta pregunta deben ser mínimas, ya que la pregunta es bastante artificial especialmente en lo que respecta a la funcionalidad y el lado del cuerpo, aunque esto no significa que esta sea una pregunta menos útil. Hipotéticamente, una respuesta podría ser similar a "Node.js usa write para permitir un mejor rendimiento en x situaciones (donde x es un caso de uso más real del mundo)"

^{Divulgación: pregunta copiada y ligeramente modificada de mi publicación en el blog con la esperanza de que esta sea una mejor vía para responder a esta pregunta}

31 de julio de 2017 EDITAR

Mi hipótesis inicial de que escribir el cuerpo repetido después de que el flujo de solicitud haya terminado aumenta el rendimiento ha sido desmentido por @robertklep con su implementación legible.js (o legible ):

const http   = require(''http'');
const BUFSIZ = 2048;

const handler = (req, res) => {
  req.on(''readable'', _ => {
    let chunk;
    while (null !== (chunk = req.read(BUFSIZ))) {
      res.write(chunk);
    }
  });
  req.on(''end'', () => {
    res.end();
  });
};
http.createServer(handler).listen(3001);

Legible realizado en el mismo nivel que el búfer mientras escribe datos antes del evento end . En todo caso, esto me hace estar más confundido porque la única diferencia entre la implementación legible y la inicial de mi pobre hombre es la diferencia entre los data y el evento readable , pero eso causó un aumento del rendimiento de 10 veces. Pero sabemos que el evento de data no es inherentemente lento porque lo usamos en nuestro código de buffer .

Para los curiosos, strace on readible writev output todos los 128 bytes de salida como buffer

¡Esto es desconcertante!

Answer 1

¡Esa es una pregunta divertida que tienes!

De hecho, el buffer frente a la tubería no es la pregunta aquí. Tienes un pequeño pedazo; se procesa en un evento. Para mostrar el problema, puede escribir su controlador de esta manera:

let chunk;
req.on(''data'', (dt) => {
    chunk=dt
});
req.on(''end'', () => {
    res.write(chunk);
    res.end();
});

o

let chunk;
req.on(''data'', (dt) => {
    chunk=dt;
    res.write(chunk);
    res.end();
});
req.on(''end'', () => {
});

o

let chunk;
req.on(''data'', (dt) => {
    chunk=dt
    res.write(chunk);
});
req.on(''end'', () => {
    res.end();
});

Si write y end están en el mismo controlador, la latencia es 10 veces menor.

Si comprueba el código de función de write , hay alrededor de esta línea

msg.connection.cork();
process.nextTick(connectionCorkNT, msg.connection);

cork y uncork conexión en el próximo evento. Esto significa que utiliza un caché para los datos, luego fuerza que los datos se envíen en el siguiente evento antes de que se procesen otros eventos.

Para resumir, si tiene write y end en diferentes manejadores, tendrá:

1. conexión de corcho (+ crear una marca para descorchar)
2. crear buffer con datos
3. descorchar la conexión de otro evento (enviar datos)
4. proceso final de llamada (que envía otro paquete con el fragmento final y cierra)

Si están en el mismo controlador, se llama a la función end antes de que se procese el evento de uncork , por lo que el fragmento final estará en el caché.

1. conexión de corcho
2. crear buffer con datos
3. agregar el fragmento "final" en el búfer
4. descorche la conexión para enviar todo

Además, la función end ejecuta cork / uncork sincrónica , que será un poco más rápido.

Ahora, ¿por qué importa esto? Porque en el lado de TCP, si envía un paquete con datos y desea enviar más, el proceso esperará una confirmación del cliente antes de enviar más:

write + end en diferentes manejadores:

• 0.044961s: POST / => es la solicitud
• 0.045322s: HTTP/1.1 => 1er fragmento: encabezado + "aaaaaaaaa"
• 0.088522s: confirmación de paquete
• 0.088567s: Continuación => 2do trozo (parte final, 0/r/n/r/n )

Hay ~ 40 ms antes de ack después de que se envía el primer buffer.

write + end en el mismo controlador:

Los datos se completan en un solo paquete, no se necesita ack .

¿Por qué los 40ms en ACK ? Esta es una función incorporada en el sistema operativo para mejorar el rendimiento en general. Se describe en la sección 4.2.3.2 de IETF RFC 1122: cuándo enviar un segmento de ACK '' . Red Hat (Fedora / CentOS / RHEL) usa 40 ms: es un parámetro y se puede modificar . En Debian (Ubuntu incluido), parece estar codificado a 40ms, por lo que no es modificable (excepto si crea una conexión con la opción TCP_NO_DELAY ).

Espero que esto sea suficiente detalle para entender un poco más sobre el proceso. Esta respuesta ya es grande, así que me detendré aquí, supongo.

Legible

Revisé tu nota sobre readable . Conjetura salvaje: si readable detecta una entrada vacía, cierra la secuencia en el mismo tic.

Editar: Leí el código para leer. Como sospechaba:

https://github.com/nodejs/node/blob/master/lib/_stream_readable.js#L371

https://github.com/nodejs/node/blob/master/lib/_stream_readable.js#L1036

Si la lectura finaliza un evento, el end se emite inmediatamente para procesarse a continuación.

Entonces el procesamiento del evento es:

1. evento readable : lee datos
2. readable detecta que ha terminado => crea evento end
3. Escribe datos para que cree un evento para descorchar
4. evento end procesado (descorchar)
5. descorche procesado (pero no haga nada ya que todo está hecho)

Si reduces el buffer:

req.on(''readable'',()=> {
    let chunk2;
    while (null !== (chunk2 = req.read(5))) {
        res.write(chunk2);
    }
});

Esto obliga a dos escrituras. El proceso será:

1. evento readable : lee datos. Tienes cinco a s.
2. Escribe datos que crean un evento de descorche
3. Usted lee datos. readable detecta que ha terminado => crear evento end
4. Escribe datos y se agrega a los datos almacenados
5. descorre procesado (porque fue lanzado antes de end ); usted envía datos
6. end evento procesado (descorchar) => esperar a que ACK envíe el fragmento final
7. El proceso será lento (es, lo he comprobado)

Answer 2

La clave está en la latencia, las latencias son aproximadamente 10 veces la diferencia. Creo que debido a que el enfoque de almacenamiento en búfer mueve la llamada de escritura a la req.on(''end'', ...) , el servidor puede optimizar la respuesta. Aunque solo se lee y escribe un búfer de diez bytes en cualquier solicitud dada, se realizan muchas solicitudes simultáneas.

Estimando aproximadamente con solicitudes de 2K 10 bytes por segundo, y ~ 50ms de latencia, me imagino que el tiempo pasado en transmitir los ''datos'' es insignificante. Eso sugeriría que el servidor está manejando aproximadamente 100 solicitudes simultáneas en un momento dado.

1 / .05 = 20.  2000/20 = 100

Ahora cambie a ~ 5ms de latencia, y de nuevo teniendo en cuenta los datos reales, el tiempo tx es 0.

1 / .005 = 200.  20000/200 = 100.

Todavía tenemos el servidor manejando aproximadamente 100 solicitudes entrando simultáneamente en cualquier punto en el tiempo.

No conozco las partes internas del servidor, pero si su servidor está llegando al límite superior como este, probablemente esté introduciendo latencia para que el controlador de eventos ''datos'' también maneje la escritura de datos en la respuesta.

Al almacenar en búfer y regresar inmediatamente, el controlador puede liberarse antes y, por lo tanto, reducir drásticamente la latencia en el lado de lectura. La pregunta abierta en mi mente es: ¿el manejador realmente necesitaría casi 50ms de sobrecarga para escribir la respuesta? Yo diría que no, pero si 100 solicitudes compiten por recursos para escribir sus datos, eso podría comenzar a sumarse. Combine eso con el hecho de que todavía necesita llamar a un res.end () (en un manejador diferente) y potencialmente ha encontrado su latency hog.

En el procesamiento ''final'', las respuestas de 20K 10bytes difícilmente pueden llamarse una gran carga de datos, por lo que es una ganancia una cuestión de gestión de recursos, es decir, el manejador de finalización de la respuesta. Si res.write () y res.end () ocurren en el mismo controlador, es presumiblemente más eficiente que escribir los 10 bytes en uno y finalizar la respuesta en otro. De cualquier manera, no puedo imaginar que el código de finalización de la respuesta esté introduciendo cualquier retraso. Es más probable que se muera de hambre por el trabajo que hacer (incluso en el enfoque de búfer).

EDITAR

También puede intentar res.end(data) en su enfoque de almacenamiento en búfer en lugar de llamar a res.write(data) seguido de res.end() , y ver si eso agrega cualquier punto de datos aclaratorios a su análisis.

EDITAR

Acabo de probar la misma prueba en mis sistemas. Utilicé una máquina virtual Ubuntu Linux en otra máquina física como cliente, wrk como banco de pruebas, una secuencia de comandos lua como la tuya y configuraciones predeterminadas. Usé el escritorio de Windows 8 para ejecutar nodejs, el mismo script excepto usando el puerto 8080. Mi rendimiento tanto para pipe () como para el almacenamiento en búfer fue mucho más bajo que el suyo, pero comparados entre sí, los búferes eran aproximadamente 9 veces más rápidos que pipe (). Entonces, esto es simplemente una confirmación independiente.