This is the result, on a master, with "-d 02":

diag-time-2-eth0: posix_time_get:  1362675879.940187923
diag-time-1-eth0: timeout expired: PP_TO_ANN_INTERVAL
diag-time-2-eth0: posix_time_get:  1362675880.081818439
diag-time-2-eth0: posix_time_get:  1362675880.233227916
diag-time-2-eth0: recv stamp: 1362675880.233227916 (user)
diag-time-2-eth0: posix_time_get:  1362675880.233499803
diag-time-1-eth0: timeout expired: PP_TO_SYNC

(time level 1 reports timeouts and set, level 2 reports get-time too).
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Unfortunately, we need to pass ppi to the time operations, so we
can have per-instance logging options. This is the second time I found
the need for such extra argument: the first time I worked it around, now
I surrender.

Actually, I don't find it unlikely for a multi-instance process to
spit a lot of diagnostics about timestamps. A developer may need to
filter messages according to who is tiemstamping/timing out etc.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

One I forgot to remove when cleaning arch-spec, the oter I re-added by
error quite some commits ago, after it was moved to
lib-bare/bare-time.c
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

This kills the global build-time macro pp_verbose_servo and uses flags
instead.  Again, until I review the servo, stuff is not always
per-instance.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

This kills the global build-time macro pp_verbose_dump to use flags
instead.  In msg.c this commit fakes the old pp_verbose_dump, which
however is extracted from the global flags.

So, setting "frames" level to 2 prints information on frames being
received ("-d 002").

Until I get to integrate tools/ptpdump in the daemon itself, we have
no instance-specific dump, nor symmetric dumping of input and output.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

An error of mine. Removed, but make pp_error add "ERROR: " in front of
the format string it receives.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

This converts fsm.c to use the new diagnostics. We keep printing
the timestamp for fsm messages, which means diag.c::__pp_diag is
somehow duplicated here (in what was called pp_timed_printf).

This is the output with "-d 1" (or "-d "100") on a forced-slave ("-g"):

  diag level: 10000000
  diag-fsm-1-eth0: 1362666577.043: ENTER initializing, packet len 0
  diag-fsm-1-eth0: 1362666577.045: LEAVE initializing (next:   4 in 0 ms)
  diag-fsm-1-eth0: 1362666577.045: ENTER listening, packet len 0
  diag-fsm-1-eth0: 1362666577.045: listening: reenter in 11999 ms
  diag-fsm-1-eth0: 1362666587.204: listening: reenter in 1840 ms
  diag-fsm-1-eth0: 1362666588.388: LEAVE listening (next:   9 in 0 ms)
  diag-fsm-1-eth0: 1362666588.388: ENTER slave, packet len 44
  diag-fsm-1-eth0: 1362666588.389: slave: reenter in 889 ms
  diag-fsm-1-eth0: 1362666589.219: slave: reenter in 59 ms
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

By passing "-V -d 001" now I get level-1 diagnostics for frames (i.e.
sending and receiving):

Slave:

   diag-frames-1-eth0: RECV 44 bytes at 1362665418.025198568 (type 0)
   diag-frames-1-eth0: RECV 44 bytes at 1362665418.025970153 (type 8)
   diag-frames-1-eth0: SENT 44 bytes at 1362665416.806670510 (delay_req)
   diag-frames-1-eth0: RECV 54 bytes at 1362665416.808217467 (type 9)

Master:

   diag-frames-1-eth0: SENT 64 bytes at 1362665415.430554014 (announce)
   diag-frames-1-eth0: SENT 44 bytes at 1362665416.612818573 (sync)
   diag-frames-1-eth0: SENT 44 bytes at 1362665416.613056524 (follow_up)
   diag-frames-1-eth0: RECV 44 bytes at 1362665416.807983194 (type 1)
   diag-frames-1-eth0: SENT 54 bytes at 1362665416.808206209 (delay_resp)

(note: we don't tell names at receive time because the frame is still
to be validated).
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

This only introduces the header files, the actual code is still
missing, and is added by later commits. I still want this to be by
itself because it explains the thing (please read the comments in
diag-macros.h, that I won't copy in this commit message).
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

I need to refer to ppi->flags from inside diag-macros.h, so
this splits out a new header, which is expected to only be included
by ppsi.h (no change for our developers).
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Actually, until this commit we could not use pp_printf inside
ppsi.h, in inline functions or whatever.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

This adds the interface name where the error happened (we'll need it
for multi-link setups, that Aurelio is going to implement soon).

Moreover, this kills the last pp_diag_error call
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

This finally removes the diag directory by folding two one-line
functions into diag.h.  The dir is a relic of ptp-proposal that
hosted pp_printf, but now we have it separate anyways.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

fsm.c is the only user of timed_printf, and actually I don't expect
other messages to need timing (since we know the time from the fsm
states).

I may repent, I'm aware. But at this point I'm killing diag-yes, to
make the one and true diagnostic environment, without duplications and
conflicts.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Since diagnostics about the fsm is only used in fsm.c, move it there
so we have less global context and we are all happier.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

diag_fatal enters a while(1) loop, but the code here reports the
error to the caller. So calling diag_fatal was wrong.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Really, this is an extrac complexity with no advantage (did we ever
use it?)  If users really want a small system they can choose the NONE
implementation of pp_printf.  The extra half a kilobyte saved by diag-no
is really not worth the effort:

% make clean; make -s ARCH=bare-i386 CONFIG_PRINTF_NONE=y
% size ppsi.o
   text    data     bss     dec     hex filename
  10323     208     264   10795    2a2b ppsi.o

% make clean; make -s ARCH=bare-i386 CONFIG_PRINTF_NONE=y PPSI_NO_DIAG=y
% size ppsi.o
   text    data     bss     dec     hex filename
   9792     208     264   10264    2818 ppsi.o
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

fsm.c corrently decodes the received frame, and error management is
built in (even if code in msg.c still needs to be audited to be more
careful about rogue frames).  However, when a received frame is in
error, fsm.c cannot return to the caller because it doesn't know the
current delay. Thus, zero the frame and call the current status, so
we have back a recalculated ppi->next_delay.

Meanwhile, mask with pp_verbose_frames the diagnostic message for
received frames -- and be more careful with accessing it's data.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

A number of states were setting ppi->next_delay before re-setting
it to a different value, or setting it on a state change (which now
occurs immediately)
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

fsm states where we are waitiing for a frame or for a timeout,
now correctly set next_delay to the right number of milliseconds.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

The new function reports how many ms in the future is a timeout event,
to be able to correctly time when we should re-entering the state machine
and correctly spread our frames according to the specification.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

The function is called by several states, but only state-slave
is checking the delay request timeout. Thus, this commit removes
the associated lines from the common function and moves them back
to state-slave, the only state that issues delay_request frames.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

All archs allocated one foreign master, but the default was 5 and
the command line could even change it.  Hardwire the number to 5
and skip the allocation by folding the array in pp_instance itself.

Anyways, the add_foreign() function needs serious review, later on.
Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>

Signed-off-by: Alessandro Rubini <rubini@gnudd.com>