Brian Waters | 13d9601 | 2017-12-08 16:53:31 -0600 | [diff] [blame] | 1 | /********************************************************************************************************* |
| 2 | * Software License Agreement (BSD License) * |
| 3 | * Author: Sebastien Decugis <sdecugis@freediameter.net> * |
| 4 | * * |
| 5 | * Copyright (c) 2013, WIDE Project and NICT * |
| 6 | * All rights reserved. * |
| 7 | * * |
| 8 | * Redistribution and use of this software in source and binary forms, with or without modification, are * |
| 9 | * permitted provided that the following conditions are met: * |
| 10 | * * |
| 11 | * * Redistributions of source code must retain the above * |
| 12 | * copyright notice, this list of conditions and the * |
| 13 | * following disclaimer. * |
| 14 | * * |
| 15 | * * Redistributions in binary form must reproduce the above * |
| 16 | * copyright notice, this list of conditions and the * |
| 17 | * following disclaimer in the documentation and/or other * |
| 18 | * materials provided with the distribution. * |
| 19 | * * |
| 20 | * * Neither the name of the WIDE Project or NICT nor the * |
| 21 | * names of its contributors may be used to endorse or * |
| 22 | * promote products derived from this software without * |
| 23 | * specific prior written permission of WIDE Project and * |
| 24 | * NICT. * |
| 25 | * * |
| 26 | * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" AND ANY EXPRESS OR IMPLIED * |
| 27 | * WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A * |
| 28 | * PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE LIABLE FOR * |
| 29 | * ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT * |
| 30 | * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS * |
| 31 | * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR * |
| 32 | * TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF * |
| 33 | * ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. * |
| 34 | *********************************************************************************************************/ |
| 35 | |
| 36 | /* This extension uses the hooks mechanism to compute some timing information related to messages */ |
| 37 | |
| 38 | #include <freeDiameter/extension.h> |
| 39 | |
| 40 | struct fd_hook_permsgdata { |
| 41 | struct timespec received_on; |
| 42 | struct timespec sent_on; |
| 43 | }; |
| 44 | |
| 45 | static struct fd_hook_data_hdl *mt_data_hdl = NULL; |
| 46 | static struct fd_hook_hdl *mt_hdl = NULL; |
| 47 | |
| 48 | /* The callback called when messages are received and sent */ |
| 49 | static void mt_hook_cb(enum fd_hook_type type, struct msg * msg, struct peer_hdr * peer, void * other, struct fd_hook_permsgdata *pmd, void * regdata) |
| 50 | { |
| 51 | struct msg_hdr * hdr; |
| 52 | char * buf = NULL; |
| 53 | size_t len; |
| 54 | |
| 55 | ASSERT(pmd); |
| 56 | |
| 57 | if (type == HOOK_DATA_RECEIVED) { |
| 58 | /* We just store the timestamp it was received on */ |
| 59 | (void)clock_gettime(CLOCK_REALTIME, &pmd->received_on); |
| 60 | return; |
| 61 | } |
| 62 | |
| 63 | ASSERT(msg); |
| 64 | |
| 65 | /* Check if this message is request or answer */ |
| 66 | CHECK_FCT_DO( fd_msg_hdr(msg, &hdr), return); |
| 67 | |
| 68 | if (type == HOOK_MESSAGE_RECEIVED) { |
| 69 | ASSERT(pmd->received_on.tv_sec); /* otherwise it means the HOOK_DATA_RECEIVED hook was not trigged for this message */ |
| 70 | if (hdr->msg_flags & CMD_FLAG_REQUEST) { |
| 71 | /* We have received a new request, nothing special to do */ |
| 72 | } else { |
| 73 | /* This is an answer, check how long it took to get it */ |
| 74 | struct fd_hook_permsgdata *qpmd = fd_hook_get_request_pmd(mt_data_hdl, msg); |
| 75 | struct timespec delay; |
| 76 | ASSERT(qpmd); /* If we do not have it, we must find out why */ |
| 77 | ASSERT(qpmd->sent_on.tv_sec); /* same, would mean the HOOK_MESSAGE_SENT hook was not trigged */ |
| 78 | TS_DIFFERENCE( &delay, &qpmd->sent_on, &pmd->received_on ); |
| 79 | CHECK_MALLOC_DO( fd_msg_dump_summary(&buf, &len, NULL, msg, NULL, 0, 1), return ); |
| 80 | LOG_N("[TIMING] RCV ANS %ld.%06ld sec <-'%s': %s", (long)delay.tv_sec, delay.tv_nsec / 1000, peer ? peer->info.pi_diamid : "<unidentified>", buf); |
| 81 | } |
| 82 | } else if (type == HOOK_MESSAGE_SENT) { |
| 83 | DiamId_t source = NULL; |
| 84 | |
| 85 | (void)clock_gettime(CLOCK_REALTIME, &pmd->sent_on); |
| 86 | |
| 87 | /* Is this a forwarded message ? */ |
| 88 | CHECK_FCT_DO( fd_msg_source_get(msg, &source, NULL), return ); |
| 89 | if (source) { |
| 90 | struct timespec delay; |
| 91 | ASSERT(pmd->received_on.tv_sec); |
| 92 | TS_DIFFERENCE( &delay, &pmd->received_on, &pmd->sent_on ); |
| 93 | CHECK_MALLOC_DO( fd_msg_dump_summary(&buf, &len, NULL, msg, NULL, 0, 1), return ); |
| 94 | LOG_N("[TIMING] FWD %ld.%06ld sec '%s'->'%s': %s", (long)delay.tv_sec, delay.tv_nsec / 1000, source, peer ? peer->info.pi_diamid : "<unidentified>", buf); |
| 95 | } else if (hdr->msg_flags & CMD_FLAG_REQUEST) { |
| 96 | /* We are sending a request issued locally, nothing special to log */ |
| 97 | } else { |
| 98 | /* We have generated an anwer, log the time it took since the corresponding request was received */ |
| 99 | struct fd_hook_permsgdata *qpmd = fd_hook_get_request_pmd(mt_data_hdl, msg); |
| 100 | if (qpmd->received_on.tv_sec) { |
| 101 | struct timespec delay; |
| 102 | TS_DIFFERENCE( &delay, &qpmd->received_on, &pmd->sent_on ); |
| 103 | CHECK_MALLOC_DO( fd_msg_dump_summary(&buf, &len, NULL, msg, NULL, 0, 1), return ); |
| 104 | LOG_N("[TIMING] ANS %ld.%06ld sec ->'%s': %s", (long)delay.tv_sec, delay.tv_nsec / 1000, peer ? peer->info.pi_diamid : "<unidentified>", buf); |
| 105 | } |
| 106 | } |
| 107 | } |
| 108 | |
| 109 | free(buf); |
| 110 | } |
| 111 | |
| 112 | /* Entry point */ |
| 113 | static int mt_main(char * conffile) |
| 114 | { |
| 115 | TRACE_ENTRY("%p", conffile); |
| 116 | |
| 117 | CHECK_FCT( fd_hook_data_register( sizeof(struct fd_hook_permsgdata), NULL, NULL, &mt_data_hdl ) ); |
| 118 | |
| 119 | CHECK_FCT( fd_hook_register( HOOK_MASK( HOOK_MESSAGE_RECEIVED, HOOK_MESSAGE_SENT, HOOK_DATA_RECEIVED ), |
| 120 | mt_hook_cb, NULL, mt_data_hdl, &mt_hdl) ); |
| 121 | |
| 122 | return 0; |
| 123 | } |
| 124 | |
| 125 | /* Cleanup */ |
| 126 | void fd_ext_fini(void) |
| 127 | { |
| 128 | TRACE_ENTRY(); |
| 129 | CHECK_FCT_DO( fd_hook_unregister( mt_hdl ), ); |
| 130 | return ; |
| 131 | } |
| 132 | |
| 133 | EXTENSION_ENTRY("dbg_msg_timing", mt_main); |