38.1.4 Tracing

Each object writes out trace information that can be used to track the progress of the object in its error recovery. Each trace entry is of the form:

\tup{prefix} \tup{tag} \tup{type of entry} \tup{values}

The prefix is as describe in the previous section for statistics. The tag is Q for request objects, P for repair objects, and S for session objects. The following types of trace entries and parameters are written by each object:

	Type of
Tag	Object	Other values	Comments
Q	DETECT
Q	INTERVALS	C1 C1_ C2 C2_ dist distance i backoff_
Q	NTIMER	at time	Time the request timer will fire
Q	SENDNACK
Q	NACK	IGNORE-BACKOFF time	Receive NACK, ignore other NACKs until time
Q	REPAIR	IGNORES time	Receive REPAIR, ignore NACKs until time
Q	DATA		Agent receives data instead of repair. Possibly indicates out of order arrival of data.
P	NACK	from requester	Receive NACK, initiate repair
P	INTERVALS	D1 D1_ D2 D2_ dist distance
P	RTIMER	at time	Time the repair timer will fire
P	SENDREP
P	REPAIR	IGNORES time	Receive REPAIR, ignore NACKs until time
P	DATA		Agent receives data instead of repair. Indicates premature request by an agent.
S	SESSION		logs session message sent

The following illustrates a typical trace for a single loss and recovery.

 3.5543 n 1 m <1:1> r 0 Q DETECT
 3.5543 n 1 m <1:1> r 1 Q INTERVALS C1 2.0 C2 0.0 d 0.0105 i 1
 3.5543 n 1 m <1:1> r 1 Q NTIMER at 3.57527
 3.5685 n 2 m <1:1> r 0 Q DETECT
 3.5685 n 2 m <1:1> r 1 Q INTERVALS C1 2.0 C2 0.0 d 0.021 i 1
 3.5685 n 2 m <1:1> r 1 Q NTIMER at 3.61053
 3.5753 n 1 m <1:1> r 1 Q SENDNACK
 3.5753 n 1 m <1:1> r 2 Q INTERVALS C1 2.0 C2 0.0 d 0.0105 i 2
 3.5753 n 1 m <1:1> r 2 Q NTIMER at 3.61727
 3.5753 n 1 m <1:1> r 2 Q NACK IGNORE-BACKOFF 3.59627
 3.5828 n 3 m <1:1> r 0 Q DETECT
 3.5828 n 3 m <1:1> r 1 Q INTERVALS C1 2.0 C2 0.0 d 0.032 i 1
 3.5828 n 3 m <1:1> r 1 Q NTIMER at 3.6468
 3.5854 n 0 m <1:1> r 0 P NACK from 257
 3.5854 n 0 m <1:1> r 1 P INTERVALS D1 1.0 D2 0.0 d 0.0105
 3.5854 n 0 m <1:1> r 1 P RTIMER at 3.59586
 3.5886 n 2 m <1:1> r 2 Q INTERVALS C1 2.0 C2 0.0 d 0.021 i 2
 3.5886 n 2 m <1:1> r 2 Q NTIMER at 3.67262
 3.5886 n 2 m <1:1> r 2 Q NACK IGNORE-BACKOFF 3.63062
 3.5959 n 0 m <1:1> r 1 P SENDREP
 3.5959 n 0 m <1:1> r 1 P REPAIR IGNORES 3.62736
 3.5971 n 4 m <1:1> r 0 Q DETECT
 3.5971 n 4 m <1:1> r 1 Q INTERVALS C1 2.0 C2 0.0 d 0.0425 i 1
 3.5971 n 4 m <1:1> r 1 Q NTIMER at 3.68207
 3.5971 n 5 m <1:1> r 0 Q DETECT
 3.5971 n 5 m <1:1> r 1 Q INTERVALS C1 2.0 C2 0.0 d 0.042 i 1
 3.5971 n 5 m <1:1> r 1 Q NTIMER at 3.68107
 3.6029 n 3 m <1:1> r 2 Q INTERVALS C1 2.0 C2 0.0 d 0.032 i 2
 3.6029 n 3 m <1:1> r 2 Q NTIMER at 3.73089
 3.6029 n 3 m <1:1> r 2 Q NACK IGNORE-BACKOFF 3.66689
 3.6102 n 1 m <1:1> r 2 Q REPAIR IGNORES 3.64171
 3.6172 n 4 m <1:1> r 2 Q INTERVALS C1 2.0 C2 0.0 d 0.0425 i 2
 3.6172 n 4 m <1:1> r 2 Q NTIMER at 3.78715
 3.6172 n 4 m <1:1> r 2 Q NACK IGNORE-BACKOFF 3.70215
 3.6172 n 5 m <1:1> r 2 Q INTERVALS C1 2.0 C2 0.0 d 0.042 i 2
 3.6172 n 5 m <1:1> r 2 Q NTIMER at 3.78515
 3.6172 n 5 m <1:1> r 2 Q NACK IGNORE-BACKOFF 3.70115
 3.6246 n 2 m <1:1> r 2 Q REPAIR IGNORES 3.68756
 3.6389 n 3 m <1:1> r 2 Q REPAIR IGNORES 3.73492
 3.6533 n 4 m <1:1> r 2 Q REPAIR IGNORES 3.78077
 3.6533 n 5 m <1:1> r 2 Q REPAIR IGNORES 3.77927

The logging of request and repair traces is done by []SRM::evTrace../ns-2/srm.tclSRM::evTrace. However, the routine []SRM/Session::evTrace../ns-2/srm.tclSRM/Session::evTrace, overrides the base class definition of []srm::evTrace, and writes out nothing. Individual simulation scripts can override these methods for greater flexibility in logging options. One possible reason to override these methods might to reduce the amount of data generated; the new procedure could then generate compressed and processed output.

Notice that the trace filoe contains sufficient information and details to derive most of the statistics written out in the log file, or is stored in the statistics arrays.