{"id":4976,"date":"2018-04-09T12:53:25","date_gmt":"2018-04-09T19:53:25","guid":{"rendered":"https:\/\/www.couchbase.com\/blog\/?p=4976"},"modified":"2023-06-13T05:26:43","modified_gmt":"2023-06-13T12:26:43","slug":"response-time-observability-with-the-java-sdk","status":"publish","type":"post","link":"https:\/\/www.couchbase.com\/blog\/es\/response-time-observability-with-the-java-sdk\/","title":{"rendered":"Observabilidad del tiempo de respuesta con el SDK de Java"},"content":{"rendered":"

En blogs anteriores se explicaba mejor nuestro enfoque de la Observabilidad en tiempo real<\/strong> (RTO) en general ayuda a solucionar los problemas de los sistemas distribuidos y por qu\u00e9 elegimos OpenTracing<\/a> como base y API p\u00fablica. Si a\u00fan no lo ha hecho, puede consultar estos blogs aqu\u00ed<\/a>\u00a0y aqu\u00ed<\/a>.<\/p>\n

En este blog, aprender\u00e1 c\u00f3mo funciona RTO con el SDK de Java<\/strong> y c\u00f3mo puede utilizarlo hoy en su beneficio.<\/p>\n

Primeros pasos<\/h2>\n

En cuanto se publique la versi\u00f3n 2.6.0 (o posterior) del SDK de Java, podr\u00e1 obtenerla por los medios habituales descritos a continuaci\u00f3n aqu\u00ed<\/a>. Dado que esta versi\u00f3n se encuentra ahora mismo en estado de versi\u00f3n preliminar, es necesario acceder a ella desde nuestro propio repositorio maven. A trav\u00e9s de un maven pom.xml<\/code>:<\/p>\n

<dependencies>\r\n  <dependency>\r\n\t<groupId>com.couchbase.client<\/groupId>\r\n\t<artifactId>java-client<\/artifactId>\r\n\t<version>2.6.0-dp1<\/version>\r\n  <\/dependency>\r\n<\/dependencies>\r\n\r\n<repositories>\r\n  <repository>\r\n\t<id>cb-pre<\/id>\r\n\t<name>Couchbase Prerelease Repo<\/name>\r\n\t<url>https:\/\/files.couchbase.com\/maven2<\/url>\r\n  <\/repository>\r\n<\/repositories><\/pre>\n
La \u00fanica diferencia que notar\u00e1 es una nueva dependencia llamada opentracing-api<\/code> de la que hablaremos m\u00e1s adelante. Dado que no se trata de una versi\u00f3n mayor, todo el c\u00f3digo anterior funcionar\u00e1 como antes y te beneficiar\u00e1s de las mejoras de inmediato.<\/p>\n
Si necesita personalizar el propio trazador o parte de su configuraci\u00f3n, puede hacerlo a trav\u00e9s de la funci\u00f3n CouchbaseEntorno.Builder<\/code> como con el resto de ajustes. Este es un ejemplo de c\u00f3mo personalizar nuestro trazador predeterminado para reducir el intervalo de tiempo en el que se registra la informaci\u00f3n:<\/p>\n
Tracer tracer = ThresholdLogTracer.create(ThresholdLogReporter.builder()\r\n  .logInterval(10, TimeUnit.SECONDS) \/\/ log every 10 seconds\r\n  .build());\r\n\r\nCouchbaseEnvironment env = DefaultCouchbaseEnvironment.builder()\r\n  .tracer(tracer)\r\n  .build();<\/pre>\n
Explicaci\u00f3n del registro de umbrales<\/h2>\n
Para mojarnos los pies con el rastreador de registro de umbrales (que est\u00e1 activado por defecto) vamos a personalizar un poco su configuraci\u00f3n y bajar los umbrales tan bajos que pr\u00e1cticamente todas las peticiones y respuestas est\u00e9n cubiertas. Obviamente esto no es una buena idea para producci\u00f3n, pero nos ayudar\u00e1 a llegar a la salida de registro deseada r\u00e1pidamente y afirmar su funcionalidad.<\/p>\n
Aplique la siguiente configuraci\u00f3n como se ha indicado anteriormente:<\/p>\n
Tracer tracer = ThresholdLogTracer.create(ThresholdLogReporter.builder()\r\n  .kvThreshold(1) \/\/ 1 micros\r\n  .logInterval(1, TimeUnit.SECONDS) \/\/ log every second\r\n  .sampleSize(Integer.MAX_VALUE)\r\n  .pretty(true) \/\/ pretty print the json output in the logs\r\n  .build());<\/pre>\n
Esto fijar\u00e1 nuestro umbral para las operaciones clave\/valor en un microsegundo, registrar\u00e1 las operaciones encontradas cada segundo y fijar\u00e1 el tama\u00f1o de la muestra en un valor muy grande para que se registre todo. Por defecto, se registrar\u00e1 cada minuto (si se encuentra algo) y s\u00f3lo se muestrear\u00e1n las 10 operaciones m\u00e1s lentas. El umbral por defecto para las operaciones clave\/valor es de 500 milisegundos.<\/p>\n
Con estas configuraciones en su lugar estamos listos para ejecutar algunas operaciones. Si\u00e9ntase libre de ajustar la siguiente configuraci\u00f3n para que apunte a su servidor y aplique las credenciales apropiadas:<\/p>\n
\/\/ Connect\r\nCouchbaseEnvironment env = DefaultCouchbaseEnvironment.builder()\r\n    .tracer(tracer)\r\n    .build();\r\nCluster cluster = CouchbaseCluster.create(env, \"127.0.0.1\");\r\n\r\nBucket bucket = cluster.openBucket(\"travel-sample\");\r\n\r\n\/\/ Load a couple of docs and write them back\r\nfor(int i = 0; i < 5; i++) {\r\n  JsonDocument doc = bucket.get(\"airline_1\" + i);\r\n  if (doc != null) {\r\n    bucket.upsert(doc);\r\n  }\r\n}\r\n\r\nThread.sleep(TimeUnit.MINUTES.toMillis(1));<\/pre>\n
En este sencillo c\u00f3digo estamos leyendo algunos documentos de la base de datos viaje-muestra<\/code> y si lo encuentra lo escribe de vuelta con un upsert<\/code>. Esto nos permite de forma sencilla realizar operaciones tanto de lectura como de escritura. Una vez ejecutado el c\u00f3digo, ver\u00e1s una salida (similar) en los logs:<\/p>\n
Apr 04, 2018 9:42:57 AM com.couchbase.client.core.tracing.ThresholdLogReporter logOverThreshold\r\nWARNING: Operations over threshold: [ {\r\n  \"top\" : [ {\r\n    \"server_us\" : 8,\r\n    \"local_id\" : \"41837B87B9B1C5D1\/000000004746B9AA\",\r\n    \"local_address\" : \"127.0.0.1:55011\",\r\n    \"operation_id\" : \"get:0x6\",\r\n    \"dispatch_us\" : 315,\r\n    \"remote_address\" : \"127.0.0.1:11210\",\r\n    \"total_us\" : 576\r\n  }, {\r\n    \"server_us\" : 8,\r\n    \"local_id\" : \"41837B87B9B1C5D1\/000000004746B9AA\",\r\n    \"local_address\" : \"127.0.0.1:55011\",\r\n    \"operation_id\" : \"get:0x5\",\r\n    \"dispatch_us\" : 319,\r\n    \"remote_address\" : \"127.0.0.1:11210\",\r\n    \"total_us\" : 599\r\n  }, {\r\n    \"server_us\" : 8,\r\n    \"local_id\" : \"41837B87B9B1C5D1\/000000004746B9AA\",\r\n    \"local_address\" : \"127.0.0.1:55011\",\r\n    \"operation_id\" : \"get:0x4\",\r\n    \"dispatch_us\" : 332,\r\n    \"remote_address\" : \"127.0.0.1:11210\",\r\n    \"total_us\" : 632\r\n  }, {\r\n    \"server_us\" : 11,\r\n    \"local_id\" : \"41837B87B9B1C5D1\/000000004746B9AA\",\r\n    \"local_address\" : \"127.0.0.1:55011\",\r\n    \"operation_id\" : \"get:0x3\",\r\n    \"dispatch_us\" : 392,\r\n    \"remote_address\" : \"127.0.0.1:11210\",\r\n    \"total_us\" : 762\r\n  }, {\r\n    \"server_us\" : 23,\r\n    \"local_id\" : \"41837B87B9B1C5D1\/000000004746B9AA\",\r\n    \"local_address\" : \"127.0.0.1:55011\",\r\n    \"operation_id\" : \"get:0x1\",\r\n    \"decode_us\" : 9579,\r\n    \"dispatch_us\" : 947,\r\n    \"remote_address\" : \"127.0.0.1:11210\",\r\n    \"total_us\" : 16533\r\n  }, {\r\n    \"server_us\" : 56,\r\n    \"encode_us\" : 12296,\r\n    \"local_id\" : \"41837B87B9B1C5D1\/000000004746B9AA\",\r\n    \"local_address\" : \"127.0.0.1:55011\",\r\n    \"operation_id\" : \"upsert:0x2\",\r\n    \"dispatch_us\" : 1280,\r\n    \"remote_address\" : \"127.0.0.1:11210\",\r\n    \"total_us\" : 20935\r\n  } ],\r\n  \"service\" : \"kv\",\r\n  \"count\" : 6\r\n} ]<\/pre>\n
This is our threshold log reporter in action! For each service (only `kv` based on this workload) it will show you the total amount of recorded ops (through `count`) and give you the top slowest ops sorted by their latency. Since only `airline_10` exists in the bucket you see 5 document fetches but only one mutation happening.<\/p>\n
Veamos una operaci\u00f3n concreta y hablemos de cada campo con un poco m\u00e1s de detalle:<\/p>\n
{\r\n\t\"server_us\" : 23,\r\n\t\"local_id\" : \"41837B87B9B1C5D1\/000000004746B9AA\",\r\n\t\"local_address\" : \"127.0.0.1:55011\",\r\n\t\"operation_id\" : \"get:0x1\",\r\n\t\"decode_us\" : 1203,\r\n\t\"dispatch_us\" : 947,\r\n\t\"remote_address\" : \"127.0.0.1:11210\",\r\n\t\"total_us\" : 1525\r\n}<\/pre>\n
Nos dice lo siguiente:<\/p>\n