1 // Copyright 2017 The Fuchsia Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4
5 #include <inttypes.h>
6 #include <string.h>
7
8 #include <zircon/syscalls.h>
9 #include <zircon/syscalls/log.h>
10
11 #include "netsvc.h"
12
13 #define MAX_LOG_LINE (ZX_LOG_RECORD_MAX + 32)
14
15 static zx_handle_t loghandle;
16 static logpacket_t pkt;
17 static int pkt_len;
18
19 static volatile uint32_t seqno = 1;
20 static volatile uint32_t pending = 0;
21
22 zx_time_t debuglog_next_timeout = ZX_TIME_INFINITE;
23
24 #define SEND_DELAY_SHORT ZX_MSEC(100)
25 #define SEND_DELAY_LONG ZX_SEC(4)
26
27 // Number of consecutive unacknowledged packets we will send before reducing send rate.
28 static const unsigned kUnackedThreshold = 5;
29
30 // Number of consecutive packets that went unacknowledged. Is reset on acknowledgment.
31 static unsigned num_unacked = 0;
32
33 // How long to wait between sending.
34 static zx_duration_t send_delay = SEND_DELAY_SHORT;
35
get_log_line(char * out)36 static int get_log_line(char* out) {
37 char buf[ZX_LOG_RECORD_MAX + 1];
38 zx_log_record_t* rec = (zx_log_record_t*)buf;
39 for (;;) {
40 if (zx_debuglog_read(loghandle, 0, rec, ZX_LOG_RECORD_MAX) > 0) {
41 if (rec->datalen && (rec->data[rec->datalen - 1] == '\n')) {
42 rec->datalen--;
43 }
44 // records flagged for local display are ignored
45 if (rec->flags & ZX_LOG_LOCAL) {
46 continue;
47 }
48 rec->data[rec->datalen] = 0;
49 snprintf(out, MAX_LOG_LINE, "[%05d.%03d] %05" PRIu64 ".%05" PRIu64 "> %s\n",
50 (int)(rec->timestamp / 1000000000ULL),
51 (int)((rec->timestamp / 1000000ULL) % 1000ULL),
52 rec->pid, rec->tid, rec->data);
53 return strlen(out);
54 } else {
55 return 0;
56 }
57 }
58 }
59
debuglog_init(void)60 int debuglog_init(void) {
61 if (zx_debuglog_create(ZX_HANDLE_INVALID, ZX_LOG_FLAG_READABLE, &loghandle) < 0) {
62 return -1;
63 }
64
65 // Set up our timeout to expire immediately, so that we check for pending log messages
66 debuglog_next_timeout = zx_clock_get_monotonic();
67
68 seqno = 1;
69 pending = 0;
70
71 return 0;
72 }
73
74 // If we have an outstanding (unacknowledged) log, resend it. Otherwise, send new logs, if we
75 // have any.
debuglog_send(void)76 static void debuglog_send(void) {
77 if (pending == 0) {
78 pkt.magic = NB_DEBUGLOG_MAGIC;
79 pkt.seqno = seqno;
80 strncpy(pkt.nodename, nodename, sizeof(pkt.nodename) - 1);
81 pkt_len = 0;
82 while (pkt_len < (MAX_LOG_DATA - MAX_LOG_LINE)) {
83 int r = get_log_line(pkt.data + pkt_len);
84 if (r > 0) {
85 pkt_len += r;
86 } else {
87 break;
88 }
89 }
90 if (pkt_len) {
91 // include header and nodename in length
92 pkt_len += MAX_NODENAME_LENGTH + sizeof(uint32_t) * 2;
93 pending = 1;
94 } else {
95 goto done;
96 }
97 }
98 udp6_send(&pkt, pkt_len, &ip6_ll_all_nodes, DEBUGLOG_PORT, DEBUGLOG_ACK_PORT, false);
99 done:
100 debuglog_next_timeout = zx_deadline_after(send_delay);
101 }
102
debuglog_recv(void * data,size_t len,bool is_mcast)103 void debuglog_recv(void* data, size_t len, bool is_mcast) {
104 // The only message we should be receiving is acknowledgement of our last transmission
105 if (!pending) {
106 return;
107 }
108 if ((len != 8) || is_mcast) {
109 return;
110 }
111 logpacket_t* pkt = data;
112 if ((pkt->magic != NB_DEBUGLOG_MAGIC) || (pkt->seqno != seqno)) {
113 return;
114 }
115
116 // Received an ack. We have an active listener. Don't delay.
117 num_unacked = 0;
118 send_delay = SEND_DELAY_SHORT;
119
120 seqno++;
121 pending = 0;
122 debuglog_send();
123 }
124
debuglog_timeout_expired(void)125 void debuglog_timeout_expired(void) {
126 if (pending) {
127 // No reply. If noone is listening, reduce send rate.
128 if (++num_unacked >= kUnackedThreshold) {
129 send_delay = SEND_DELAY_LONG;
130 }
131 }
132 debuglog_send();
133 }
134
135