Metaswitch/sprout — pull request #667 by rkd-msw (2014-07-22 14:09:25+00:00)
Title: [Reviewer: Alex] Fix memcached ordering and improve SAS traces

The first part of this (i.e. the first commit) fixes https://github.com/Metaswitch/sprout/issues/662 using the approach agreed in this issue (writing to av//impi/nonce/authdone to indicate that a REGISTER flow has finished successfully, not deleting av//impi/nonce, which introduces a race condition).

The second part fixes https://github.com/Metaswitch/sprout/issues/664 - ensuring that AUTHENTICATION_TIMEOUTs get logged to SAS - and sorts out https://github.com/Metaswitch/sprout/issues/343 along the way. This means that:

* Call-ID markers are no longer raised for REGISTERs, SUBSCRIBEs and NOTIFYs
* The REGISTER-401, REGISTER-200 and any timeout flows are correlated together in SAS
* Subsequent unchallenged re-REGISTERs and de-REGISTERs appear in their own SAS trail
* NOTIFYs are logged in the same SAS trail as the message that triggered them (either a SUBSCRIBE or a REGISTER)

Testing:
* A call that looks the same as before: http://sas.cw-ngv.com/serviceassurance/tview/view/eJxjZGBgmDhViQEEAAl_AUo=?sg_inst_id=7215
* Successful REGISTER: http://sas.cw-ngv.com/serviceassurance/tview/view/eJxjZGBgaJuqxAACAAknAT8=?sg_inst_id=7224
* Failed REGISTER with timeout:http://sas.cw-ngv.com/serviceassurance/tview/view/eJxjZGBgKJyuxAACAAiNASw=?sg_inst_id=7333
* Two re-REGISTERs close together, with the same Call-ID, but not correlated: http://sas.cw-ngv.com/serviceassurance/tview/view/eJxjZGBgODJViQEEAAsXAX0=?sg_inst_id=7271, http://sas.cw-ngv.com/serviceassurance/tview/view/eJxjZGBgODZViQEEAAsnAX8=?sg_inst_id=7272
* SUBSCRIBE triggering a NOTIFY: http://sas.cw-ngv.com/serviceassurance/tview/view/eJxjZGBgcJqsxAACAAb5APk=?sg_inst_id=7071
* REGISTER triggering a NOTIFY: http://sas.cw-ngv.com/serviceassurance/tview/view/eJxjZGBg8J6sxAACAAdBAQI=?sg_inst_id=7072

I found all these by just searching on the DN, so they're easily findable in the SAS UI.