Mercurial > hg > freeDiameter
comparison extensions/dbg_msg_timings/dbg_msg_timings.c @ 1121:ccbd1426e04a
Improve testmesg_stress to measure impact of loaded dictionary
author | Sebastien Decugis <sdecugis@freediameter.net> |
---|---|
date | Tue, 14 May 2013 15:27:28 +0800 |
parents | d8591b1c56cd |
children | 7c5449ddc434 |
comparison
equal
deleted
inserted
replaced
1120:c473581adff2 | 1121:ccbd1426e04a |
---|---|
75 struct timespec delay; | 75 struct timespec delay; |
76 ASSERT(qpmd); /* If we do not have it, we must find out why */ | 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 */ | 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 ); | 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 ); | 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", (long)delay.tv_sec, delay.tv_nsec / 1000, buf); | 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 } | 81 } |
82 } else if (type == HOOK_MESSAGE_SENT) { | 82 } else if (type == HOOK_MESSAGE_SENT) { |
83 DiamId_t source = NULL; | 83 DiamId_t source = NULL; |
84 size_t slen = 0; | |
85 | 84 |
86 (void)clock_gettime(CLOCK_REALTIME, &pmd->sent_on); | 85 (void)clock_gettime(CLOCK_REALTIME, &pmd->sent_on); |
87 | 86 |
88 /* Is this a forwarded message ? */ | 87 /* Is this a forwarded message ? */ |
89 CHECK_FCT_DO( fd_msg_source_get(msg, &source, &slen), return ); | 88 CHECK_FCT_DO( fd_msg_source_get(msg, &source, NULL), return ); |
90 if (source) { | 89 if (source) { |
91 struct timespec delay; | 90 struct timespec delay; |
92 ASSERT(pmd->received_on.tv_sec); | 91 ASSERT(pmd->received_on.tv_sec); |
93 TS_DIFFERENCE( &delay, &pmd->received_on, &pmd->sent_on ); | 92 TS_DIFFERENCE( &delay, &pmd->received_on, &pmd->sent_on ); |
94 CHECK_MALLOC_DO( fd_msg_dump_summary(&buf, &len, NULL, msg, NULL, 0, 1), return ); | 93 CHECK_MALLOC_DO( fd_msg_dump_summary(&buf, &len, NULL, msg, NULL, 0, 1), return ); |
95 LOG_N("[TIMING] FWD %ld.%06ld sec: %s", (long)delay.tv_sec, delay.tv_nsec / 1000, buf); | 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); |
96 } else if (hdr->msg_flags & CMD_FLAG_REQUEST) { | 95 } else if (hdr->msg_flags & CMD_FLAG_REQUEST) { |
97 /* We are sending a request issued locally, nothing special to log */ | 96 /* We are sending a request issued locally, nothing special to log */ |
98 } else { | 97 } else { |
99 /* We have generated an anwer, log the time it took since the corresponding request was received */ | 98 /* We have generated an anwer, log the time it took since the corresponding request was received */ |
100 struct fd_hook_permsgdata *qpmd = fd_hook_get_request_pmd(mt_data_hdl, msg); | 99 struct fd_hook_permsgdata *qpmd = fd_hook_get_request_pmd(mt_data_hdl, msg); |
101 if (qpmd->received_on.tv_sec) { | 100 if (qpmd->received_on.tv_sec) { |
102 struct timespec delay; | 101 struct timespec delay; |
103 TS_DIFFERENCE( &delay, &qpmd->received_on, &pmd->sent_on ); | 102 TS_DIFFERENCE( &delay, &qpmd->received_on, &pmd->sent_on ); |
104 CHECK_MALLOC_DO( fd_msg_dump_summary(&buf, &len, NULL, msg, NULL, 0, 1), return ); | 103 CHECK_MALLOC_DO( fd_msg_dump_summary(&buf, &len, NULL, msg, NULL, 0, 1), return ); |
105 LOG_N("[TIMING] ANS %ld.%06ld sec: %s", (long)delay.tv_sec, delay.tv_nsec / 1000, buf); | 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); |
106 } | 105 } |
107 } | 106 } |
108 } | 107 } |
109 | 108 |
110 free(buf); | 109 free(buf); |