viernes, 12 de agosto de 2016

Mongotail 2.0 with new performance features, SSL and MongoDB 3.2 support

A couple of weeks ago I released Mongotail 2.0.0, with new features and support for the latest version of MongoDB 3.2. Also one of the most important features is the ability to login against a database with SSL authentication, and new options that give us more information about what is happening in our database, like the consumed time by a query, or how many registries the engine had to "walk" to find a particular record.

What is Mongotail? mongotail is a command line tool to output any operation from a Mongo database in the standard output. You can see the operations collected by the database profiler from your console.

In the following steps we will see how to use these new features, and at the end of the post are the instructions to update or install the tool.

Activating the profiler of a database

You need to activate the profiler of a database to see what is happening. In the following steps we will assume that we are connecting against a database called sales in your local computer (localhost). For more instructions of how to connect with an external database and other options, executes mongotail --help.

First at all, go to the console and activate the profiler with the -l 2 option:

$ mongotail sales -l 2
Profiling level set to level 2

Watching the logs with the new features

Once the profiling is activated, let started to see the logs. Go to a Mongo client and just execute some queries, or launch the application that connects with your database, and all the operations will be registered by the profiler. Then to see the latest instructions executed, go back to the command line and execute:

$ mongotail sales
2016-07-27 22:30:36.822 UPDATE  [mongeez] : {"type": {"$exists": false}}, {"$set": {"type": "changeSetExecution"}}. 0 updated.
2016-07-27 22:30:36.828 QUERY   [mongeez] : {"type": "configuration"}. 1 returned.
2016-07-27 22:30:36.839 COUNT   [operations] : {"user": "mrsarm", "type": ...

The first change you can see compared with previous versions is the final information at each line counting how many records were affected (0 updated. and 1 returned.).

But the more interesting feature is to see the changes in "real time" with the -f option, and occasionally filter the result with grep to find a particular operation (this is an old feature). For example, to see in "real time" only new changes, you can use the -f option and pipe the command with grep like the following:

$ mongotail sales -f | egrep "(INSERT|UPDATE|REMOVE)"

The -m option

One of the options is -m, --metadata, that give us extra metadata fields from the profiler. Fields may vary depending of the operation and the MongoDB version, some well known fields are: millis, nscanned, docsExamined, execStats and lockStats.

This is an example getting the latest 2 queries (-n 2) with the milliseconds taken by each query and some statistics about the execution:

$ mongotail sales -n 2 -m millis execStats
2016-08-10 02:01:47.646 QUERY   [users] : {"_id": ObjectId("56aa65eff7e82fee8b4433c3")}. 1 returned. millis: 0, execStats: {"needYield": 0, "docsExamined": 1, "saveState": 0, "restoreState": 0, "isEOF": 1, "nReturned": 1, "needTime": 0, "keysExamined": 1, "executionTimeMillisEstimate": 0, "invalidates": 0, "works": 1, "advanced": 1, "stage": "IDHACK"}
2016-08-10 02:04:29.654 REMOVE  [invites] : {"_id": ObjectId("57aa8b16e4b0aef63a46c4e7")}. 1 deleted. millis: 0, execStats: {}

If you want to know how many records MongoDB needs to "walk" to find a particular result, use with -m nscanned (doesn't work for all types of operations):

$ mongotail sales -n 3 -m nscanned
2016-08-10 02:04:29.654 QUERY   [ops] : {"deleted": {"$exists": false}, "prod_id": "367133"}. 2 returned. nscanned: 9

The -v option

But, how many meta-data fields are available for a query? As I said before, it depends of the operation and the MongoDB version, but you can see all the information of each operation if you use the -v, --verbose option instead of -m option. All the information will printed in "RAW" format, without the pre-formatting Mongotail does, so I don't recommend this option unless you want to know what information is available for a given query, so the next execution you can use with -m FIELD_I_FOUND_INTERESTING ...

$ mongotail sales -v
{"cursorExhausted": true, "writeConflicts": 0, "docsExamined": 1, "keysExamined": 1, "execStats": {"needYield": 0, "saveState": 0, "restoreState": 0, "isEOF": 1, "inputStage": {"needYield": 0, "docsExamined": 1, "saveState": 0, "restoreState": 0, "isEOF": 0, "inputStage": {"saveState": 0, "isEOF": 0, "seenInvalidated": 0, "keysExamined": 1, "nReturned": 1, "invalidates": 0, "keyPattern": {"_id": 1}, "isUnique": true, "needTime": 0, "isMultiKey": false, "executionTimeMillisEstimate": 0, "dupsTested": 0, "restoreState": 0, "direction": "forward", "indexName": "_id_", "isSparse": false, "advanced": 1, "stage": "IXSCAN", "dupsDropped": 0, "needYield": 0, "isPartial": false, "indexBounds": {"_id": ["[ObjectId("'5751b9a64c5c774e25434d14'), ObjectId("'5751b9a64c5c774e25434d14')]"]}, "works": 1, "indexVersion": 1}, "nReturned": 1, "needTime": 0, "filter": {"$not": {"deleted": {"$exists": true}}}, "executionTimeMillisEstimate": 0, "alreadyHasObj": 0, "invalidates": 0, "works": 1, "advanced": 1, "stage": "FETCH"}, "nReturned": 1, "needTime": 0, "executionTimeMillisEstimate": 0, "limitAmount": 1, "invalidates": 0, "works": 1, "advanced": 1, "stage": "LIMIT"}, "responseLength": 423, "millis": 0, "ts": ISODate("2016-08-10T22:56:44.951Z"), "nreturned": 1, "client": "172.17.0.4", "locks": {"Global": {"acquireCount": {"r": 2}}, "Collection": {"acquireCount": {"r": 1}}, "Database": {"acquireCount": {"r": 1}}}, "numYield": 0, "user": "", "keyUpdates": 0, "query": {"filter": {"_id": ObjectId("5751b9a64c5c774e25434d14")}, "find": "users", "ntoreturn": -1}, "ns": "sales.users", "allUsers": [], "op": "query"}
...

Find slow queries in MongoDB

When you activate the profiler with Mongotail, you can choose level 1 profiling instead of level 2. Level 1 configure the profiler system to log only "slow" operations. Then you have to set the threshold in milliseconds for the profile to consider an operation "slow". In the following example the threshold is set to 5 milliseconds:

$ mongotail sales -l 1
Profiling level set to level 1
$ mongotail sales -s 5
Threshold profiling set to 5 milliseconds

Then when you check your databases only operations that take 5 or more milliseconds will be displayed.

The -i option

The option -i, --info is a working in progress feature, but for now it gives you some useful information about your database and the MongoDB instance you are connecting to.

Considerations for production environments

Mongotail purpose is allow users debug their databases to find a particular problem, and see what is happening in real time. However the level chosen can affect performance, and the queries are written to the profiler log, which might have information security implications for production deployments. Remember to setup your database profiling level to 0 again after debugging your data:

$ mongotail sale -l 0

The profiling level configuration is not saved in any place and it's applied on the "fly", so restart the MongoDB instance always will set to level 0 (no profiling) for all databases again if you forgot doing so.

What about the new logging capabilities present in MongoDB 3.0+

Since Mongo 3.0 it's possible to debug the activity in a log file similarly other databases do, instead of save the activity in a capped collection like the MongoDB profiler does (Mongotail uses this system, watching, filtering and formatting the information saved at the system.profile collection). In this case you don't need Mongotail to see the activity, just look at the /var/log/mongodb/mongod.log file with any editor or with cat, less, tail... from the command line, but, like the profiler, the format used by the logging system is ugly, extremely verbose, and the information for a single query is displayed in many lines instead of a single one, getting less readable and more difficult to process the log using scripts.

Also some information available in the profiler system (therefore Mongotail) isn't registered in the logging system.

How to update the tool

If you have a previous version of Mongotail, in any Unix OS (Linux, OSX) you only need to execute:

$ sudo pip install mongotail --upgrade

Or if you don't have pip installed, try with easy_install:

$ sudo easy_install --upgrade mongotail

How to install the tool

Mongotail is available at PyPI Python Package Repository. You can find a more complete guide of how to install Mongotail in the README instructions. But basically to do it:

$ sudo pip install mongotail

Or if you don't have pip installed, it can be used easy_install to install Mongotail:

$ sudo easy_install mongotail

Whats next?

Well, next version I think it will be fine to add more "status" capability options, like get the consumed resource for a given instance in real time. Also I want to add some pretty print capabilities to the command, like colorizing the JSON output.

If you think there is a better feature to add, or you find a bug, go to the Issues section and post a new issue. Pull requests also are welcome!

Spanish documentation

If you want to see how to use Mongotail in "Español", you can see this previous post.

martes, 24 de marzo de 2015

Logs Queries de MongoDB con Mongotail

Mongotail es una herramienta de línea de comandos que permite ver los logs de las últimas queries (o todas) ejecutadas en una base de datos Mongo, de una manera similar a la que el comando "tail" nos permite ver las últimas líneas de un archivo. Esto es realmente útil cuando estamos teniendo problemas de performance y necesitamos saber dónde se están consumiendo los recursos, o porqué una aplicación que suponemos hace una consulta no nos devuelve el resultado que esperamos, entre otros casos de uso.

Desarrollé la herramienta con Python hace poco más de un mes, y hace unos días publiqué en los repositorios PyPI una última versión con mejoras, por lo que no es necesario saber nada de Python ni de como instalar un script en el PATH del sistema, ya que podemos instalarlo como un comando más del sistema con una herramienta llamada PIP (describiré los pasos luego).

Ejecutando mongotail NOMBRE_BBDD nos dará las últimas 10 instrucciones ejecutadas en la base de datos, pero lo más interesante es usarlo con la opción -f, que nos permite dejar el comando en modo "escucha" a que nuevas consultas sean ejecutadas en la base, las cuales serán mostradas en la consola a medida que se ejecutan. También al igual que se suele hacer con tail, podemos redireccionar la salida a un archivo log, o filtrar la salida con | (pipe) hacia algún comando que tome ésta como entrada, el caso más común es hacerlo con el comando grep para filtrar el resultado.

Pero vamos por paso, MongoDB tiene un módulo llamado Database Profiler que permite guardar información de qué queries se están ejecutando en una BBDD, y la almacena en una collection especial llamada system.profile dentro de la misma base, pero este feature por default es desactivado en todas las bases en el arranque de MongoDB, ya que ralentiza levemente la performance de las BBDDs, y también puede ser un problema de seguridad si es una base de producción a la cual no tenemos un buen control de quién accede a la misma. Por el espacio que ocupará este registro no nos debemos hacer problema, ya que es una capped collection: algo así como una tabla con estructura de cola, donde hay un tope máximo, y cuando llegamos a ese tope, los registros más antiguos son automáticamente borrados.

Usando la herramienta

Vamos a suponer que tenemos una BBDD en una instancia local de MongoDB que se llama "ventas". Para activar el logging de la BBDD ejecutamos desde la consola:

$ mongotail ventas -l 2
Profiling level set to level 2

A partir de este momento todas las queries ejecutadas serán registradas. Para mostrarlas, simplemente volvemos a ejecutar el comando anterior sin opciones, o con la opción -n NUMERO_LINEAS, que nos permite especificar cuantos comandos del historial mostrar (siempre los últimos ejecutados), o -n all, que mostrará el registro completo.

Por ejemplo, supongamos que tenemos una collection llamada "zips", y queremos listar todos los registros donde el campo "state" sea "CA" por línea de comandos con el comando mongo, o con algún otro cliente como Robomongo:

$ mongo ventas

ventas> db.zips.find({"state": "CA"})
{"_id": "90016", "city": "LOS ANGELES","loc": [-118.352787,34.029826], "pop": 43669, "state": "CA"}
{"_id": "90017", "city": "LOS ANGELES", "loc": [-118.266582, ...

Si luego desde la consola ejecutamos:

$ mongotail test
2015-03-17 12:34:12.552 QUERY  [zips] : {"state": "CA"}

Mongotail nos da información de cuándo, qué tipo de operación (QUERY, COUNT, INSERT, UPDATE, REMOVE, MAP...), qué documento y con qué parámetros fue consultada la base.

Pero como había mencionado antes, lo más interesante es usarlo con la opción -f, y ver los cambios en "tiempo real", mientras por ejemplo ejecutamos una aplicación que accede a la base. Además, como mongotail imprime el resultado en la "salida estándar", podemos redireccionarlo a un archivo de registro, o filtrar qué consultas deseamos ver con grep/egrep.

En el siguiente ejemplo, ejecutamos mongotail con la opción -f para ver las queries a medida que suceden, y además redireccionaremos la salida al comando grep para que nos filtre solo las queries que modifican la información de la base, omitiendo consulta de datos:

$ mongotail ventas -f | egrep "(INSERT|UPDATE|REMOVE)"

Al finalizar la "inspección" de queries, debemos recordar desactivar el logging por las razones ya mencionadas:

$ mongotail ventas -l 0
Profiling level set to level 0

Para ver más opciones de ejecución, ver la lista completa con:

$ mongotail --help

Instalación

La instalación en una distribución Linux es bastante sencilla, primero debemos asegurarnos de tener el comando pip instalado. Para verificarlo, simplemente ejecutamos el comando sin parámetros desde la consola:

$ pip

Si obtenemos una página de ayuda de resultado, tenemos el comando!, si en cambio obtenemos un error similar a command not found: pip, significa que tenemos que instalarlo.

En distribuciones Debian/Ubuntu,podemos hacerlo con:

$ apt-get install python-pip python-dev

Tener en cuenta que en Debian hace falta estar autenticado como usuario root, en cambio en Ubuntu podemos hacerlo directamente con cualquier usuario, pero anteponiendo al comando anterior la instrucción sudo para que nos de privilegios de administrador en la ejecución.

Finalmente, para instalar mongotail con pip, ejecutamos (también con privilegios de administrador):

$ pip install mongotail

Acerca del proyecto

Mongotil todavía está en desarrollo, es open source y pueden descargar el código fuente desde Github. Es posible que tenga algunos fallos, y que le agregue algunos features adicionales en el futuro, si tienen algún inconveniente usándolo, no duden en reportar el error en https://github.com/mrsarm/mongotail/issues.

También, pueden hacer click en el ícono "Star" con su cuenta de Github si les es útil el proyecto.

miércoles, 5 de noviembre de 2014

Grails: Fixing timeout exceptions and hibernate AssertionFailure when execute a SQL query



Some times, for a particular reason you need to perform a SQL query instead of execute a Grails/GORM operation. In these cases you can do the job writing a method in your domain models, or in your service classes like the following example:


class MyService {

 def sessionFactory

 int myCustomOperation() { 
  def session = sessionFactory.openSession()
  def sql = session.createSQLQuery(
   "SELECT field1 FROM ...MY CRAZY QUERY ... LIMIT 1")
  sql.uniqueResult().intValue()
 }
}

As you can seen, a new database session will open each time the function will call, so if the method is massively called by the application, it's possible that after the 30th or more calls, a timeout exception will rise, because the BBDD engine doesn't have more connections to give to our application.

A possible solution can be replace the openSession() call by a getCurrentSession() call, I have tried it, but the result is a new exception given the concurrent operations performed:


hibernate.AssertionFailure  - an assertion failure occured (this may indicate a bug in Hibernate, but is more likely due to unsafe use of the session)

So, coming back to the first approach, we can fix it with something that in Grails guides and Spring guides will found like something that is not necessary to do: close the session explicitly. That's all, in general lines, doing the close() operation is not necessary because Grails (Spring) do it for us, but when the operation is executed so repetitively in a short time, the framework is not able to close the connections so fast as the new sessions are opened, and in a few of seconds the limit of concurrent connections is reached.

The code above can be fixed with a few extra lines:


int myCustomOperation() {
def session = null
try {
  def query = "SELECT field1 FROM ...MY CRAZY QUERY ... LIMIT 1"
  session = sessionFactory.openSession()
  def sql = session.createSQLQuery(query)
  sql.uniqueResult().intValue()
} finally {
  if(session) session.close()
 }
}

Exceptions during the startup with "Searchable" module

Also, if you have activated the "searchble" module in your project, and the SQL method is a transient field, you have to add the field in the defaultExcludedProperties key in the grails-app/conf/Searchable.groovy configuration file, or set to false the bulkIndexOnStartup key in the same file. This is because the session is not available during the startup process for this type of operations.

lunes, 28 de octubre de 2013

New Home to Zoook-eSale Project


Zoook is e-commerce OpenERP App without connector, is developed in Python with Django framework, and is 100% compatible and designed to work with OpenERP.

Zoook e-Sale was originally developed by Zikzakmedia, and currently is unmaintained. This is an unofficial fork developed by Enterprise Objects Consulting, fully functional, with active development, free and open source, and with commercial support too.


The original project of ZZ works with OpenERP version 6.0, and does not come with all the source code. When we started the project more than a year ago, we complete all the missing code, fix and improve a lot of features, and make it work with the latest version at this time, so we migrated the modules and the dependencies to the version 6.1, and also moved the Django code to version 1.4

First we pushed all the code in a Github fork, but now all the sources was moved to Launchpad to align with the OpenERP practices, and we published the modules in OpenERP Apps.

Today is an ecommerce fully functional and stable. It is still an e-commerce system very small compared with other systems such as Magento or Prestashop, but that's what makes great Zoook: it's extremely easy for OpenERP developers to implement and extend it, as it's written in the same language, has an extremely compact code, and executes all business operations directly in OpenERP via webservices.

It's not only a shopping cart system, can be used as developement framework to construct any web application integrated with OpenERP.

I was working these weeks in the new site where all the code reside, the installation guide, and also I created a repository with all dependencies of third party modules. The project are in https://launchpad.net/zoook-esale.

I hope collaborators will join to the project, a lot of improvements still to be done. And maybe the main task is migrate the modules to latest OpenERP, now the version 7.0.

miércoles, 16 de octubre de 2013

Re-deploy Plugin Ext en Liferay con Tomcat


Para deployar por primera vez un Plugin-Ext en Liferay corriendo sobre un Tomcat basta con deployarlo en "caliente" sobre la carpeta deploy/ y restartear, pero luego de la primera vez este método ya no funciona.

Esta es la forma "oficial" para la versión 6.x, aunque no bien documentada en Liferay.com.

Requerimientos:


  • Tener el Plugin Ext que queremos deployar empaquetado en formato .war
  • Tener todos los .war de todos los portlets deployados en nuestra instancia de Liferay.
  • Tener el "unbundled Liferay web application", se puede descarcar desde la página Additional Files, sección "Download WARs". Lo descargamos y renombramos a ROOT.war.
  • Hacer un backup ! Nunca hagas un deploy, y menos de un Ext, sin haber echo un backup tanto de la BBDD, como de la carpeta donde está Liferay instalado.


Pasos:


  1. Shutdown de la instancia
  2. Borrar del Tomcat webapps/*, work/* y temp/*. También lib/ext/*-ext*.jar
  3. Copiar en webapps/ el empaquetado de Liferay ROOT.war, y todos los .war de los portlets y themes en deploy/, excepto el Plugin Ext
  4. Startup de la instancia
  5. Luego de que arrancó y deployó, copiar el war del Ext en la carpeta deploy/
  6. Esperar a que termine el proceso de deploy (ver el log). Shutdown
  7. Copiar los .war de todos los plugins excepto los plugins Ext en deploy/nuevamente
  8. Startup


Otra manera que puede resultar más rápido, pero que no garantiza el redeploy en todos los casos (aparentemente no redeploya bien en los casos en que se cambian desde el Ext archivos JavaScript):
http://www.liferay.com/de/community/wiki/-/wiki/Main/Ext+Plugin