Index: drbd/drbd_receiver.c =================================================================== --- drbd/drbd_receiver.c (revision 3489) +++ drbd/drbd_receiver.c (working copy) @@ -2373,6 +2373,8 @@ else handler = NULL; + dump_packet(mdev,mdev->data.socket,2,&mdev->data.rbuf, __FILE__, __LINE__); + if (unlikely(!handler)) { ERR("unknown packet type %d, l: %d!\n", header->command, header->length); @@ -2383,7 +2385,6 @@ cmdname(header->command), header->length); break; } - dump_packet(mdev,mdev->data.socket,2,&mdev->data.rbuf, __FILE__, __LINE__); } } Index: drbd/drbd_actlog.c =================================================================== --- drbd/drbd_actlog.c (revision 3489) +++ drbd/drbd_actlog.c (working copy) @@ -732,8 +732,10 @@ sbnr = BM_SECT_TO_BIT(sector + BM_SECT_PER_BIT-1); #ifdef DUMP_EACH_PACKET - INFO("drbd_set_in_sync: sector=%lu size=%d sbnr=%lu ebnr=%lu\n", - (unsigned long)sector, size, sbnr, ebnr); + if (dump_packets >= DUMP_MAX) { + INFO("drbd_set_in_sync: sector=%llx size=%x sbnr=%lx ebnr=%lx\n", + (long long)sector, size, sbnr, ebnr); + } #endif if (sbnr > ebnr) return; @@ -794,6 +796,13 @@ sbnr = BM_SECT_TO_BIT(sector); ebnr = BM_SECT_TO_BIT(esector); +#ifdef DUMP_EACH_PACKET + if (dump_packets >= DUMP_MAX) { + INFO("drbd_set_out_of_sync: sector=%llx size=%x sbnr=%lx ebnr=%lx\n", + (long long)sector, size, sbnr, ebnr); + } +#endif + /* * ok, (capacity & 7) != 0 sometimes, but who cares... * we count rs_{total,left} in bits, not sectors. Index: drbd/linux/drbd_config.h =================================================================== --- drbd/linux/drbd_config.h (revision 3489) +++ drbd/linux/drbd_config.h (working copy) @@ -36,8 +36,9 @@ #define DUMP_MD 2 // Dump even all cstate changes (I like it!) //#define PARANOIA // some extra checks -// don't enable this, unless you can cope with gigabyte syslogs :) -//#define DUMP_EACH_PACKET +// Define this to enable printing of packets under control of dump_packets +// module parameter (/sys/module/drbd/parameters/dump_packets) +//#define DUMP_EACH_PACKET // Dump every hour the usage / not usage of zero copy IO //#define SHOW_SENDPAGE_USAGE Index: drbd/drbd_main.c =================================================================== --- drbd/drbd_main.c (revision 3489) +++ drbd/drbd_main.c (working copy) @@ -126,6 +126,14 @@ #endif int disable_bd_claim = 0; +#ifdef DUMP_EACH_PACKET +int dump_packets = 0; // Module parameter that controls packet tracing + // 0 = none + // 1 = summary (trace 'interesting' packets in summary fmt) + // 2 = verbose (trace all packets in full format) +module_param(dump_packets,int,0644); +#endif + // devfs name char* drbd_devfs_name = "drbd"; @@ -859,6 +867,7 @@ } #if DUMP_MD >= 2 + { char *pbp,pb[300]; pbp = pb; *pbp=0; @@ -872,6 +881,7 @@ PSC(peer_isp); PSC(user_isp); INFO("%s\n", pb); + } #endif mdev->state.i = ns.i; @@ -2870,5 +2880,145 @@ return 1; } +#ifdef DUMP_EACH_PACKET +#define PSM(A) \ +do { \ + if( mask.A ) { \ + int i = snprintf(p, len, " " #A "( %s )", \ + A##s_to_name(val.A)); \ + if (i >= len) return op; \ + p += i; \ + len -= i; \ + } \ +} while (0) + +STATIC char *dump_st(char *p, int len, drbd_state_t mask, drbd_state_t val) +{ + char *op=p; + *p = '\0'; + PSM(role); + PSM(peer); + PSM(conn); + PSM(disk); + PSM(pdsk); + + return op; +} + +#define INFOP(fmt, args...) \ +do { \ + if (dump_packets > DUMP_SUMMARY) { \ + INFO("%s:%d: %s [%d] %s %s " fmt , \ + file, line, current->comm, current->pid, \ + sockname, recv?"<<<":">>>" \ + , ## args ); \ + } \ + else { \ + INFO("%s " fmt, recv?"<<<":">>>", ## args ); \ + } \ +} while (0) + +void +_dump_packet(drbd_dev *mdev, struct socket *sock, + int recv, Drbd_Polymorph_Packet *p, char* file, int line) +{ + char *sockname = sock == mdev->meta.socket ? "meta" : "data"; + int cmd = (recv == 2) ? p->head.command : be16_to_cpu(p->head.command); + char tmp[300]; + drbd_state_t m,v; + + switch (cmd) { + case HandShake: + INFOP("%s (protocol %u)\n", cmdname(cmd), be32_to_cpu(p->HandShake.protocol_version)); + break; + + case ReportBitMap: /* don't report this */ + break; + + case Data: + case DataReply: + case RSDataReply: + INFOP("%s (sector %llx, id %llx, seq %x, f %x)\n", cmdname(cmd), + (long long)be64_to_cpu(p->Data.sector), + (long long)be64_to_cpu(p->Data.block_id), + be32_to_cpu(p->Data.seq_num), + be32_to_cpu(p->Data.dp_flags) + ); + break; + + case RecvAck: + case WriteAck: + case NegAck: + INFOP("%s (sector %llx, size %x, id %llx, seq %x)\n", cmdname(cmd), + (long long)be64_to_cpu(p->BlockAck.sector), + be32_to_cpu(p->BlockAck.blksize), + (long long)be64_to_cpu(p->BlockAck.block_id), + be32_to_cpu(p->BlockAck.seq_num) + ); + break; + + case DataRequest: + case RSDataRequest: + INFOP("%s (sector %llx, size %x, id %llx)\n", cmdname(cmd), + (long long)be64_to_cpu(p->BlockRequest.sector), + be32_to_cpu(p->BlockRequest.blksize), + (long long)be64_to_cpu(p->BlockRequest.block_id) + ); + break; + + case Barrier: + case BarrierAck: + INFOP("%s (barrier %u)\n", cmdname(cmd), p->Barrier.barrier); + break; + + case ReportSizes: + INFOP("%s (d %lluMiB, u %lluMiB, c %lldMiB, max bio %x, q order %x)\n", cmdname(cmd), + (long long)(be64_to_cpu(p->Sizes.d_size)>>(20-9)), + (long long)(be64_to_cpu(p->Sizes.u_size)>>(20-9)), + (long long)(be64_to_cpu(p->Sizes.c_size)>>(20-9)), + be32_to_cpu(p->Sizes.max_segment_size), + be32_to_cpu(p->Sizes.queue_order_type)); + break; + + case ReportState: + v.i = be32_to_cpu(p->State.state); + m.i = 0xffffffff; + dump_st(tmp,sizeof(tmp),m,v); + INFOP("%s (s %x {%s})\n", cmdname(cmd), v.i, tmp); + break; + + case StateChgRequest: + m.i = be32_to_cpu(p->ReqState.mask); + v.i = be32_to_cpu(p->ReqState.val); + dump_st(tmp,sizeof(tmp),m,v); + INFOP("%s (m %x v %x {%s})\n", cmdname(cmd), m.i, v.i, tmp); + break; + + case StateChgReply: + INFOP("%s (ret %x)\n", cmdname(cmd), + be32_to_cpu(p->RqSReply.retcode)); + break; + + case DiscardNote: + INFOP("%s (id %llx, seq %x)\n", cmdname(cmd), + (long long)be64_to_cpu(p->Discard.block_id), + be32_to_cpu(p->Discard.seq_num)); + break; + + case Ping: + case PingAck: + /* + * Dont trace pings at summary level + */ + if (dump_packets <= DUMP_SUMMARY) + break; + /* fall through... */ + default: + INFOP("%s (%u)\n",cmdname(cmd), cmd); + break; + } +} +#endif + module_init(drbd_init) module_exit(drbd_cleanup) Index: drbd/drbd_int.h =================================================================== --- drbd/drbd_int.h (revision 3489) +++ drbd/drbd_int.h (working copy) @@ -361,8 +361,22 @@ [StateChgReply] = "StateChgReply" }; - if (cmd == HandShake) return "HandShake"; - if (Data > cmd || cmd >= MAX_CMD) return "Unknown"; + if (Data > cmd || cmd >= MAX_CMD) { + switch (cmd) { + case HandShakeM: + return "HandShakeM"; + break; + case HandShakeS: + return "HandShakeS"; + break; + case HandShake: + return "HandShake"; + break; + default: + return "Unknown"; + break; + } + } return cmdnames[cmd]; } @@ -543,7 +557,10 @@ Drbd_Sizes_Packet Sizes; Drbd_GenCnt_Packet GenCnt; Drbd_State_Packet State; + Drbd_Req_State_Packet ReqState; + Drbd_RqS_Reply_Packet RqSReply; Drbd_BlockRequest_Packet BlockRequest; + Drbd_Discard_Packet Discard; } __attribute((packed)) Drbd_Polymorph_Packet; /**********************************************************************/ @@ -1602,63 +1619,29 @@ } #ifdef DUMP_EACH_PACKET + /* + * variable that controls dumping + */ +extern int dump_packets; + +#define DUMP_NONE 0 +#define DUMP_SUMMARY 1 +#define DUMP_ALL 2 +#define DUMP_MAX 3 + +/* * enable to dump information about every packet exchange. */ -#define INFOP(fmt, args...) \ - INFO("%s:%d: %s [%d] %s %s " fmt , \ - file, line, current->comm, current->pid, \ - sockname, recv?"<<<":">>>" \ - , ## args ) +extern void _dump_packet(drbd_dev *mdev, struct socket *sock, + int recv, Drbd_Polymorph_Packet *p, char* file, int line); + static inline void dump_packet(drbd_dev *mdev, struct socket *sock, int recv, Drbd_Polymorph_Packet *p, char* file, int line) { - char *sockname = sock == mdev->meta.socket ? "meta" : "data"; - int cmd = (recv == 2) ? p->head.command : be16_to_cpu(p->head.command); - switch (cmd) { - case HandShake: - INFOP("%s (%u)\n", be32_to_cpu(p->HandShake.protocol_version)); - break; - - case Ping: - case PingAck: - case BecomeSyncTarget: - case BecomeSyncSource: - case UnplugRemote: - - case SyncParam: - case ReportParams: - INFOP("%s\n", cmdname(cmd)); - break; - - case ReportBitMap: /* don't report this */ - break; - - case Data: - case DataReply: - case RSDataReply: - - case RecvAck: /* yes I know. but it is the same layout */ - case WriteAck: - case NegAck: - - case DataRequest: - case RSDataRequest: - INFOP("%s (%lu,%llx)\n", cmdname(cmd), - (long)be64_to_cpu(p->Data.sector), (long long)p->Data.block_id - ); - break; - - case Barrier: - case BarrierAck: - INFOP("%s (%u)\n", cmdname(cmd), p->Barrier.barrier); - break; - - default: - INFOP("%s (%u)\n",cmdname(cmd), cmd); - break; - } + if (dump_packets > DUMP_NONE) + _dump_packet(mdev,sock,recv,p,file,line); } #else #define dump_packet(ignored...) ((void)0)