Development HOWTOs
From BroWiki
Contents |
How to pinpoint policy location during an in-core crash/exception
Say you get something like this:
1194542244.676561 <no location> (59353/tcp): bad tag in Val::CONVERTER (port/record) bro: Obj.cc:121: void BroObj::BadTag(const char*, const char*, const char*) const: Assertion `0' failed.
gdb tells you:
(gdb) bt #0 0x005027a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2 #1 0x005437a5 in raise () from /lib/tls/libc.so.6 #2 0x00545209 in abort () from /lib/tls/libc.so.6 #3 0x0053cd91 in __assert_fail () from /lib/tls/libc.so.6 #4 0x0814c1a2 in BroObj::BadTag (this=Could not find the frame base for "BroObj::BadTag(char const*, char const*, char const*) const".) at Obj.cc:121 #5 0x08085426 in Val::AsRecordVal (this=0xd9c8db8) at Val.h:312 #6 0x080e1722 in FieldExpr::Fold (this=0x9a5fb60, v=0xd9c8db8) at Expr.cc:3140 #7 0x080d3501 in UnaryExpr::Eval (this=0x9a5fb60, f=0xe050bf8) at Expr.cc:522 #8 0x080ee05d in eval_list (f=0xe050bf8, l=0x9a5f8f0) at Expr.cc:5398 #9 0x080ea38c in CallExpr::Eval (this=0x9a5fd90, f=0xe050bf8) at Expr.cc:4609 #10 0x080ee05d in eval_list (f=0xe050bf8, l=0x9a5f490) at Expr.cc:5398 #11 0x080ea38c in CallExpr::Eval (this=0x9a5fdf8, f=0xe050bf8) at Expr.cc:4609 #12 0x081a627e in ExprStmt::Exec (this=0x9a5fe60, f=0xe050bf8, flow=@0xbffedf54) at Stmt.cc:400 #13 0x081ab460 in StmtList::Exec (this=0x9a5f230, f=0xe050bf8, flow=@0xbffedf54) at Stmt.cc:1396 #14 0x080f941f in BroFunc::Call (this=0x9a5fed0, args=0xe0b5840, parent=0x0) at Func.cc:324 #15 0x080bcf56 in EventHandler::Call (this=0x9a5a470, vl=0xe0b5840, no_remote=false) at EventHandler.cc:64 #16 0x08051300 in Event::Dispatch (this=0xe0b5890, no_remote=false) at Event.h:60 #17 0x080bc627 in EventMgr::Dispatch (this=0x8354120) at Event.cc:124 #18 0x080bc68e in EventMgr::Drain (this=0x8354120) at Event.cc:136
Question: How do you find out where in your policy this was triggered?
Answer: step up through the call stack until you reach the first object that is derived from a BroObj. All such objects have a location associated with them, whose details you can print out:
(gdb) up
#1 0x005437a5 in raise () from /lib/tls/libc.so.6
(gdb) up
#2 0x00545209 in abort () from /lib/tls/libc.so.6
(gdb) up
#3 0x0053cd91 in __assert_fail () from /lib/tls/libc.so.6
(gdb) up
#4 0x0814c1a2 in BroObj::BadTag (this=Could not find the frame base for "BroObj::BadTag(char const*, char const*, char const*) const".) at Obj.cc:121
121 assert(0);
(gdb) up
#5 0x08085426 in Val::AsRecordVal (this=0xd9c8db8) at Val.h:312
312 CONVERTER(TYPE_RECORD, RecordVal*, AsRecordVal)
(gdb) up
#6 0x080e1722 in FieldExpr::Fold (this=0x9a5fb60, v=0xd9c8db8) at Expr.cc:3140
3140 Val* result = v->AsRecordVal()->Lookup(field);
(gdb) print *this->location
$1 = {<SerialObj> = {_vptr.SerialObj = 0x829d128, static NEVER = 0, static ALWAYS = 1, serial_type = 0, static factories = 0x976d930,
static names = 0x976d950, static time_counter = 1412671},
filename = 0x9784e58 "/home/foo/devel/bro/policy/mypolicy.bro", first_line = 76, last_line = 76, first_column = 0,
last_column = 0, delete_data = false, timestamp = 0, text = 0x0, static register_type = {<No data fields>}, tid = {id = 55425,
static counter = 3552074}}
The problem was triggered in mypolicy.bro, in line 76.
How to understand memory consumption
Memory leaks
To discover memleaks, we recommend running Bro on a reasonably sized trace using a memory checker such as valgrind. However, note that high memory use in Bro does not generally suggest a leak. It is more likely that your configuration's state keeping is flawed or simply requires substantial storage. In those cases, tuning the policy is the right thing to do. For this, there are several options.
stats.bro and profiling.bro
Adding these policies (one, not both) to the invocation causes memory consumption to be reported periodically. stats.bro is more lightweight than profiling.bro. An example of output generated by profiling.bro:
1216977665.085632 Memory: total=487412K total_adj=482264K malloced: 437533K 1216977665.085632 Run-time: user+sys=2210.3 user=1609.6 sys=600.7 real=149147.9 1216977665.085632 Conns: total=1057967 current=251/0 ext=0 mem=0K avg=0.0 table=0K connvals=0K 1216977665.085632 ConnCompressor: pending=128 pending_in_mem=205 full_conns=-5209 pending+real=353 mem=16Kavg=128.2/80.0 1216977665.085632 Conns: tcp=0/0 udp=0/11 icmp=0/0 1216977665.085632 TCP-States: Inact. Syn. SA Part. Est. Fin. Rst. 1216977665.085632 TCP-States:Inact. 7 1 4 1216977665.085632 TCP-States:Syn. 1216977665.085632 TCP-States:SA 1216977665.085632 TCP-States:Part. 3 1 1216977665.085632 TCP-States:Est. 105 21 1216977665.085632 TCP-States:Fin. 3 87 1216977665.085632 TCP-States:Rst. 7 8 4 1216977665.085632 Connections expired due to inactivity: 30284 1216977665.085632 Total reassembler data: 408K 1216977665.085632 Timers: current=276 max=54570 mem=15K lag=1216977665.09s 1216977665.085632 ConnectionInactivityTimer = 247 1216977665.085632 ProfileTimer = 1 1216977665.085632 RotateTimer = 8 1216977665.085632 TCPConnectionExpireTimer = 21
To do: Document the meaning of the various numbers.
print-globals.bro
This policy will cause the sizes of global variables upon termination. The underlying BiF, global_sizes(), can also be called at other times during operation.
