The Stack Trace

MasonHub’s Order Management System (OMS) logs and keeps version of all the work it does. Every request from our clients, every queued item we process, we record and connect back to the preceding action that either called it or caused it. In programming parlance, this is typically called the stack trace. It allows engineers to walk back through the execution path of the code and find an error or a performance bottleneck. In any complex and integrated system, like, say, an order management system, figuring out where something went wrong or how an integration played out can be extremely difficult.

Which is why we put logging and connecting the dots throughout the application front and center from the very beginning. As a 3PL, we need to know what happened, when it happened, and how to troubleshoot, if need be. For us, it’s not a feature of our product, it is our product. Our warrant is that our system is accurate, reliable, and repeatable, and the stack trace is essential to keeping and proving the system is just that.

The Stack

On it’s face, the “stack” is actually quite simple. For illustration purposes, the image below shows the progression of a call into the MasonHub API and the points where we log and store data. Request Flow

But it’s probably more fun to look at the records we store along the way:

Inbound Requests

Say a client posts to the Skus endpoint in order to create some skus in their item catalog. We’ll first record the request and our response to the request as below:

id               | 43f66b48-24bd-4c17-bc0f-16355861beb5
account_id       | [account id for test account]
request_method   | POST
request_url      | /test/api/v1/skus
request_headers  | user-agent: PostmanRuntime/7.4.0,cache-control: no-cache,cookie: _masonhub_session=MTU0MzU0MTczOHxEdi1CQkFFQ180SUFBUkFCRUFBQV85N19nZ0FFQm5OMGNtbHVad3dKQUFkZlpteGhjMmhmQjF0ZGRXbHVkRGdLQkFBQ2UzMEdjM1J5YVc1bkRBNEFESEpsY1hWbGMzUnZjbDlwWkFaemRISnBibWNNREFBS1RsSmhhMlJVV1ZSSmJ3WnpkSEpwYm1jTURnQU1ZV05qYjNWdWRGOXpiSFZuQm5OMGNtbHVad3dHQUFSMFpYTjBCbk4wY21sdVp3d01BQXBoWTJOdmRXNTBYMmxrUW0xaGMyOXVhSFZpTG1OdkwzZGxZbDl2Y21SbGNsOXRZVzVoWjJWdFpXNTBMM1psYm1SdmNpOW5hWFJvZFdJdVkyOXRMMmR2Wm5KekwzVjFhV1F1VlZWSlJQLURCZ0VCQkZWVlNVUUJfNFFBQUFBVl80UVNBQkJQRUhFNEtQektfYVVwbC1WR296STV8SPvN_wJXo-KW5BqyZVQxpYsUP9Trn3Lu1kC1v-kg2H4=,via: 1.1 spaces-router (fb604cb97f2b),content-length: 802,accept: */*,authorization: [Redacted],x-request-id: a9c818f6-2699-b835-8d4d-a2d7bd1d59cd,accept-encoding: gzip, deflate,content-type: application/json,x-forwarded-port: 443,x-forwarded-proto: https,x-forwarded-for: 173.63.125.160,x-request-start: 1543541743338
request_body     |
[                                                                        
        {                                                                
                "customer_identifier": "kit00001",                       
                "brand_name": "peter piper",                             
                "customer_bar_code": "kit234523",                        
                "customer_brand_code": "pp",                             
                "customer_color": "w",                                   
                "brand_code": "3",                                       
                "dim_height": 12,                                        
                "dim_weight": 10,                                        
                "dim_length": 2,                                         
                "dim_volume": 3,                                         
                "image_url": "http://bohemianrhapsody.com/img432523.jpg",
                "price": 15.95,                                          
                "unit_cost": 5.95,                                       
                "product_category": "shirt",                             
                "product_sub_category": "man blouse",                    
                "size": "M",                                             
                "vendor_bar_code": "kit675443",                          
                "vendor_brand_code": "pete's",                           
                "vendor_color": "WHITE",                                 
                "product_name": "McShirt",                               
                "product_description": "This is my product description",
                "is_kit": true,                                          
                "kit_skus": [                                            
                        {                                                
                                "customer_identifier": "10000",          
                                "quantity": 2                            
                        },                                               
                        {                                                
                                "customer_identifier": "10001",          
                                "quantity": 1                            
                        }                                                
                ]                                                        
        }                                                                

response_headers | content-type: application/json,set-cookie: _masonhub_session=MTU0MzU0MTc0M3xEdi1CQkFFQ180SUFBUkFCRUFBQV85N19nZ0FFQm5OMGNtbHVad3dKQUFkZlpteGhjMmhmQjF0ZGRXbHVkRGdLQkFBQ2UzMEdjM1J5YVc1bkRBNEFESEpsY1hWbGMzUnZjbDlwWkFaemRISnBibWNNREFBS1RsSmhhMlJVV1ZSSmJ3WnpkSEpwYm1jTURnQU1ZV05qYjNWdWRGOXpiSFZuQm5OMGNtbHVad3dHQUFSMFpYTjBCbk4wY21sdVp3d01BQXBoWTJOdmRXNTBYMmxrUW0xaGMyOXVhSFZpTG1OdkwzZGxZbDl2Y21SbGNsOXRZVzVoWjJWdFpXNTBMM1psYm1SdmNpOW5hWFJvZFdJdVkyOXRMMmR2Wm5KekwzVjFhV1F1VlZWSlJQLURCZ0VCQkZWVlNVUUJfNFFBQUFBVl80UVNBQkJQRUhFNEtQektfYVVwbC1WR296STV8xNQiGlKFC8PO7CXNFwQ8rFQHjlPVJaNeIId73Ni4vvk=; Path=/; Expires=Sun, 30 Dec 2018 01:35:43 GMT; Max-Age=2592000
response_body    |
{
  "records_submitted":1,
  "records_processed":1,
  "records_failed":0,
  "records_succeeded":1,
  "results":[
    {
      "customer_identifier":"kit00001",
      "status":"success",
      "uri":"https://sandbox.masonhub.co/test/api/v1/skus?cid=kit00001"
    }
  ]
}                 
response_code    | 200
created_at       | 2018-11-30 01:35:43.3707+00
updated_at       | 2018-11-30 01:35:43.370703+00
request_id       | NRakdTYTIo-ZnozabOBxQ

Because all calls to the MasonHub API are non-blocking, it’s important that we record not only the inbound request, but our response to that request which has in it the validation results for all posted skus. After we’ve recorded the initial request, we then split the array of skus into individual queued payloads for persistence. Each payload is then processed individually, with processing time and processing results recorded as in the example below:

id               | 798d67b0-ca41-4310-80c2-d760fa363ff8
account_id       | [account id hidden to protect the innocent]
json             | {"id":null,"customer_identifier":"3342336657679876986","customer_bar_code":"324gjhfjkhgf2342","vendor_bar_code":"2342345dfghzsdf342","pick_style":"FIFO","brand_name":"peter piper","product_name":"McShirt","product_category":"shirt","product_sub_category":"man blouse","product_description":"This is my product description","image_url":"http://bohemianrhapsody.com/img432523.jpg","vendor_brand_code":"pete's","customer_brand_code":"pp","customer_color":"w","vendor_color":"WHITE","size":"M","ormd":false,"lot_controlled":false,"expirable":false,"unit_cost":5.95,"price":15.95,"dim_weight":10,"dim_length":2,"dim_height":12,"dim_volume":3,"created_at":"0001-01-01T00:00:00Z","updated_at":"0001-01-01T00:00:00Z","deleted_at":null,"inventory_totals":{"sku_id":"00000000-0000-0000-0000-000000000000","total_units":0,"total_available_to_sell":0,"as_of":"0001-01-01T00:00:00Z"}}
created_at       | 2018-11-21 21:29:56.922172
processed_at     | 2018-11-21 21:29:57.841147
process_result   | success
process_messages |

In the full system, the story wouldn’t end there, it would be queued again for persistence into the WMS and that would come with a set of payloads and queue results for the subsequent actions.

Outbound messages

Obviously, the MasonHub OMS talks back to our customers through a series of callbacks/webhooks. Each one of the actions that lead to the callback along with the callback itself is recorded as well. Let’s take a skuInventoryChange message for example. Every inventory change starts with a ledger entry and each of those ledger entries references the calling action. In the example below, it was triggered in the sandbox via a data factory action.

id                    | ae973696-57f6-4dd7-b1c9-c9c0fd5c2dea
account_id            | [account id hidden to protect the innocent]
inventory_location_id | bf7bb516-ce52-8950-2a8b-9008f0091d93
sku_id                | e5d00ff6-b34a-496e-9559-eb90e99463af
reference_item_uri    | app.masonhub.co/[account id hidden to protect the innocent]/payload/676954fa-d6b2-47ff-b20e-cefac216ac65
actor_uri             | data factory create available
entry_type            | expected
quantity              | 100
occured_at            | 2018-11-21 16:13:30.612314+00
created_at            | 2018-11-21 16:13:30.652487+00

Those are then compiled into inventory_calculations and inventory_totals. Each cached calculation is stored and older versions archived for future retrieval, and every ledger entry used to build a total is recorded for auditing and reporting. This allows for infinite replay of calculations and gives us the ability to track how inventory totals were built.

Once an inventory calculation has been made, outbound messages are sent to clients so they can update their systems. These are recorded in detail as well, both the message at the point in time it was sent and the response we received from the endpoint provided by the client along with any errors we encountered issuing the callback (example below).

id               | e58769ec-c4cf-47f9-b80a-378a9b85aeae
account_id       | 4f107138-28fc-cafd-a529-97e546a33239
message_type     | skuInventoryChange
outbound_url     | https://mister-bucket.herokuapp.com/api/bucket/skuInventoryChange
response_headers | via: 1.1 vegur,server: Cowboy,connection: keep-alive,content-type: application/json,set-cookie: _mister_bucket_session=MTU0MjUwMTgxMnxEdi1CQkFFQ180SUFBUkFCRUFBQU1QLUNBQUVHYzNSeWFXNW5EQTRBREhKbGNYVmxjM1J2Y2w5cFpBWnpkSEpwYm1jTURBQUtNRFJqWkRsaFl6UTFZUT09fLOrMOBAxDuyo5QJ52c4jy0sWtq2dbnkha9WIaZ6_jpW; Path=/; Expires=Tue, 18 Dec 2018 00:43:32 GMT; Max-Age=2592000,set-cookie: _mister_bucket_session=MTU0MjUwMTgxMnxEdi1CQkFFQ180SUFBUkFCRUFBQVVQLUNBQUlHYzNSeWFXNW5EQTRBREhKbGNYVmxjM1J2Y2w5cFpBWnpkSEpwYm1jTURBQUtNRFJqWkRsaFl6UTFZUVp6ZEhKcGJtY01DUUFIWDJac1lYTm9Yd2RiWFhWcGJuUTRDZ1FBQW50OXyna3qhn4doEYZ62pS9kmdMz3wObeYqLFzwXGGpt8acxg==; Path=/; Expires=Tue, 18 Dec 2018 00:43:32 GMT; Max-Age=2592000,date: Sun, 18 Nov 2018 00:43:32 GMT,content-length: 1895
response_body    | {"id":"39777d0e-1b15-4121-b403-a0a902263c07","created_at":"2018-11-18T00:43:32.340280977Z","updated_at":"2018-11-18T00:43:32.340284129Z","request_action":"skuInventoryChange","payload":"{\"callback_url\":\"https://mister-bucket.herokuapp.com/api/bucket/skuInventoryChange\",\"message_type\":\"skuInventoryChange\",\"message_id\":\"e58769ec-c4cf-47f9-b80a-378a9b85aeae\",\"data\":\"[{\\\"sku_id\\\":\\\"e5d00ff6-b34a-496e-9559-eb90e99463af\\\",\\\"customer_identifier\\\":\\\"10000\\\",\\\"total_units\\\":200,\\\"total_available_to_sell\\\":100,\\\"as_of\\\":\\\"2018-11-18T00:43:23.095637Z\\\",\\\"status_counts\\\":[{\\\"inventory_location_id\\\":\\\"bf7bb516-ce52-8950-2a8b-9008f0091d93\\\",\\\"inventory_location_address\\\":\\\"MasonHub - Rancho Cucamonga | 8595 Milliken Avenue, B102 Rancho Cucamonga, CA 91730\\\",\\\"inventory_status\\\":\\\"available\\\",\\\"quantity\\\":100,\\\"as_of\\\":\\\"2018-11-18T00:43:22.664965Z\\\"},{\\\"inventory_location_id\\\":\\\"bf7bb516-ce52-8950-2a8b-9008f0091d93\\\",\\\"inventory_location_address\\\":\\\"MasonHub - Rancho Cucamonga | 8595 Milliken Avenue, B102 Rancho Cucamonga, CA 91730\\\",\\\"inventory_status\\\":\\\"received\\\",\\\"quantity\\\":100,\\\"as_of\\\":\\\"2018-11-18T00:43:23.095637Z\\\"},{\\\"inventory_location_id\\\":\\\"bf7bb516-ce52-8950-2a8b-9008f0091d93\\\",\\\"inventory_location_address\\\":\\\"MasonHub - Rancho Cucamonga | 8595 Milliken Avenue, B102 Rancho Cucamonga, CA 91730\\\",\\\"inventory_status\\\":\\\"in-receiving\\\",\\\"quantity\\\":0,\\\"as_of\\\":\\\"2018-11-18T00:43:23.095637Z\\\"},{\\\"inventory_location_id\\\":\\\"bf7bb516-ce52-8950-2a8b-9008f0091d93\\\",\\\"inventory_location_address\\\":\\\"MasonHub - Rancho Cucamonga | 8595 Milliken Avenue, B102 Rancho Cucamonga, CA 91730\\\",\\\"inventory_status\\\":\\\"expected\\\",\\\"quantity\\\":0,\\\"as_of\\\":\\\"2018-11-18T00:43:22.345419Z\\\"}]}]\"}"}                           
                 |
payload          | [{"sku_id":"e5d00ff6-b34a-496e-9559-eb90e99463af","customer_identifier":"10000","total_units":200,"total_available_to_sell":100,"as_of":"2018-11-18T00:43:23.095637Z","status_counts":[{"inventory_location_id":"bf7bb516-ce52-8950-2a8b-9008f0091d93","inventory_location_address":"MasonHub - Rancho Cucamonga | 8595 Milliken Avenue, B102 Rancho Cucamonga, CA 91730","inventory_status":"available","quantity":100,"as_of":"2018-11-18T00:43:22.664965Z"},{"inventory_location_id":"bf7bb516-ce52-8950-2a8b-9008f0091d93","inventory_location_address":"MasonHub - Rancho Cucamonga | 8595 Milliken Avenue, B102 Rancho Cucamonga, CA 91730","inventory_status":"received","quantity":100,"as_of":"2018-11-18T00:43:23.095637Z"},{"inventory_location_id":"bf7bb516-ce52-8950-2a8b-9008f0091d93","inventory_location_address":"MasonHub - Rancho Cucamonga | 8595 Milliken Avenue, B102 Rancho Cucamonga, CA 91730","inventory_status":"in-receiving","quantity":0,"as_of":"2018-11-18T00:43:23.095637Z"},{"inventory_location_id":"bf7bb516-ce52-8950-2a8b-9008f0091d93","inventory_location_address":"MasonHub - Rancho Cucamonga | 8595 Milliken Avenue, B102 Rancho Cucamonga, CA 91730","inventory_status":"expected","quantity":0,"as_of":"2018-11-18T00:43:22.345419Z"}]}]
created_at       | 2018-11-18 00:43:25.904553+00
message_key      | bf7bb516-ce52-8950-2a8b-9008f0091d93_e5d00ff6-b34a-496e-9559-eb90e99463af
response_code    | 200
processed_at     | 2018-11-18 00:43:32.349294+00
process_result   | sent
process_messages |
bearer_token     | [redacted]
send_most_recent | t
occured_at       | 2018-11-18 00:43:23.095637+00

All of these items are stored with a URI (Universal Resource Identifier) that allows our systems to tie arbitrary items together and allow our systems to trace back actions to their source. In the future, we’ll display these records and the reference and actor objects in our administrative UI, but for now we wanted to make sure that our clients understood the level of detail we store to ensure nothing gets lost in translation and everything is recoverable.

Don’t be afraid to reach out to Chris or Andy with any questions.

Sidenote: You may have noticed the mister-bucket.herokuapp.com url. Mr. Bucket is our smoke test service. It is so named because it receives all requests for later inspection. Mr. Bucket, in this instance, responds with the original payload, which is atypical in a production system, but it does allow us to check that things are working. Mr. Bucket is also accompanied by Mrs. Shovel, which can create thousands of records in our test accounts and allows us to check out how our systems perform under load or deal with race conditions.