From 59b89cfac8c3e0402b8e3c27cca8990674b8a5e3 Mon Sep 17 00:00:00 2001 From: xengineering Date: Sat, 1 Jul 2023 19:55:11 +0200 Subject: Implement byte-based logging for TX Using an io.MultiWriter it is trivially possible to write encoded tokens to the TCP channel aswell as to stdout. The disadvantage is that it is not possible to inject prefix data like the so far used `C: ` only for stdout and not for the TCP channel. Such a prefix is not wanted in the TCP channel and thus not wanted for both. The solution to get a nice log is to implement a transparent logging middleware which gets the raw TX stream and inserts a prefix at each line before sending to stdout. --- xmpp/encoder_decoder.go | 24 ++++++------------------ 1 file changed, 6 insertions(+), 18 deletions(-) diff --git a/xmpp/encoder_decoder.go b/xmpp/encoder_decoder.go index c340b09..6a37c42 100644 --- a/xmpp/encoder_decoder.go +++ b/xmpp/encoder_decoder.go @@ -10,8 +10,7 @@ import ( type encoderDecoder struct { session *session - ct *xml.Encoder // client transport encoder - cl *xml.Encoder // client log encoder + tx *xml.Encoder st *xml.Decoder // server transport decoder sl *xml.Encoder // server log encoder terminator chan bool @@ -22,11 +21,9 @@ func newEncoderDecoder(s *session) encoderDecoder { ed.session = s - ed.ct = xml.NewEncoder(s.transport) - ed.ct.Indent("", " ") - - ed.cl = xml.NewEncoder(os.Stdout) - ed.cl.Indent("C: ", " ") + w := io.MultiWriter(s.transport, os.Stdout) + ed.tx = xml.NewEncoder(w) + ed.tx.Indent("", " ") ed.st = xml.NewDecoder(s.transport) @@ -44,20 +41,11 @@ func (ed *encoderDecoder) encodeToken(t xml.Token) error { } }() - err = ed.ct.EncodeToken(t) - if err != nil { - return err - } - err = ed.ct.Flush() - if err != nil { - return err - } - - err = ed.cl.EncodeToken(t) + err = ed.tx.EncodeToken(t) if err != nil { return err } - err = ed.cl.Flush() + err = ed.tx.Flush() if err != nil { return err } -- cgit v1.2.3-70-g09d2 From ad882d60b7dabeb4d4ece6435c2fad9f23ab821f Mon Sep 17 00:00:00 2001 From: xengineering Date: Sat, 1 Jul 2023 20:05:56 +0200 Subject: Implement byte-based logging for RX This commit uses an io.TeeReader to achieve the same goal for RX like in the previous commit for TX. --- xmpp/encoder_decoder.go | 19 ++++--------------- 1 file changed, 4 insertions(+), 15 deletions(-) diff --git a/xmpp/encoder_decoder.go b/xmpp/encoder_decoder.go index 6a37c42..e7eeaf8 100644 --- a/xmpp/encoder_decoder.go +++ b/xmpp/encoder_decoder.go @@ -11,8 +11,7 @@ import ( type encoderDecoder struct { session *session tx *xml.Encoder - st *xml.Decoder // server transport decoder - sl *xml.Encoder // server log encoder + rx *xml.Decoder terminator chan bool } @@ -25,10 +24,8 @@ func newEncoderDecoder(s *session) encoderDecoder { ed.tx = xml.NewEncoder(w) ed.tx.Indent("", " ") - ed.st = xml.NewDecoder(s.transport) - - ed.sl = xml.NewEncoder(os.Stdout) - ed.sl.Indent("S: ", " ") + r := io.TeeReader(s.transport, os.Stdout) + ed.rx = xml.NewDecoder(r) return ed } @@ -59,16 +56,8 @@ func (ed *encoderDecoder) run() { case <-ed.terminator: return default: - t, err := ed.st.Token() + t, err := ed.rx.Token() if t != nil && err == nil { - err = ed.sl.EncodeToken(t) - if err != nil { - log.Println("Could not encode to server stream log") - } - err = ed.sl.Flush() - if err != nil { - log.Println("Could not flush server stream log") - } c := xml.CopyToken(t) ed.session.rx <- c } -- cgit v1.2.3-70-g09d2 From 8a0a460089d3ee1a2e1b69991da546034531f8de Mon Sep 17 00:00:00 2001 From: xengineering Date: Sat, 1 Jul 2023 20:25:26 +0200 Subject: Add log module based XML logging with prefix The prefix is re-implemented with this commit to distinguish between RX and TX XML. Furthermore the logging is now based on the log module to have the same (e.g. timestamp) prefix as other log messages. --- xmpp/encoder_decoder.go | 7 ++++--- xmpp/log.go | 15 +++++++++++++++ 2 files changed, 19 insertions(+), 3 deletions(-) create mode 100644 xmpp/log.go diff --git a/xmpp/encoder_decoder.go b/xmpp/encoder_decoder.go index e7eeaf8..f6958be 100644 --- a/xmpp/encoder_decoder.go +++ b/xmpp/encoder_decoder.go @@ -5,7 +5,6 @@ import ( "errors" "io" "log" - "os" ) type encoderDecoder struct { @@ -20,11 +19,13 @@ func newEncoderDecoder(s *session) encoderDecoder { ed.session = s - w := io.MultiWriter(s.transport, os.Stdout) + lw := logger{"TX: "} + w := io.MultiWriter(s.transport, lw) ed.tx = xml.NewEncoder(w) ed.tx.Indent("", " ") - r := io.TeeReader(s.transport, os.Stdout) + lr := logger{"RX: "} + r := io.TeeReader(s.transport, lr) ed.rx = xml.NewDecoder(r) return ed diff --git a/xmpp/log.go b/xmpp/log.go new file mode 100644 index 0000000..4ac0f88 --- /dev/null +++ b/xmpp/log.go @@ -0,0 +1,15 @@ +package xmpp + +import ( + "log" +) + +type logger struct { + prefix string +} + +func (l logger) Write(p []byte) (n int, err error) { + log.Printf("%s%s", l.prefix, string(p)) + + return len(p), nil +} -- cgit v1.2.3-70-g09d2 From 342364d134ad4bbf64b1d0f077fb74fd0d86b454 Mon Sep 17 00:00:00 2001 From: xengineering Date: Sat, 1 Jul 2023 20:50:10 +0200 Subject: Improve prefix and disable indent The prefix has now more visual contrast to the XML content due to its own bracket style. Furthermore the indent for the TX stream was disabled. Indent is a nice thing but it just makes sense if both streams are indented identically. Since the RX stream received from the current development server has no indent and also no newlines it is better to turn it of completely. This might change in the future with structured logging (with the new slog package) or command line flags to toggle this behaviour. Re-encoding of the RX stream could also be an option but should stay one because it alters the RX stream and might hide errors during debugging. --- xmpp/encoder_decoder.go | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/xmpp/encoder_decoder.go b/xmpp/encoder_decoder.go index f6958be..d7951b3 100644 --- a/xmpp/encoder_decoder.go +++ b/xmpp/encoder_decoder.go @@ -19,12 +19,12 @@ func newEncoderDecoder(s *session) encoderDecoder { ed.session = s - lw := logger{"TX: "} + lw := logger{"[TX] "} w := io.MultiWriter(s.transport, lw) ed.tx = xml.NewEncoder(w) - ed.tx.Indent("", " ") + ed.tx.Indent("", "") - lr := logger{"RX: "} + lr := logger{"[RX] "} r := io.TeeReader(s.transport, lr) ed.rx = xml.NewDecoder(r) -- cgit v1.2.3-70-g09d2 From 6e973cfabe17421748af51856351f83e9856d137 Mon Sep 17 00:00:00 2001 From: xengineering Date: Sat, 1 Jul 2023 20:57:15 +0200 Subject: Drop xml.{ProcInst,Directive,Comment} LimoX does not care about these XML tokens at least for now. The issued error messages on other levels. Dropping those tokens on the encoderDecoder level asserts that the rest of the xmpp code has only `clean` XML content to process. --- xmpp/encoder_decoder.go | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/xmpp/encoder_decoder.go b/xmpp/encoder_decoder.go index d7951b3..b0ea77b 100644 --- a/xmpp/encoder_decoder.go +++ b/xmpp/encoder_decoder.go @@ -59,8 +59,14 @@ func (ed *encoderDecoder) run() { default: t, err := ed.rx.Token() if t != nil && err == nil { - c := xml.CopyToken(t) - ed.session.rx <- c + switch t.(type) { + case xml.ProcInst: + case xml.Directive: + case xml.Comment: + default: + c := xml.CopyToken(t) + ed.session.rx <- c + } } if err != nil { if errors.Is(err, io.EOF) { -- cgit v1.2.3-70-g09d2