Using Giraffe


2022-05-27 - Giraffe is now maintained at https://github.com/library-data-platform/giraffe and has been updated to support the new Okapi log format.

Introduction

Giraffe is a handy tool created by the FOLIO community that graphs calls to/from Okapi for a single API call using the information provided by the modules in the trace headers. Giraffe can be useful to understand the underlying calls to modules that are involved in the API call, their pattern and response time. This tool gives allows a developer or a tester to visualize how the calls are made to gain further insight into the system.

Using Giraffe

Giraffe can be found here: https://github.com/folio-labs/giraffe

  1. Download the Giraffe source code
  2. Follow instructions on Giraffe's README to install Go and Graphviz.
  3. Make sure that Okapi's log level is INFO. If it's not in INFO, switch it to INFO.
  4. Run a manual API call (either from Postman or a similar tool, or from FOLIO UI once). Take note of the time of the run
  5. Go to Okapi log and search for the log statements at that precise timestamp
  6. Here is a snippet of Okapi log

    05:27:07 INFO ProxyContext 139655/circulation;338790/instance-storage RES 202 2352us mod-authtoken-2.4.0 http://pvt.lb.q1b.folio-eis.us-east-1:8051/mod-authtoken/instance-storage/instances/777edd64-58c7-42a6-8374-736f0946b954 
    05:27:07 INFO ProxyContext 180978/proxy REQ 10.23.36.103:62560 supertenant GET /_/proxy/health okapi-2.37.2 
    05:27:07 INFO ProxyContext 180978/proxy RES 200 25us okapi-2.37.2 /_/proxy/health 
    05:27:07 INFO ProxyContext 139655/circulation;338790/instance-storage RES 200 10298us mod-inventory-storage-19.1.3 http://pvt.lb.q1b.folio-eis.us-east-1:8051/mod-inventory-storage/instance-storage/instances/777edd64-58c7-42a6-8374-736f0946b954 
    05:27:07 INFO ProxyContext 356119/circulation;102182/loan-types RES 200 4987us mod-inventory-storage-19.1.3 http://pvt.lb.q1b.folio-eis.us-east-1:8051/mod-inventory-storage/loan-types?query=id%3D%3D%28%22ac19815e-1d8e-473f-bd5a-3193cb301b8b%22%20or%20%2223e4f1ec-cf31-4098-959e-de64ce4781ce%22%29&limit=2147483647 05:27:07 INFO ProxyContext 970897/proxy REQ 10.23.36.103:35466 supertenant GET /_/proxy/health okapi-2.37.2 
    05:27:07 INFO ProxyContext 970897/proxy RES 200 19us okapi-2.37.2 /_/proxy/health 
    05:27:07 INFO ProxyContext 139655/circulation;393636/locations REQ 10.23.36.103:55698 fs09000000 GET /locations/24be4408-fb6f-4a44-9c91-ecd4982d7849 mod-authtoken-2.4.0 mod-inventory-storage-19.1.3 
    05:27:07 INFO ProxyContext 356119/circulation;878397/location-units REQ 10.23.36.103:62560 fs09000000 GET /location-units/libraries mod-authtoken-2.4.0 mod-inventory-storage-19.1.3 
    05:27:07 INFO ProxyContext 139655/circulation;393636/locations RES 202 2698us mod-authtoken-2.4.0 http://pvt.lb.q1b.folio-eis.us-east-1:8051/mod-authtoken/locations/24be4408-fb6f-4a44-9c91-ecd4982d7849 
    05:27:07 INFO ProxyContext 356119/circulation;878397/location-units RES 202 2909us mod-authtoken-2.4.0 http://pvt.lb.q1b.folio-eis.us-east-1:8051/mod-authtoken/location-units/libraries?query=id%3D%3D%28%220381d93d-8ad6-4158-8c01-c446faa37437%22%29&limit=2147483647
    Note that the log statement has a leading number before the module, such as "139655/circulation".  This number is the Okapi transaction ID.  Okapi logs will have various calls concurrently interleaved with each other so we need to find and group all lines that have the same IDs together. Important to keep their order when grouping them.  Each group (by Okapi transaction ID) should have its own file so that Giraffe can generate the graph for each set of calls into its own file/image.  On Linux this can simply be done with the grep command:
    $ grep <okapiTransactionID> okapi.log > <okapiTransactionId>.log

  7. Get the logs to look like this: (See Okapi Log Formatting for more details)

    2020-06-12 05:27:07 INFO  ProxyContext        139655/circulation REQ 10.23.36.103:11578 fs09000000 GET /circulation/requests/1f2c0c34-5212-4dac-92b4-3c9e655fd874  mod-authtoken-2.4.0 mod-circulation-18.0.11
    2020-06-12 05:27:07 INFO  ProxyContext        139655/circulation RES 202 3062us mod-authtoken-2.4.0 http://pvt.lb.q1b.folio-eis.us-east-1:8051/mod-authtoken/circulation/requests/1f2c0c34-5212-4dac-92b4-3c9e655fd874
    2020-06-12 05:27:07 INFO  ProxyContext        139655/circulation;879664/request-storage REQ 10.23.36.226:19442 fs09000000 GET /request-storage/requests/1f2c0c34-5212-4dac-92b4-3c9e655fd874  mod-authtoken-2.4.0 mod-circulation-storage-11.0.0
    2020-06-12 05:27:07 INFO  ProxyContext        139655/circulation;879664/request-storage RES 202 4444us mod-authtoken-2.4.0 http://pvt.lb.q1b.folio-eis.us-east-1:8051/mod-authtoken/request-storage/requests/1f2c0c34-5212-4dac-92b4-3c9e655fd874
    2020-06-12 05:27:07 INFO  ProxyContext        139655/circulation;879664/request-storage RES 200 4695us mod-circulation-storage-11.0.0 http://pvt.lb.q1b.folio-eis.us-east-1:8051/mod-circulation-storage/request-storage/requests/1f2c0c34-5212-4dac-92b4-3c9e655fd874
    2020-06-12 05:27:07 INFO  ProxyContext        139655/circulation;271055/item-storage REQ 10.23.36.226:19442 fs09000000 GET /item-storage/items/5e51585b-19e0-4107-914c-7b847d1a771e  mod-authtoken-2.4.0 mod-inventory-storage-19.1.3
    2020-06-12 05:27:07 INFO  ProxyContext        139655/circulation;271055/item-storage RES 202 4274us mod-authtoken-2.4.0 http://pvt.lb.q1b.folio-eis.us-east-1:8051/mod-authtoken/item-storage/items/5e51585b-19e0-4107-914c-7b847d1a771e
    2020-06-12 05:27:07 INFO  ProxyContext        139655/circulation;271055/item-storage RES 200 8808us mod-inventory-storage-19.1.3 http://pvt.lb.q1b.folio-eis.us-east-1:8051/mod-inventory-storage/item-storage/items/5e51585b-19e0-4107-914c-7b847d1a771e
    2020-06-12 05:27:07 INFO  ProxyContext        139655/circulation;390035/holdings-storage REQ 10.23.36.103:62560 fs09000000 GET /holdings-storage/holdings/f9b05aa4-0f30-4a77-b7c5-e4fec6df0725  mod-authtoken-2.4.0 mod-inventory-storage-19.1.3
    2020-06-12 05:27:07 INFO  ProxyContext        139655/circulation;390035/holdings-storage RES 202 3430us mod-authtoken-2.4.0 http://pvt.lb.q1b.folio-eis.us-east-1:8051/mod-authtoken/holdings-storage/holdings/f9b05aa4-0f30-4a77-b7c5-e4fec6df0725

    Note the that the timestamp now has the date component.  The log needs to be in this exact format for Giraffe to run.

  8. Execute the following command from the go/bin directory to run Giraffe.  It's better to output it as a PNG file than a PDF file because image software are better at zooming in and out of the image than a PDF reader.

    $ ./giraffe call -i sample.log -o sample.png -T png