spanish sol puerta movimiento mayo manifestacion los indignados definicion 22m 15m c++ performance curl network-programming cpp-netlib

c++ - sol - movimiento 15 m



¿De dónde viene un retraso en un HTTP POST? (1)

Problema resuelto, gracias a las técnicas de depuración y diagnóstico sugeridas por @jxh.

La adición de --trace - --trace-time al comando curl reveló que curl estaba pasando ese misterioso segundo esperando a que el servidor devuelva una respuesta de 100 Continuar antes de enviar el resto de la solicitud:

01:31:44.043611 == Info: Connected to localhost (127.0.0.1) port 8787 (#0) 01:31:44.043726 => Send header, 175 bytes (0xaf) 0000: 50 4f 53 54 20 2f 66 6f 6f 20 48 54 54 50 2f 31 POST /foo HTTP/1 0010: 2e 31 0d 0a 55 73 65 72 2d 41 67 65 6e 74 3a 20 .1..User-Agent: 0020: 63 75 72 6c 2f 37 2e 33 35 2e 30 0d 0a 48 6f 73 curl/7.35.0..Hos 0030: 74 3a 20 6c 6f 63 61 6c 68 6f 73 74 3a 38 37 38 t: localhost:878 0040: 37 0d 0a 41 63 63 65 70 74 3a 20 2a 2f 2a 0d 0a 7..Accept: */*.. 0050: 43 6f 6e 74 65 6e 74 2d 4c 65 6e 67 74 68 3a 20 Content-Length: 0060: 31 32 30 36 0d 0a 43 6f 6e 74 65 6e 74 2d 54 79 1206..Content-Ty 0070: 70 65 3a 20 61 70 70 6c 69 63 61 74 69 6f 6e 2f pe: application/ 0080: 78 2d 77 77 77 2d 66 6f 72 6d 2d 75 72 6c 65 6e x-www-form-urlen 0090: 63 6f 64 65 64 0d 0a 45 78 70 65 63 74 3a 20 31 coded..Expect: 1 00a0: 30 30 2d 63 6f 6e 74 69 6e 75 65 0d 0a 0d 0a 00-continue.... 01:31:45.045626 == Info: Done waiting for 100-continue 01:31:45.045831 => Send data, 1206 bytes (0x4b6)

Es una deficiencia conocida en cpp-netlib (al menos a partir de la versión 0.11.0) que no admite el envío de la respuesta 100 Continuar que espera el rizo.

La solución se convirtió entonces en un rizo convincente para no esperar una respuesta de 100 Continuar. Como descubrí aquí , agregar -H ''Expect:'' a la línea de comandos curl hace el truco. Con eso, la transacción completa toma alrededor de un milisegundo.

Ya que respondí a mi propia pregunta, no aceptaré mi respuesta durante algunas semanas para dar a otros la oportunidad de contribuir con algo mejor.

Estoy desarrollando un servicio web en Ubuntu 14.04 en C ++ usando cpp-netlib en modo asíncrono. El servicio debe responder a los datos enviados a través de HTTP POST en el cuerpo del mensaje. Estoy observando un rendimiento bajo cuando recibo una entrada mayor a 1K, y quiero corregir eso.

Si los datos son relativamente pequeños, menos de 1 K, el servidor los recibe casi instantáneamente. Si los datos son más de 1K, hay un retraso de aproximadamente un segundo después de que se invoca por primera vez la función de devolución de llamada de lectura asíncrona antes de que la primera parte de los datos reales se presente a la devolución de llamada. Después del retraso inicial, los trozos subsiguientes llegan casi instantáneamente.

¿Cómo puedo eliminar este retraso? ¿Es un artefacto del uso de rizo para publicar datos de prueba? ¿Cómo puedo probar fácilmente el rendimiento de Curl para publicar datos?

Puede encontrar un código fuente mínimo que demuestre el problema en github. Aquí está el comando que utilizo para publicar datos en el servidor:

rcook$ curl -d @AsyncDaemon.h http://localhost:8787/foo

Aquí hay un ejemplo de su salida (anotada):

rcook$ ./async_daemon 1431387368.321863: AsyncDaemon constructor 1431387368.322446: receive thread beginning *** It''s waiting for a connection here. 1431387371.536191: begin transaction 0 on thread 24050 1431387371.536237: transaction 0 constructor 1431387371.536273: received 1206 byte request for /foo from 127.0.0.1:49402 1431387371.536312: invoked asynchronous read 1431387371.536321: end transaction handler 1431387371.536335: begin asynchronous read callback on thread 24050 1431387371.536348: read 0 bytes 1431387371.536386: invoked asynchronous read 1431387371.536394: end asynchronous read callback *** The asynchronous read callback is invoked quickly, but gets no data. *** There is then a pause of just over one second before the asynchronous *** read callback is invoked again. 1431387372.537203: begin asynchronous read callback on thread 24050 1431387372.537253: read 1024 bytes 1431387372.537307: invoked asynchronous read 1431387372.537317: end asynchronous read callback *** There is no significant delay when reading the next chunk. 1431387372.537429: begin asynchronous read callback on thread 24050 1431387372.537469: read 182 bytes 1431387372.537478: finished reading the body 1431387372.537746: wrote response 1431387372.537763: transaction 0 destructor 1431387372.537772: end asynchronous read callback *** The server is then killed with a keyboard interrupt. ^C1431387375.382186: terminating with signal 2 1431387375.382231: initiating shutdown 1431387375.382241: stopping server 1431387375.382363: server run finished 1431387375.382423: receive thread ending 1431387375.382522: AsyncDaemon destructor

Como puede ver, después de que se invoca por primera vez la devolución de llamada de lectura asíncrona (y recibe cero bytes de datos, por cierto), solicita otra porción de entrada. En este punto, hay una pausa de poco más de un segundo antes de que llegue la entrada, desde 1431387371.536394 a 1431387372.537203 en este ejemplo. ¿Qué está pasando durante ese tiempo? ¿Cómo puedo eliminar ese retraso?

He investigado un poco en línea y ejecuté varios experimentos (modo síncrono vs. asíncrono con cpp-netlib (sin efecto), curl contra libcurl (sin efecto)), pero no he podido encontrar una respuesta.

Actualización: TCP Dump

Tras la sugerencia de jxh, ejecuté un volcado de TCP durante una transacción de muestra:

00:28:01.304446 IP6 localhost.52265 > localhost.8787: Flags [S], seq 3956487146, win 43690, options [mss 65476,sackOK,TS val 395479802 ecr 0,nop,wscale 7], length 0 00:28:01.304461 IP6 localhost.8787 > localhost.52265: Flags [R.], seq 0, ack 3956487147, win 0, length 0 00:28:01.305014 IP localhost.49421 > localhost.8787: Flags [S], seq 1668603425, win 43690, options [mss 65495,sackOK,TS val 395479803 ecr 0,nop,wscale 7], length 0 00:28:01.305039 IP localhost.8787 > localhost.49421: Flags [S.], seq 4010788604, ack 1668603426, win 43690, options [mss 65495,sackOK,TS val 395479803 ecr 395479803,nop,wscale 7], length 0 00:28:01.305079 IP localhost.49421 > localhost.8787: Flags [.], ack 1, win 342, options [nop,nop,TS val 395479803 ecr 395479803], length 0 00:28:01.305185 IP localhost.49421 > localhost.8787: Flags [P.], seq 1:176, ack 1, win 342, options [nop,nop,TS val 395479803 ecr 395479803], length 175 00:28:01.305210 IP localhost.8787 > localhost.49421: Flags [.], ack 176, win 350, options [nop,nop,TS val 395479803 ecr 395479803], length 0 00:28:02.306555 IP localhost.49421 > localhost.8787: Flags [P.], seq 176:1382, ack 1, win 342, options [nop,nop,TS val 395480053 ecr 395479803], length 1206 00:28:02.306620 IP localhost.8787 > localhost.49421: Flags [.], ack 1382, win 1373, options [nop,nop,TS val 395480053 ecr 395480053], length 0 00:28:02.307223 IP localhost.8787 > localhost.49421: Flags [P.], seq 1:52, ack 1382, win 1373, options [nop,nop,TS val 395480053 ecr 395480053], length 51 00:28:02.307270 IP localhost.49421 > localhost.8787: Flags [.], ack 52, win 342, options [nop,nop,TS val 395480053 ecr 395480053], length 0 00:28:02.307494 IP localhost.8787 > localhost.49421: Flags [P.], seq 52:66, ack 1382, win 1373, options [nop,nop,TS val 395480053 ecr 395480053], length 14 00:28:02.307522 IP localhost.49421 > localhost.8787: Flags [.], ack 66, win 342, options [nop,nop,TS val 395480053 ecr 395480053], length 0 00:28:02.307765 IP localhost.8787 > localhost.49421: Flags [F.], seq 66, ack 1382, win 1373, options [nop,nop,TS val 395480053 ecr 395480053], length 0 00:28:02.307867 IP localhost.49421 > localhost.8787: Flags [F.], seq 1382, ack 67, win 342, options [nop,nop,TS val 395480053 ecr 395480053], length 0 00:28:02.307917 IP localhost.8787 > localhost.49421: Flags [.], ack 1383, win 1373, options [nop,nop,TS val 395480053 ecr 395480053], length 0

No tengo mucha experiencia con tcpdump, pero parece que 175 bytes fluyen al servidor (¿encabezados HTTP?), Luego, tras un retraso de poco más de un segundo, 1206 bytes fluyen al servidor, seguidos de un fragmento de 51 bytes con Retardo mínimo, seguido de la respuesta del servidor.

Esto me dice que el retraso se está introduciendo en el lado del cliente, probablemente en rizo. ¿Alguien sabe por qué?