fsm.c revision 26516
1/*
2 *		PPP Finite State Machine for LCP/IPCP
3 *
4 *	    Written by Toshiharu OHNO (tony-o@iij.ad.jp)
5 *
6 *   Copyright (C) 1993, Internet Initiative Japan, Inc. All rights reserverd.
7 *
8 * Redistribution and use in source and binary forms are permitted
9 * provided that the above copyright notice and this paragraph are
10 * duplicated in all such forms and that any documentation,
11 * advertising materials, and other materials related to such
12 * distribution and use acknowledge that the software was developed
13 * by the Internet Initiative Japan, Inc.  The name of the
14 * IIJ may not be used to endorse or promote products derived
15 * from this software without specific prior written permission.
16 * THIS SOFTWARE IS PROVIDED ``AS IS'' AND WITHOUT ANY EXPRESS OR
17 * IMPLIED WARRANTIES, INCLUDING, WITHOUT LIMITATION, THE IMPLIED
18 * WARRANTIES OF MERCHANTIBILITY AND FITNESS FOR A PARTICULAR PURPOSE.
19 *
20 * $Id: fsm.c,v 1.12 1997/06/02 00:04:40 brian Exp $
21 *
22 *  TODO:
23 *		o Refer loglevel for log output
24 *		o Better option log display
25 */
26#include "fsm.h"
27#include "hdlc.h"
28#include "lqr.h"
29#include "lcpproto.h"
30#include "lcp.h"
31#include "ccp.h"
32
33void FsmSendConfigReq(struct fsm *fp);
34void FsmSendTerminateReq(struct fsm *fp);
35void FsmInitRestartCounter(struct fsm *fp);
36void FsmTimeout(struct fsm *fp);
37
38char const *StateNames[] = {
39  "Initial", "Starting", "Closed", "Stopped", "Closing", "Stopping",
40  "Req-Sent", "Ack-Rcvd", "Ack-Sent", "Opened",
41};
42
43void
44FsmInit(fp)
45struct fsm *fp;
46{
47  LogPrintf(LogDEBUG, "FsmInit\n");
48  fp->state = ST_INITIAL;
49  fp->reqid = 1;
50  fp->restart = 1;
51  fp->maxconfig = 3;
52}
53
54void
55NewState(fp, new)
56struct fsm *fp;
57int new;
58{
59  LogPrintf(LogLCP, "State change %s --> %s\n",
60	  StateNames[fp->state], StateNames[new]);
61  fp->state = new;
62  if ((new >= ST_INITIAL && new <= ST_STOPPED) || (new == ST_OPENED))
63    StopTimer(&fp->FsmTimer);
64}
65
66void
67FsmOutput(fp, code, id, ptr, count)
68struct fsm *fp;
69u_int code, id;
70u_char *ptr;
71int count;
72{
73  int plen;
74  struct fsmheader lh;
75  struct mbuf *bp;
76
77  plen =  sizeof(struct fsmheader) + count;
78  lh.code = code;
79  lh.id = id;
80  lh.length = htons(plen);
81  bp = mballoc(plen, MB_FSM);
82  bcopy(&lh, MBUF_CTOP(bp), sizeof(struct fsmheader));
83  if (count)
84    bcopy(ptr, MBUF_CTOP(bp) + sizeof(struct fsmheader), count);
85  LogDumpBp(LogDEBUG, "FsmOutput", bp);
86  HdlcOutput(PRI_LINK, fp->proto, bp);
87}
88
89void
90FsmOpen(fp)
91struct fsm *fp;
92{
93  switch (fp->state) {
94  case ST_INITIAL:
95    (fp->LayerStart)(fp);
96    NewState(fp, ST_STARTING);
97    break;
98  case ST_STARTING:
99    break;
100  case ST_CLOSED:
101    if (fp->open_mode == OPEN_PASSIVE) {
102      NewState(fp, ST_STOPPED);
103    } else {
104      FsmInitRestartCounter(fp);
105      FsmSendConfigReq(fp);
106      NewState(fp, ST_REQSENT);
107    }
108    break;
109  case ST_STOPPED:	/* XXX: restart option */
110  case ST_REQSENT:
111  case ST_ACKRCVD:
112  case ST_ACKSENT:
113  case ST_OPENED:	/* XXX: restart option */
114    break;
115  case ST_CLOSING:	/* XXX: restart option */
116  case ST_STOPPING:	/* XXX: restart option */
117    NewState(fp, ST_STOPPING);
118    break;
119  }
120}
121
122void
123FsmUp(fp)
124struct fsm *fp;
125{
126  switch (fp->state) {
127  case ST_INITIAL:
128    NewState(fp, ST_CLOSED);
129    break;
130  case ST_STARTING:
131    FsmInitRestartCounter(fp);
132    FsmSendConfigReq(fp);
133    NewState(fp, ST_REQSENT);
134    break;
135  default:
136    LogPrintf(LogLCP, "Oops, Up at %s\n", StateNames[fp->state]);
137    break;
138  }
139}
140
141void
142FsmDown(fp)
143struct fsm *fp;
144{
145  switch (fp->state) {
146  case ST_CLOSED:
147  case ST_CLOSING:
148    NewState(fp, ST_INITIAL);
149    break;
150  case ST_STOPPED:
151    (fp->LayerStart)(fp);
152    /* Fall into.. */
153  case ST_STOPPING:
154  case ST_REQSENT:
155  case ST_ACKRCVD:
156  case ST_ACKSENT:
157    NewState(fp, ST_STARTING);
158    break;
159  case ST_OPENED:
160    (fp->LayerDown)(fp);
161    NewState(fp, ST_STARTING);
162    break;
163  }
164}
165
166void
167FsmClose(fp)
168struct fsm *fp;
169{
170  switch (fp->state) {
171  case ST_STARTING:
172    NewState(fp, ST_INITIAL);
173    break;
174  case ST_STOPPED:
175    NewState(fp, ST_CLOSED);
176    break;
177  case ST_STOPPING:
178    NewState(fp, ST_CLOSING);
179    break;
180  case ST_OPENED:
181    (fp->LayerDown)(fp);
182    /* Fall down */
183  case ST_REQSENT:
184  case ST_ACKRCVD:
185  case ST_ACKSENT:
186    FsmInitRestartCounter(fp);
187    FsmSendTerminateReq(fp);
188    NewState(fp, ST_CLOSING);
189    break;
190  }
191}
192
193/*
194 *	Send functions
195 */
196void
197FsmSendConfigReq(fp)
198struct fsm *fp;
199{
200  if (--fp->maxconfig > 0) {
201    (fp->SendConfigReq)(fp);
202    StartTimer(&fp->FsmTimer);	/* Start restart timer */
203    fp->restart--;		/* Decrement restart counter */
204  } else {
205    FsmClose(fp);
206  }
207}
208
209void
210FsmSendTerminateReq(fp)
211struct fsm *fp;
212{
213  LogPrintf(LogLCP, "SendTerminateReq.\n");
214  FsmOutput(fp, CODE_TERMREQ, fp->reqid++, NULL, 0);
215  (fp->SendTerminateReq)(fp);
216  StartTimer(&fp->FsmTimer);	/* Start restart timer */
217  fp->restart--;		/* Decrement restart counter */
218}
219
220static void
221FsmSendConfigAck(fp, lhp, option, count)
222struct fsm *fp;
223struct fsmheader *lhp;
224u_char *option;
225int count;
226{
227  LogPrintf(LogLCP, "SendConfigAck(%s)\n", StateNames[fp->state]);
228  (fp->DecodeConfig)(option, count, MODE_NOP);
229  FsmOutput(fp, CODE_CONFIGACK, lhp->id, option, count);
230}
231
232static void
233FsmSendConfigRej(fp, lhp, option, count)
234struct fsm *fp;
235struct fsmheader *lhp;
236u_char *option;
237int count;
238{
239  LogPrintf(LogLCP, "SendConfigRej(%s)\n", StateNames[fp->state]);
240  (fp->DecodeConfig)(option, count, MODE_NOP);
241  FsmOutput(fp, CODE_CONFIGREJ, lhp->id, option, count);
242}
243
244static void
245FsmSendConfigNak(fp, lhp, option, count)
246struct fsm *fp;
247struct fsmheader *lhp;
248u_char *option;
249int count;
250{
251  LogPrintf(LogLCP, "SendConfigNak(%s)\n", StateNames[fp->state]);
252  (fp->DecodeConfig)(option, count, MODE_NOP);
253  FsmOutput(fp, CODE_CONFIGNAK, lhp->id, option, count);
254}
255
256/*
257 *	Timeout actions
258 */
259void
260FsmTimeout(fp)
261struct fsm *fp;
262{
263  if (fp->restart) {
264    switch (fp->state) {
265    case ST_CLOSING:
266    case ST_STOPPING:
267      FsmSendTerminateReq(fp);
268      break;
269    case ST_REQSENT:
270    case ST_ACKSENT:
271      FsmSendConfigReq(fp);
272      break;
273    case ST_ACKRCVD:
274      FsmSendConfigReq(fp);
275      NewState(fp, ST_REQSENT);
276      break;
277    }
278    StartTimer(&fp->FsmTimer);
279  } else {
280    switch (fp->state) {
281    case ST_CLOSING:
282      NewState(fp, ST_CLOSED);
283      (fp->LayerFinish)(fp);
284      break;
285    case ST_STOPPING:
286      NewState(fp, ST_STOPPED);
287      (fp->LayerFinish)(fp);
288      break;
289    case ST_REQSENT:		/* XXX: 3p */
290    case ST_ACKSENT:
291    case ST_ACKRCVD:
292      NewState(fp, ST_STOPPED);
293      (fp->LayerFinish)(fp);
294      break;
295    }
296  }
297}
298
299void
300FsmInitRestartCounter(fp)
301struct fsm *fp;
302{
303  StopTimer(&fp->FsmTimer);
304  fp->FsmTimer.state = TIMER_STOPPED;
305  fp->FsmTimer.func = FsmTimeout;
306  fp->FsmTimer.arg = (void *)fp;
307  (fp->InitRestartCounter)(fp);
308}
309
310/*
311 *   Actions when receive packets
312 */
313void
314FsmRecvConfigReq(fp, lhp, bp)			/* RCR */
315struct fsm *fp;
316struct fsmheader *lhp;
317struct mbuf *bp;
318{
319  int plen, flen;
320  int ackaction = 0;
321
322  plen = plength(bp);
323  flen = ntohs(lhp->length) - sizeof(*lhp);
324  if (plen < flen) {
325    LogPrintf(LogERROR, "FsmRecvConfigReq: plen (%d) < flen (%d)", plen, flen);
326    pfree(bp);
327    return;
328  }
329
330
331  /*
332   *  Check and process easy case
333   */
334  switch (fp->state) {
335  case ST_INITIAL:
336  case ST_STARTING:
337    LogPrintf(LogLCP, "Oops, RCR in %s.\n", StateNames[fp->state]);
338    pfree(bp);
339    return;
340  case ST_CLOSED:
341    (fp->SendTerminateAck)(fp);
342    pfree(bp);
343    return;
344  case ST_CLOSING:
345  case ST_STOPPING:
346    LogPrintf(LogERROR, "Got ConfigReq while state = %d\n", fp->state);
347    pfree(bp);
348    return;
349  }
350
351  (fp->DecodeConfig)(MBUF_CTOP(bp), flen, MODE_REQ);
352
353  if (nakp == NakBuff && rejp == RejBuff)
354    ackaction = 1;
355
356  switch (fp->state) {
357  case ST_OPENED:
358    (fp->LayerDown)(fp);
359    FsmSendConfigReq(fp);
360    break;
361  case ST_STOPPED:
362    FsmInitRestartCounter(fp);
363    FsmSendConfigReq(fp);
364    break;
365  }
366
367  if (rejp != RejBuff)
368    FsmSendConfigRej(fp, lhp, RejBuff, rejp - RejBuff);
369  if (nakp != NakBuff)
370    FsmSendConfigNak(fp, lhp, NakBuff, nakp - NakBuff);
371  if (ackaction)
372    FsmSendConfigAck(fp, lhp, AckBuff, ackp - AckBuff);
373
374  switch (fp->state) {
375  case ST_STOPPED:
376  case ST_OPENED:
377    if (ackaction)
378      NewState(fp, ST_ACKSENT);
379    else
380      NewState(fp, ST_REQSENT);
381    break;
382  case ST_REQSENT:
383    if (ackaction)
384      NewState(fp, ST_ACKSENT);
385    break;
386  case ST_ACKRCVD:
387    if (ackaction) {
388      NewState(fp, ST_OPENED);
389      (fp->LayerUp)(fp);
390    }
391    break;
392  case ST_ACKSENT:
393    if (!ackaction)
394      NewState(fp, ST_REQSENT);
395    break;
396  }
397  pfree(bp);
398}
399
400void
401FsmRecvConfigAck(fp, lhp, bp)			/* RCA */
402struct fsm *fp;
403struct fsmheader *lhp;
404struct mbuf *bp;
405{
406  switch (fp->state) {
407  case ST_CLOSED:
408  case ST_STOPPED:
409    (fp->SendTerminateAck)(fp);
410    break;
411  case ST_CLOSING:
412  case ST_STOPPING:
413    break;
414  case ST_REQSENT:
415    FsmInitRestartCounter(fp);
416    NewState(fp, ST_ACKRCVD);
417    break;
418  case ST_ACKRCVD:
419    FsmSendConfigReq(fp);
420    NewState(fp, ST_REQSENT);
421    break;
422  case ST_ACKSENT:
423    FsmInitRestartCounter(fp);
424    NewState(fp, ST_OPENED);
425    (fp->LayerUp)(fp);
426    break;
427  case ST_OPENED:
428    (fp->LayerDown)(fp);
429    FsmSendConfigReq(fp);
430    NewState(fp, ST_REQSENT);
431    break;
432  }
433  pfree(bp);
434}
435
436void
437FsmRecvConfigNak(fp, lhp, bp)			/* RCN */
438struct fsm *fp;
439struct fsmheader *lhp;
440struct mbuf *bp;
441{
442  int plen, flen;
443
444  plen = plength(bp);
445  flen = ntohs(lhp->length) - sizeof(*lhp);
446  if (plen < flen) {
447    pfree(bp);
448    return;
449  }
450
451  /*
452   *  Check and process easy case
453   */
454  switch (fp->state) {
455  case ST_INITIAL:
456  case ST_STARTING:
457    LogPrintf(LogLCP, "Oops, RCN in %s.\n", StateNames[fp->state]);
458    pfree(bp);
459    return;
460  case ST_CLOSED:
461  case ST_STOPPED:
462    (fp->SendTerminateAck)(fp);
463    pfree(bp);
464    return;
465  case ST_CLOSING:
466  case ST_STOPPING:
467    pfree(bp);
468    return;
469  }
470
471  (fp->DecodeConfig)(MBUF_CTOP(bp), flen, MODE_NAK);
472
473  switch (fp->state) {
474  case ST_REQSENT:
475  case ST_ACKSENT:
476    FsmInitRestartCounter(fp);
477    FsmSendConfigReq(fp);
478    break;
479  case ST_OPENED:
480    (fp->LayerDown)(fp);
481    /* Fall down */
482  case ST_ACKRCVD:
483    FsmSendConfigReq(fp);
484    NewState(fp, ST_REQSENT);
485    break;
486  }
487
488  pfree(bp);
489}
490
491void
492FsmRecvTermReq(fp, lhp, bp)				/* RTR */
493struct fsm *fp;
494struct fsmheader *lhp;
495struct mbuf *bp;
496{
497  switch (fp->state) {
498  case ST_INITIAL:
499  case ST_STARTING:
500    LogPrintf(LogLCP, "Oops, RTR in %s\n", StateNames[fp->state]);
501    break;
502  case ST_CLOSED:
503  case ST_STOPPED:
504  case ST_CLOSING:
505  case ST_STOPPING:
506  case ST_REQSENT:
507    (fp->SendTerminateAck)(fp);
508    break;
509  case ST_ACKRCVD:
510  case ST_ACKSENT:
511    (fp->SendTerminateAck)(fp);
512    NewState(fp, ST_REQSENT);
513    break;
514  case ST_OPENED:
515    (fp->LayerDown)(fp);
516    (fp->SendTerminateAck)(fp);
517    StartTimer(&fp->FsmTimer);	/* Start restart timer */
518    fp->restart = 0;
519    NewState(fp, ST_STOPPING);
520    break;
521  }
522  pfree(bp);
523}
524
525void
526FsmRecvTermAck(fp, lhp, bp)			/* RTA */
527struct fsm *fp;
528struct fsmheader *lhp;
529struct mbuf *bp;
530{
531  switch (fp->state) {
532  case ST_CLOSING:
533    NewState(fp, ST_CLOSED);
534    (fp->LayerFinish)(fp);
535    break;
536  case ST_STOPPING:
537    NewState(fp, ST_STOPPED);
538    (fp->LayerFinish)(fp);
539    break;
540  case ST_ACKRCVD:
541    NewState(fp, ST_REQSENT);
542    break;
543  case ST_OPENED:
544    (fp->LayerDown)(fp);
545    FsmSendConfigReq(fp);
546    NewState(fp, ST_REQSENT);
547    break;
548  }
549  pfree(bp);
550}
551
552void
553FsmRecvConfigRej(fp, lhp, bp)			/* RCJ */
554struct fsm *fp;
555struct fsmheader *lhp;
556struct mbuf *bp;
557{
558  int plen, flen;
559
560  plen = plength(bp);
561  flen = ntohs(lhp->length) - sizeof(*lhp);
562  if (plen < flen) {
563    pfree(bp);
564    return;
565  }
566  LogPrintf(LogLCP, "RecvConfigRej.\n");
567
568  /*
569   *  Check and process easy case
570   */
571  switch (fp->state) {
572  case ST_INITIAL:
573  case ST_STARTING:
574    LogPrintf(LogLCP, "Oops, RCJ in %s.\n", StateNames[fp->state]);
575    pfree(bp);
576    return;
577  case ST_CLOSED:
578  case ST_STOPPED:
579    (fp->SendTerminateAck)(fp);
580    pfree(bp);
581    return;
582  case ST_CLOSING:
583  case ST_STOPPING:
584    pfree(bp);
585    return;
586  }
587
588  (fp->DecodeConfig)(MBUF_CTOP(bp), flen, MODE_REJ);
589
590  switch (fp->state) {
591  case ST_REQSENT:
592  case ST_ACKSENT:
593    FsmInitRestartCounter(fp);
594    FsmSendConfigReq(fp);
595    break;
596  case ST_OPENED:
597    (fp->LayerDown)(fp);
598    /* Fall down */
599  case ST_ACKRCVD:
600    FsmSendConfigReq(fp);
601    NewState(fp, ST_REQSENT);
602    break;
603  }
604  pfree(bp);
605}
606
607void
608FsmRecvCodeRej(fp, lhp, bp)
609struct fsm *fp;
610struct fsmheader *lhp;
611struct mbuf *bp;
612{
613  LogPrintf(LogLCP, "RecvCodeRej\n");
614  pfree(bp);
615}
616
617void
618FsmRecvProtoRej(fp, lhp, bp)
619struct fsm *fp;
620struct fsmheader *lhp;
621struct mbuf *bp;
622{
623  u_short *sp, proto;
624
625  sp = (u_short *)MBUF_CTOP(bp);
626  proto = ntohs(*sp);
627  LogPrintf(LogLCP, "-- Protocol (%04x) was rejected.\n", proto);
628
629  switch (proto) {
630  case PROTO_LQR:
631    StopLqr(LQM_LQR);
632    break;
633  case PROTO_CCP:
634    fp = &CcpFsm;
635    (fp->LayerFinish)(fp);
636    switch (fp->state) {
637    case ST_CLOSED:
638    case ST_CLOSING:
639      NewState(fp, ST_CLOSED);
640    default:
641      NewState(fp, ST_STOPPED);
642      break;
643    }
644    break;
645  }
646  pfree(bp);
647}
648
649void
650FsmRecvEchoReq(fp, lhp, bp)
651struct fsm *fp;
652struct fsmheader *lhp;
653struct mbuf *bp;
654{
655  u_char *cp;
656  u_long *lp, magic;
657
658  cp = MBUF_CTOP(bp);
659  lp = (u_long *)cp;
660  magic = ntohl(*lp);
661  if (magic != LcpInfo.his_magic) {
662    LogPrintf(LogERROR, "RecvEchoReq: his magic is bad!!\n");
663    /* XXX: We should send terminate request */
664  }
665
666  if (fp->state == ST_OPENED) {
667    *lp = htonl(LcpInfo.want_magic);	/* Insert local magic number */
668    LogPrintf(LogLCP, "SendEchoRep(%s)\n", StateNames[fp->state]);
669    FsmOutput(fp, CODE_ECHOREP, lhp->id, cp, plength(bp));
670  }
671  pfree(bp);
672}
673
674void
675FsmRecvEchoRep(fp, lhp, bp)
676struct fsm *fp;
677struct fsmheader *lhp;
678struct mbuf *bp;
679{
680  u_long *lp, magic;
681
682  lp = (u_long *)MBUF_CTOP(bp);
683  magic = ntohl(*lp);
684/*
685 * Tolerate echo replies with either magic number
686 */
687  if (magic != 0 && magic != LcpInfo.his_magic && magic != LcpInfo.want_magic) {
688    LogPrintf(LogERROR, "RecvEchoRep: his magic is wrong! expect: %x got: %x\n",
689	LcpInfo.his_magic, magic);
690    /*
691     *  XXX: We should send terminate request. But poor implementation
692     *       may die as a result.
693     */
694  }
695  RecvEchoLqr(bp);
696  pfree(bp);
697}
698
699void
700FsmRecvDiscReq(fp, lhp, bp)
701struct fsm *fp;
702struct fsmheader *lhp;
703struct mbuf *bp;
704{
705  LogPrintf(LogLCP, "RecvDiscReq\n");
706  pfree(bp);
707}
708
709void
710FsmRecvIdent(fp, lhp, bp)
711struct fsm *fp;
712struct fsmheader *lhp;
713struct mbuf *bp;
714{
715  LogPrintf(LogLCP, "RecvIdent\n");
716  pfree(bp);
717}
718
719void
720FsmRecvTimeRemain(fp, lhp, bp)
721struct fsm *fp;
722struct fsmheader *lhp;
723struct mbuf *bp;
724{
725  LogPrintf(LogLCP, "RecvTimeRemain\n");
726  pfree(bp);
727}
728
729void
730FsmRecvResetReq(fp, lhp, bp)
731struct fsm *fp;
732struct fsmheader *lhp;
733struct mbuf *bp;
734{
735  LogPrintf(LogLCP, "RecvResetReq\n");
736  CcpRecvResetReq(fp);
737  LogPrintf(LogLCP, "SendResetAck\n");
738  FsmOutput(fp, CODE_RESETACK, fp->reqid, NULL, 0);
739  pfree(bp);
740}
741
742void
743FsmRecvResetAck(fp, lhp, bp)
744struct fsm *fp;
745struct fsmheader *lhp;
746struct mbuf *bp;
747{
748  LogPrintf(LogLCP, "RecvResetAck\n");
749  fp->reqid++;
750  pfree(bp);
751}
752
753struct fsmcodedesc FsmCodes[] = {
754 { FsmRecvConfigReq,  "Configure Request", },
755 { FsmRecvConfigAck,  "Configure Ack", },
756 { FsmRecvConfigNak,  "Configure Nak", },
757 { FsmRecvConfigRej,  "Configure Reject", },
758 { FsmRecvTermReq,    "Terminate Request", },
759 { FsmRecvTermAck,    "Terminate Ack", },
760 { FsmRecvCodeRej,    "Code Reject", },
761 { FsmRecvProtoRej,   "Protocol Reject", },
762 { FsmRecvEchoReq,    "Echo Request", },
763 { FsmRecvEchoRep,    "Echo Reply", },
764 { FsmRecvDiscReq,    "Discard Request", },
765 { FsmRecvIdent,      "Ident", },
766 { FsmRecvTimeRemain, "Time Remain", },
767 { FsmRecvResetReq,   "Reset Request", },
768 { FsmRecvResetAck,   "Reset Ack", },
769};
770
771void
772FsmInput(fp, bp)
773struct fsm *fp;
774struct mbuf *bp;
775{
776  int len;
777  struct fsmheader *lhp;
778  struct fsmcodedesc *codep;
779
780  len = plength(bp);
781  if (len < sizeof(struct fsmheader)) {
782    pfree(bp);
783    return;
784  }
785  lhp = (struct fsmheader *)MBUF_CTOP(bp);
786  if (lhp->code == 0 || lhp->code > fp->max_code) {
787    pfree(bp);		/* XXX: Should send code reject */
788    return;
789  }
790
791  bp->offset += sizeof(struct fsmheader);
792  bp->cnt -= sizeof(struct fsmheader);
793
794  codep = FsmCodes + lhp->code - 1;
795  LogPrintf(LogLCP, "Received %s (%d) state = %s (%d)\n",
796    codep->name, lhp->id, StateNames[fp->state], fp->state);
797  if (LogIsKept(LogDEBUG))
798    LogMemory();
799  (codep->action)(fp, lhp, bp);
800  if (LogIsKept(LogDEBUG))
801    LogMemory();
802}
803