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);
"Welcome to our mercurial repository"