MySQL 5.6.14 Source Code Document
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Friends Macros Groups Pages
SignalLoggerManager.cpp
1 /*
2  Copyright (c) 2003, 2011, Oracle and/or its affiliates. All rights reserved.
3 
4  This program is free software; you can redistribute it and/or modify
5  it under the terms of the GNU General Public License as published by
6  the Free Software Foundation; version 2 of the License.
7 
8  This program is distributed in the hope that it will be useful,
9  but WITHOUT ANY WARRANTY; without even the implied warranty of
10  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
11  GNU General Public License for more details.
12 
13  You should have received a copy of the GNU General Public License
14  along with this program; if not, write to the Free Software
15  Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA
16 */
17 
18 #include <ndb_global.h>
19 
20 #include "SignalLoggerManager.hpp"
21 #include <LongSignal.hpp>
22 #include <GlobalSignalNumbers.h>
23 #include <DebuggerNames.hpp>
24 #include <NdbTick.h>
25 #include <NdbEnv.h>
26 
27 #ifdef VM_TRACE_TIME
28 static char* mytime()
29 {
30  NDB_TICKS t = NdbTick_CurrentMillisecond();
31  uint s = (t / 1000) % 3600;
32  uint ms = t % 1000;
33  static char buf[100];
34  sprintf(buf, "%u.%03u", s, ms);
35  return buf;
36 }
37 #endif
38 SignalLoggerManager::SignalLoggerManager()
39 {
40  for (int i = 0; i < NO_OF_BLOCKS; i++){
41  logModes[i] = 0;
42  }
43  outputStream = 0;
44  m_ownNodeId = 0;
45  m_logDistributed = false;
46 
47  // using mutex avoids MT log mixups but has some serializing effect
48  m_mutex = 0;
49  const char* p = NdbEnv_GetEnv("NDB_SIGNAL_LOG_MUTEX", (char*)0, 0);
50  if (p != 0 && strchr("1Y", p[0]) != 0)
51  m_mutex = NdbMutex_Create();
52 }
53 
54 SignalLoggerManager::~SignalLoggerManager()
55 {
56  if(outputStream != 0){
57  fflush(outputStream);
58  fclose(outputStream);
59  outputStream = 0;
60  }
61  if (m_mutex != 0) {
62  NdbMutex_Destroy(m_mutex);
63  m_mutex = 0;
64  }
65 }
66 
67 FILE *
68 SignalLoggerManager::setOutputStream(FILE * output)
69 {
70  if(outputStream != 0){
71  fflush(outputStream);
72  }
73 
74  FILE * out = outputStream;
75  outputStream = output;
76  return out;
77 }
78 
79 FILE *
80 SignalLoggerManager::getOutputStream() const
81 {
82  return outputStream;
83 }
84 
85 void
86 SignalLoggerManager::flushSignalLog()
87 {
88  if(outputStream != 0)
89  fflush(outputStream);
90 }
91 
92 void
93 SignalLoggerManager::setTrace(unsigned long trace)
94 {
95  traceId = trace;
96 }
97 
98 unsigned long
99 SignalLoggerManager::getTrace() const
100 {
101  return traceId;
102 }
103 
104 void
105 SignalLoggerManager::setOwnNodeId(int nodeId){
106  m_ownNodeId = nodeId;
107 }
108 
109 void
110 SignalLoggerManager::setLogDistributed(bool val){
111  m_logDistributed = val;
112 }
113 
114 int
115 getParameter(char *blocks[NO_OF_BLOCKS], const char * par, const char * line)
116 {
117  const char * loc = strstr(line, par);
118  if(loc == NULL)
119  return 0;
120 
121  loc += strlen(par);
122 
123  int found = 0;
124 
125  char * copy = strdup(loc);
126  char * tmp = copy;
127  bool done = false;
128  while(!done){
129  int len = strcspn(tmp, ", ;:\0");
130  if(len == 0)
131  done = true;
132  else {
133  if(* (tmp + len) != ',')
134  done = true;
135  * (tmp + len) = 0;
136  blocks[found] = strdup(tmp);
137  found ++;
138  tmp += (len + 1);
139  }
140  }
141  free(copy);
142  return found;
143 }
144 
145 
146 #define SLM_OFF 0
147 #define SLM_ON 1
148 #define SLM_TOGGLE 2
149 
150 int
151 SignalLoggerManager::log(LogMode logMode, const char * params)
152 {
153  char * blocks[NO_OF_BLOCKS];
154  const int count = getParameter(blocks, "BLOCK=", params);
155 
156  int cnt = 0;
157  if((count == 1 && !strcmp(blocks[0], "ALL")) ||
158  count == 0){
159 
160  for (int number = 0; number < NO_OF_BLOCKS; ++number){
161  cnt += log(SLM_ON, MIN_BLOCK_NO + number, logMode);
162  }
163  } else {
164  for (int i = 0; i < count; ++i){
165  BlockNumber number = getBlockNo(blocks[i]);
166  cnt += log(SLM_ON, number, logMode);
167  }
168  }
169  for(int i = 0; i<count; i++){
170  free(blocks[i]);
171  }
172 
173  return cnt;
174 }
175 
176 int
177 SignalLoggerManager::log(int cmd, BlockNumber bno, LogMode logMode)
178 {
179  // Normalise blocknumber for use in logModes array
180  const BlockNumber bno2 = bno-MIN_BLOCK_NO;
181  assert(bno2<NO_OF_BLOCKS);
182  switch(cmd){
183  case SLM_ON:
184  logModes[bno2] |= logMode;
185  return 1;
186  break;
187  case SLM_OFF:
188  logModes[bno2] &= (~logMode);
189  return 1;
190  break;
191  case SLM_TOGGLE:
192  logModes[bno2] ^= logMode;
193  return 1;
194  break;
195  }
196  return 0;
197 }
198 
199 int
200 SignalLoggerManager::logOn(bool allBlocks, BlockNumber bno, LogMode logMode)
201 {
202  if(!allBlocks){
203  return log(SLM_ON, bno, logMode);
204  }
205  int cnt = 0;
206  for(unsigned int i = MIN_BLOCK_NO; i <= MAX_BLOCK_NO; i++)
207  cnt += log(SLM_ON, i, logMode);
208  return cnt;
209 }
210 
211 int
212 SignalLoggerManager::logOff(bool allBlocks, BlockNumber bno, LogMode logMode)
213 {
214  if(!allBlocks){
215  return log(SLM_OFF, bno, logMode);
216  }
217  int cnt = 0;
218  for(unsigned int i = MIN_BLOCK_NO; i <= MAX_BLOCK_NO; i++)
219  cnt += log(SLM_OFF, i, logMode);
220  return cnt;
221 
222 }
223 
224 int
225 SignalLoggerManager::logToggle(bool allBlocks, BlockNumber bno, LogMode logMode)
226 {
227  if(!allBlocks){
228  return log(SLM_TOGGLE, bno, logMode);
229  }
230  int cnt = 0;
231  for(unsigned int i = MIN_BLOCK_NO; i <= MAX_BLOCK_NO; i++)
232  cnt += log(SLM_TOGGLE, i, logMode);
233  return cnt;
234 }
235 
236 void
237 SignalLoggerManager::executeDirect(const SignalHeader& sh,
238  Uint8 prio, // in-out flag
239  const Uint32 * theData, Uint32 node)
240 {
241  Uint32 trace = sh.theTrace;
242  Uint32 senderBlockNo = refToBlock(sh.theSendersBlockRef);
243  Uint32 receiverBlockNo = sh.theReceiversBlockNumber;
244 
245  if(outputStream != 0 &&
246  (traceId == 0 || traceId == trace) &&
247  (logMatch(senderBlockNo, LogOut) || logMatch(receiverBlockNo, LogIn))){
248  lock();
249  const char* inOutStr = prio == 0 ? "In" : "Out";
250 #ifdef VM_TRACE_TIME
251  fprintf(outputStream, "---- Direct --- Signal --- %s - %s ----\n", inOutStr, mytime());
252 #else
253  fprintf(outputStream, "---- Direct --- Signal --- %s ----------------\n", inOutStr);
254 #endif
255  // XXX pass in/out to print* function somehow
256  printSignalHeader(outputStream, sh, 0, node, true);
257  printSignalData(outputStream, sh, theData);
258  unlock();
259  }
260 }
261 
265 void
266 SignalLoggerManager::executeSignal(const SignalHeader& sh, Uint8 prio,
267  const Uint32 * theData, Uint32 node,
268  const SegmentedSectionPtr ptr[3], Uint32 secs)
269 {
270  Uint32 trace = sh.theTrace;
271  //Uint32 senderBlockNo = refToBlock(sh.theSendersBlockRef);
272  Uint32 receiverBlockNo = sh.theReceiversBlockNumber;
273  Uint32 senderNode = refToNode(sh.theSendersBlockRef);
274 
275  if(outputStream != 0 &&
276  (traceId == 0 || traceId == trace) &&
277  (logMatch(receiverBlockNo, LogOut) ||
278  (m_logDistributed && m_ownNodeId != senderNode))){
279  lock();
280 #ifdef VM_TRACE_TIME
281  fprintf(outputStream, "---- Received - Signal - %s ----\n", mytime());
282 #else
283  fprintf(outputStream, "---- Received - Signal ----------------\n");
284 #endif
285 
286  printSignalHeader(outputStream, sh, prio, node, true);
287  printSignalData(outputStream, sh, theData);
288  for (unsigned i = 0; i < secs; i++)
289  printSegmentedSection(outputStream, sh, ptr, i);
290  unlock();
291  }
292 }
293 
294 void
295 SignalLoggerManager::executeSignal(const SignalHeader& sh, Uint8 prio,
296  const Uint32 * theData, Uint32 node,
297  const LinearSectionPtr ptr[3], Uint32 secs)
298 {
299  Uint32 trace = sh.theTrace;
300  //Uint32 senderBlockNo = refToBlock(sh.theSendersBlockRef);
301  Uint32 receiverBlockNo = sh.theReceiversBlockNumber;
302  Uint32 senderNode = refToNode(sh.theSendersBlockRef);
303 
304  if(outputStream != 0 &&
305  (traceId == 0 || traceId == trace) &&
306  (logMatch(receiverBlockNo, LogOut) ||
307  (m_logDistributed && m_ownNodeId != senderNode))){
308  lock();
309 #ifdef VM_TRACE_TIME
310  fprintf(outputStream, "---- Received - Signal - %s ----\n", mytime());
311 #else
312  fprintf(outputStream, "---- Received - Signal ----------------\n");
313 #endif
314 
315  printSignalHeader(outputStream, sh, prio, node, true);
316  printSignalData(outputStream, sh, theData);
317  for (unsigned i = 0; i < secs; i++)
318  printLinearSection(outputStream, sh, ptr, i);
319  unlock();
320  }
321 }
322 
326 void
327 SignalLoggerManager::sendSignal(const SignalHeader& sh,
328  Uint8 prio,
329  const Uint32 * theData, Uint32 node,
330  const LinearSectionPtr ptr[3], Uint32 secs)
331 {
332  Uint32 trace = sh.theTrace;
333  Uint32 senderBlockNo = refToBlock(sh.theSendersBlockRef);
334  //Uint32 receiverBlockNo = sh.theReceiversBlockNumber;
335 
336  if(outputStream != 0 &&
337  (traceId == 0 || traceId == trace) &&
338  (logMatch(senderBlockNo, LogOut) ||
339  (m_logDistributed && m_ownNodeId != node))){
340  lock();
341 #ifdef VM_TRACE_TIME
342  fprintf(outputStream, "---- Send ----- Signal - %s ----\n", mytime());
343 #else
344  fprintf(outputStream, "---- Send ----- Signal ----------------\n");
345 #endif
346 
347  printSignalHeader(outputStream, sh, prio, node, false);
348  printSignalData(outputStream, sh, theData);
349  for (unsigned i = 0; i < secs; i++)
350  printLinearSection(outputStream, sh, ptr, i);
351  unlock();
352  }
353 }
354 
358 void
359 SignalLoggerManager::sendSignal(const SignalHeader& sh, Uint8 prio,
360  const Uint32 * theData, Uint32 node,
361  const SegmentedSectionPtr ptr[3], Uint32 secs)
362 {
363  Uint32 trace = sh.theTrace;
364  Uint32 senderBlockNo = refToBlock(sh.theSendersBlockRef);
365  //Uint32 receiverBlockNo = sh.theReceiversBlockNumber;
366 
367  if(outputStream != 0 &&
368  (traceId == 0 || traceId == trace) &&
369  (logMatch(senderBlockNo, LogOut) ||
370  (m_logDistributed && m_ownNodeId != node))){
371  lock();
372 #ifdef VM_TRACE_TIME
373  fprintf(outputStream, "---- Send ----- Signal - %s ----\n", mytime());
374 #else
375  fprintf(outputStream, "---- Send ----- Signal ----------------\n");
376 #endif
377 
378  printSignalHeader(outputStream, sh, prio, node, false);
379  printSignalData(outputStream, sh, theData);
380  for (unsigned i = 0; i < secs; i++)
381  printSegmentedSection(outputStream, sh, ptr, i);
382  unlock();
383  }
384 }
385 
386 void
387 SignalLoggerManager::sendSignal(const SignalHeader& sh,
388  Uint8 prio,
389  const Uint32 * theData, Uint32 node,
390  const GenericSectionPtr ptr[3], Uint32 secs)
391 {
392  Uint32 trace = sh.theTrace;
393  Uint32 senderBlockNo = refToBlock(sh.theSendersBlockRef);
394  //Uint32 receiverBlockNo = sh.theReceiversBlockNumber;
395 
396  if(outputStream != 0 &&
397  (traceId == 0 || traceId == trace) &&
398  (logMatch(senderBlockNo, LogOut) ||
399  (m_logDistributed && m_ownNodeId != node))){
400  lock();
401 #ifdef VM_TRACE_TIME
402  fprintf(outputStream, "---- Send ----- Signal - %s ----\n", mytime());
403 #else
404  fprintf(outputStream, "---- Send ----- Signal ----------------\n");
405 #endif
406 
407  printSignalHeader(outputStream, sh, prio, node, false);
408  printSignalData(outputStream, sh, theData);
409  for (unsigned i = 0; i < secs; i++)
410  printGenericSection(outputStream, sh, ptr, i);
411  unlock();
412  }
413 }
414 
415 void
416 SignalLoggerManager::sendSignalWithDelay(Uint32 delayInMilliSeconds,
417  const SignalHeader & sh, Uint8 prio,
418  const Uint32 * theData, Uint32 node,
419  const SegmentedSectionPtr ptr[3], Uint32 secs)
420 {
421  Uint32 trace = sh.theTrace;
422  Uint32 senderBlockNo = refToBlock(sh.theSendersBlockRef);
423  //Uint32 receiverBlockNo = sh.theReceiversBlockNumber;
424 
425  if(outputStream != 0 &&
426  (traceId == 0 || traceId == trace) &&
427  logMatch(senderBlockNo, LogOut)){
428  lock();
429 #ifdef VM_TRACE_TIME
430  fprintf(outputStream,
431  "---- Send ----- Signal (%d ms) %s\n",
432  delayInMilliSeconds,
433  mytime());
434 #else
435  fprintf(outputStream, "---- Send delay Signal (%d ms) ----------\n",
436  delayInMilliSeconds);
437 #endif
438 
439  printSignalHeader(outputStream, sh, prio, node, false);
440  printSignalData(outputStream, sh, theData);
441  for (unsigned i = 0; i < secs; i++)
442  printSegmentedSection(outputStream, sh, ptr, i);
443  unlock();
444  }
445 }
446 
450 void
451 SignalLoggerManager::log(BlockNumber bno, const char * msg, ...)
452 {
453  // Normalise blocknumber for use in logModes array
454  const BlockNumber bno2 = bno - MIN_BLOCK_NO;
455  assert(bno2<NO_OF_BLOCKS);
456 
457  if(outputStream != 0 &&
458  logModes[bno2] != LogOff){
459  lock();
460  va_list ap;
461  va_start(ap, msg);
462  fprintf(outputStream, "%s: ", getBlockName(bno, "API"));
463  vfprintf(outputStream, msg, ap);
464  fprintf(outputStream, "\n");
465  va_end(ap);
466  unlock();
467  }
468 }
469 
470 static inline bool
471 isSysBlock(BlockNumber block, Uint32 gsn)
472 {
473  if (block != 0)
474  return false;
475  switch (gsn) {
476  case GSN_START_ORD:
477  return true; // first sig
478  case GSN_CONNECT_REP:
479  case GSN_DISCONNECT_REP:
480  case GSN_EVENT_REP:
481  return true; // transporter
482  case GSN_STOP_FOR_CRASH:
483  return true; // mt scheduler
484  }
485  return false;
486 }
487 
488 static inline bool
489 isApiBlock(BlockNumber block)
490 {
491  return block >= 0x8000 || block == 4002 || block == 2047;
492 }
493 
494 void
495 SignalLoggerManager::printSignalHeader(FILE * output,
496  const SignalHeader & sh,
497  Uint8 prio,
498  Uint32 node,
499  bool printReceiversSignalId)
500 {
501  const char* const dummy_block_name = "UUNET";
502 
503  bool receiverIsApi = isApiBlock(sh.theReceiversBlockNumber);
504  Uint32 receiverBlockNo;
505  Uint32 receiverInstanceNo;
506  if (!receiverIsApi) {
507  receiverBlockNo = blockToMain(sh.theReceiversBlockNumber);
508  receiverInstanceNo = blockToInstance(sh.theReceiversBlockNumber);
509  } else {
510  receiverBlockNo = sh.theReceiversBlockNumber;
511  receiverInstanceNo = 0;
512  }
513  Uint32 receiverProcessor = node;
514 
515  Uint32 gsn = sh.theVerId_signalNumber;
516 
517  Uint32 sbref = sh.theSendersBlockRef;
518  bool senderIsSys = isSysBlock(refToBlock(sbref), gsn);
519  bool senderIsApi = isApiBlock(refToBlock(sbref));
520  Uint32 senderBlockNo;
521  Uint32 senderInstanceNo;
522  if (!senderIsSys && !senderIsApi) {
523  senderBlockNo = refToMain(sbref);
524  senderInstanceNo = refToInstance(sbref);
525  } else {
526  senderBlockNo = refToBlock(sbref);
527  senderInstanceNo = 0;
528  }
529  Uint32 senderProcessor = refToNode(sbref);
530 
531  Uint32 length = sh.theLength;
532  Uint32 trace = sh.theTrace;
533  Uint32 rSigId = sh.theSignalId;
534  Uint32 sSigId = sh.theSendersSignalId;
535 
536  const char * signalName = getSignalName(gsn);
537  const char * rBlockName =
538  receiverIsApi ? "API" :
539  getBlockName(receiverBlockNo, dummy_block_name);
540  const char * sBlockName =
541  senderIsSys ? "SYS" :
542  senderIsApi ? "API" :
543  getBlockName(senderBlockNo, dummy_block_name);
544 
545  char rInstanceText[20];
546  char sInstanceText[20];
547  rInstanceText[0] = 0;
548  sInstanceText[0] = 0;
549  if (receiverInstanceNo != 0)
550  sprintf(rInstanceText, "/%u", (uint)receiverInstanceNo);
551  if (senderInstanceNo != 0)
552  sprintf(sInstanceText, "/%u", (uint)senderInstanceNo);
553 
554  if (printReceiversSignalId)
555  fprintf(output,
556  "r.bn: %d%s \"%s\", r.proc: %d, r.sigId: %d gsn: %d \"%s\" prio: %d\n"
557  ,receiverBlockNo, rInstanceText, rBlockName, receiverProcessor,
558  rSigId, gsn, signalName, prio);
559  else
560  fprintf(output,
561  "r.bn: %d%s \"%s\", r.proc: %d, gsn: %d \"%s\" prio: %d\n",
562  receiverBlockNo, rInstanceText, rBlockName, receiverProcessor,
563  gsn, signalName, prio);
564 
565  fprintf(output,
566  "s.bn: %d%s \"%s\", s.proc: %d, s.sigId: %d length: %d trace: %d "
567  "#sec: %d fragInf: %d\n",
568  senderBlockNo, sInstanceText, sBlockName, senderProcessor,
569  sSigId, length, trace, sh.m_noOfSections, sh.m_fragmentInfo);
570 
571  //assert(strcmp(rBlockName, dummy_block_name) != 0);
572  //assert(strcmp(sBlockName, dummy_block_name) != 0);
573 }
574 
575 void
576 SignalLoggerManager::printSignalData(FILE * output,
577  const SignalHeader & sh,
578  const Uint32 * signalData)
579 {
580  Uint32 len = sh.theLength;
581  SignalDataPrintFunction printFunction =
582  findPrintFunction(sh.theVerId_signalNumber);
583 
584  bool ok = false; // done with printing
585  if(printFunction != 0){
586  ok = (* printFunction)(output, signalData, len, sh.theReceiversBlockNumber);
587  }
588  if(!ok){
589  while(len >= 7){
590  fprintf(output,
591  " H\'%.8x H\'%.8x H\'%.8x H\'%.8x H\'%.8x H\'%.8x H\'%.8x\n",
592  signalData[0], signalData[1], signalData[2], signalData[3],
593  signalData[4], signalData[5], signalData[6]);
594  len -= 7;
595  signalData += 7;
596  }
597  if(len > 0){
598  for(Uint32 i = 0; i<len; i++)
599  fprintf(output, " H\'%.8x", signalData[i]);
600  fprintf(output, "\n");
601  }
602  }
603 }
604 
605 void
606 SignalLoggerManager::printLinearSection(FILE * output,
607  const SignalHeader & sh,
608  const LinearSectionPtr ptr[3],
609  unsigned i)
610 {
611  fprintf(output, "SECTION %u type=linear", i);
612  if (i >= 3) {
613  fprintf(output, " *** invalid ***\n");
614  return;
615  }
616  const Uint32 len = ptr[i].sz;
617  const Uint32 * data = ptr[i].p;
618  Uint32 pos = 0;
619  fprintf(output, " size=%u\n", (unsigned)len);
620  while (pos < len) {
621  printDataWord(output, pos, data[pos]);
622  }
623  if (len > 0)
624  putc('\n', output);
625 }
626 
627 void
628 SignalLoggerManager::printGenericSection(FILE * output,
629  const SignalHeader & sh,
630  const GenericSectionPtr ptr[3],
631  unsigned i)
632 {
633  fprintf(output, "SECTION %u type=generic", i);
634  if (i >= 3) {
635  fprintf(output, " *** invalid ***\n");
636  return;
637  }
638  const Uint32 len = ptr[i].sz;
639  Uint32 pos = 0;
640  Uint32 chunksz = 0;
641  fprintf(output, " size=%u\n", (unsigned)len);
642  while (pos < len) {
643  const Uint32* data= ptr[i].sectionIter->getNextWords(chunksz);
644  Uint32 i=0;
645  while (i < chunksz)
646  printDataWord(output, pos, data[i++]);
647  }
648  if (len > 0)
649  putc('\n', output);
650 }
651 
652 
653 void
654 SignalLoggerManager::printDataWord(FILE * output, Uint32 & pos, const Uint32 data)
655 {
656  const char* const hex = "0123456789abcdef";
657  if (pos > 0 && pos % 7 == 0)
658  putc('\n', output);
659  putc(' ', output);
660  putc('H', output);
661  putc('\'', output);
662  for (int i = 7; i >= 0; i--)
663  putc(hex[(data >> (i << 2)) & 0xf], output);
664  pos++;
665 }