1
Fork 0
mirror of https://github.com/RGBCube/serenity synced 2025-07-25 15:27:35 +00:00

Kernel: Use klog() instead of kprintf()

Also, duplicate data in dbg() and klog() calls were removed.
In addition, leakage of virtual address to kernel log is prevented.
This is done by replacing kprintf() calls to dbg() calls with the
leaked data instead.
Also, other kprintf() calls were replaced with klog().
This commit is contained in:
Liav A 2020-03-01 21:45:39 +02:00 committed by Andreas Kling
parent 19aa53e1f9
commit 0fc60e41dd
53 changed files with 397 additions and 573 deletions

View file

@ -68,7 +68,7 @@ IPv4Socket::IPv4Socket(int type, int protocol)
: Socket(AF_INET, type, protocol)
{
#ifdef IPV4_SOCKET_DEBUG
kprintf("%s(%u) IPv4Socket{%p} created with type=%u, protocol=%d\n", Process::current->name().characters(), Process::current->pid(), this, type, protocol);
dbg() << "IPv4Socket{" << this << "} created with type=" << type << ", protocol=" << protocol;
#endif
m_buffer_mode = type == SOCK_STREAM ? BufferMode::Bytes : BufferMode::Packets;
if (m_buffer_mode == BufferMode::Bytes) {
@ -138,7 +138,7 @@ KResult IPv4Socket::listen(size_t backlog)
m_role = Role::Listener;
#ifdef IPV4_SOCKET_DEBUG
kprintf("IPv4Socket{%p} listening with backlog=%zu\n", this, backlog);
dbg() << "IPv4Socket{" << this << "} listening with backlog=" << backlog;
#endif
return protocol_listen();
@ -201,7 +201,7 @@ ssize_t IPv4Socket::sendto(FileDescription&, const void* data, size_t data_lengt
if (addr) {
if (addr->sa_family != AF_INET) {
kprintf("sendto: Bad address family: %u is not AF_INET!\n", addr->sa_family);
klog() << "sendto: Bad address family: " << addr->sa_family << " is not AF_INET!";
return -EAFNOSUPPORT;
}
@ -222,7 +222,7 @@ ssize_t IPv4Socket::sendto(FileDescription&, const void* data, size_t data_lengt
return rc;
#ifdef IPV4_SOCKET_DEBUG
kprintf("sendto: destination=%s:%u\n", m_peer_address.to_string().characters(), m_peer_port);
klog() << "sendto: destination=" << m_peer_address.to_string().characters() << ":" << m_peer_port;
#endif
if (type() == SOCK_RAW) {
@ -283,13 +283,13 @@ ssize_t IPv4Socket::receive_packet_buffered(FileDescription& description, void*
packet = m_receive_queue.take_first();
m_can_read = !m_receive_queue.is_empty();
#ifdef IPV4_SOCKET_DEBUG
kprintf("IPv4Socket(%p): recvfrom without blocking %d bytes, packets in queue: %zu\n", this, packet.data.value().size(), m_receive_queue.size_slow());
dbg() << "IPv4Socket(" << this << "): recvfrom without blocking " << packet.data.value().size() << " bytes, packets in queue: " << m_receive_queue.size_slow();
#endif
}
}
if (!packet.data.has_value()) {
if (protocol_is_disconnected()) {
kprintf("IPv4Socket{%p} is protocol-disconnected, returning 0 in recvfrom!\n", this);
dbg() << "IPv4Socket{" << this << "} is protocol-disconnected, returning 0 in recvfrom!";
return 0;
}
@ -308,7 +308,7 @@ ssize_t IPv4Socket::receive_packet_buffered(FileDescription& description, void*
packet = m_receive_queue.take_first();
m_can_read = !m_receive_queue.is_empty();
#ifdef IPV4_SOCKET_DEBUG
kprintf("IPv4Socket(%p): recvfrom with blocking %d bytes, packets in queue: %zu\n", this, packet.data.value().size(), m_receive_queue.size_slow());
dbg() << "IPv4Socket(" << this << "): recvfrom with blocking " << packet.data.value().size() << " bytes, packets in queue: " << m_receive_queue.size_slow();
#endif
}
ASSERT(packet.data.has_value());
@ -341,7 +341,7 @@ ssize_t IPv4Socket::recvfrom(FileDescription& description, void* buffer, size_t
return -EINVAL;
#ifdef IPV4_SOCKET_DEBUG
kprintf("recvfrom: type=%d, local_port=%u\n", type(), local_port());
klog() << "recvfrom: type=" << type() << ", local_port=" << local_port();
#endif
ssize_t nreceived = 0;
@ -367,7 +367,7 @@ bool IPv4Socket::did_receive(const IPv4Address& source_address, u16 source_port,
if (buffer_mode() == BufferMode::Bytes) {
size_t space_in_receive_buffer = m_receive_buffer.space_for_writing();
if (packet_size > space_in_receive_buffer) {
kprintf("IPv4Socket(%p): did_receive refusing packet since buffer is full.\n", this);
dbg() << "IPv4Socket(" << this << "): did_receive refusing packet since buffer is full.";
ASSERT(m_can_read);
return false;
}
@ -377,7 +377,7 @@ bool IPv4Socket::did_receive(const IPv4Address& source_address, u16 source_port,
} else {
// FIXME: Maybe track the number of packets so we don't have to walk the entire packet queue to count them..
if (m_receive_queue.size_slow() > 2000) {
kprintf("IPv4Socket(%p): did_receive refusing packet since queue is full.\n", this);
dbg() << "IPv4Socket(" << this << "): did_receive refusing packet since queue is full.";
return false;
}
m_receive_queue.append({ source_address, source_port, move(packet) });
@ -386,9 +386,9 @@ bool IPv4Socket::did_receive(const IPv4Address& source_address, u16 source_port,
m_bytes_received += packet_size;
#ifdef IPV4_SOCKET_DEBUG
if (buffer_mode() == BufferMode::Bytes)
kprintf("IPv4Socket(%p): did_receive %d bytes, total_received=%u\n", this, packet_size, m_bytes_received);
dbg() << "IPv4Socket(" << this << "): did_receive " << packet_size << " bytes, total_received=" << m_bytes_received;
else
kprintf("IPv4Socket(%p): did_receive %d bytes, total_received=%u, packets in queue: %zu\n", this, packet_size, m_bytes_received, m_receive_queue.size_slow());
dbg() << "IPv4Socket(" << this << "): did_receive " << packet_size << " bytes, total_received=" << m_bytes_received << ", packets in queue: " << m_receive_queue.size_slow();
#endif
return true;
}

View file

@ -68,7 +68,7 @@ LocalSocket::LocalSocket(int type)
m_prebind_mode = 0666;
#ifdef DEBUG_LOCAL_SOCKET
kprintf("%s(%u) LocalSocket{%p} created with type=%u\n", Process::current->name().characters(), Process::current->pid(), this, type);
dbg() << "LocalSocket{" << this << "} created with type=" << type;
#endif
}
@ -105,7 +105,7 @@ KResult LocalSocket::bind(const sockaddr* user_address, socklen_t address_size)
auto path = String(address.sun_path, strnlen(address.sun_path, sizeof(address.sun_path)));
#ifdef DEBUG_LOCAL_SOCKET
kprintf("%s(%u) LocalSocket{%p} bind(%s)\n", Process::current->name().characters(), Process::current->pid(), this, safe_address);
dbg() << "LocalSocket{" << this << "} bind(" << safe_address << ")";
#endif
mode_t mode = S_IFSOCK | (m_prebind_mode & 04777);
@ -145,7 +145,7 @@ KResult LocalSocket::connect(FileDescription& description, const sockaddr* addre
memcpy(safe_address, local_address.sun_path, sizeof(local_address.sun_path));
#ifdef DEBUG_LOCAL_SOCKET
kprintf("%s(%u) LocalSocket{%p} connect(%s)\n", Process::current->name().characters(), Process::current->pid(), this, safe_address);
dbg() << "LocalSocket{" << this << "} connect(" << safe_address << ")";
#endif
auto description_or_error = VFS::the().open(safe_address, O_RDWR, 0, Process::current->current_directory());
@ -181,7 +181,7 @@ KResult LocalSocket::connect(FileDescription& description, const sockaddr* addre
}
#ifdef DEBUG_LOCAL_SOCKET
kprintf("%s(%u) LocalSocket{%p} connect(%s) status is %s\n", Process::current->name().characters(), Process::current->pid(), this, safe_address, to_string(setup_state()));
dbg() << "LocalSocket{" << this << "} connect(" << safe_address << ") status is " << to_string(setup_state());
#endif
if (!is_connected()) {
@ -200,7 +200,7 @@ KResult LocalSocket::listen(size_t backlog)
set_backlog(backlog);
m_connect_side_role = m_role = Role::Listener;
#ifdef DEBUG_LOCAL_SOCKET
kprintf("LocalSocket{%p} listening with backlog=%zu\n", this, backlog);
dbg() << "LocalSocket{" << this << "} listening with backlog=" << backlog;
#endif
return KSuccess;
}

View file

@ -72,12 +72,7 @@ void NetworkTask_main()
adapter.set_ipv4_gateway({ 10, 0, 2, 2 });
}
kprintf("NetworkTask: %s network adapter found: hw=%s address=%s netmask=%s gateway=%s\n",
adapter.class_name(),
adapter.mac_address().to_string().characters(),
adapter.ipv4_address().to_string().characters(),
adapter.ipv4_netmask().to_string().characters(),
adapter.ipv4_gateway().to_string().characters());
klog() << "NetworkTask: " << adapter.class_name() << " network adapter found: hw=" << adapter.mac_address().to_string().characters() << " address=" << adapter.ipv4_address().to_string().characters() << " netmask=" << adapter.ipv4_netmask().to_string().characters() << " gateway=" << adapter.ipv4_gateway().to_string().characters();
adapter.on_receive = [&]() {
pending_packets++;
@ -95,7 +90,7 @@ void NetworkTask_main()
packet_size = adapter.dequeue_packet(buffer, buffer_size);
pending_packets--;
#ifdef NETWORK_TASK_DEBUG
kprintf("NetworkTask: Dequeued packet from %s (%d bytes)\n", adapter.name().characters(), packet_size);
klog() << "NetworkTask: Dequeued packet from " << adapter.name().characters() << " (" << packet_size << " bytes)";
#endif
});
return packet_size;
@ -105,7 +100,7 @@ void NetworkTask_main()
auto buffer_region = MM.allocate_kernel_region(buffer_size, "Kernel Packet Buffer", Region::Access::Read | Region::Access::Write, false, true);
auto buffer = (u8*)buffer_region->vaddr().get();
kprintf("NetworkTask: Enter main loop.\n");
klog() << "NetworkTask: Enter main loop.";
for (;;) {
size_t packet_size = dequeue_packet(buffer, buffer_size);
if (!packet_size) {
@ -113,36 +108,32 @@ void NetworkTask_main()
continue;
}
if (packet_size < sizeof(EthernetFrameHeader)) {
kprintf("NetworkTask: Packet is too small to be an Ethernet packet! (%zu)\n", packet_size);
klog() << "NetworkTask: Packet is too small to be an Ethernet packet! (" << packet_size << ")";
continue;
}
auto& eth = *(const EthernetFrameHeader*)buffer;
#ifdef ETHERNET_DEBUG
kprintf("NetworkTask: From %s to %s, ether_type=%w, packet_length=%u\n",
eth.source().to_string().characters(),
eth.destination().to_string().characters(),
eth.ether_type(),
packet_size);
klog() << "NetworkTask: From " << eth.source().to_string().characters() << " to " << eth.destination().to_string().characters() << ", ether_type=" << String::format("%w", eth.ether_type()) << ", packet_length=" << packet_size;
#endif
#ifdef ETHERNET_VERY_DEBUG
for (size_t i = 0; i < packet_size; i++) {
kprintf("%b", buffer[i]);
klog() << String::format("%b", buffer[i]);
switch (i % 16) {
case 7:
kprintf(" ");
klog() << " ";
break;
case 15:
kprintf("\n");
klog() << "";
break;
default:
kprintf(" ");
klog() << " ";
break;
}
}
kprintf("\n");
klog() << "";
#endif
switch (eth.ether_type()) {
@ -156,7 +147,7 @@ void NetworkTask_main()
// ignore
break;
default:
kprintf("NetworkTask: Unknown ethernet type %#04x\n", eth.ether_type());
klog() << "NetworkTask: Unknown ethernet type 0x" << String::format("%x", eth.ether_type());
}
}
}
@ -165,30 +156,21 @@ void handle_arp(const EthernetFrameHeader& eth, size_t frame_size)
{
constexpr size_t minimum_arp_frame_size = sizeof(EthernetFrameHeader) + sizeof(ARPPacket);
if (frame_size < minimum_arp_frame_size) {
kprintf("handle_arp: Frame too small (%d, need %d)\n", frame_size, minimum_arp_frame_size);
klog() << "handle_arp: Frame too small (" << frame_size << ", need " << minimum_arp_frame_size << ")";
return;
}
auto& packet = *static_cast<const ARPPacket*>(eth.payload());
if (packet.hardware_type() != 1 || packet.hardware_address_length() != sizeof(MACAddress)) {
kprintf("handle_arp: Hardware type not ethernet (%w, len=%u)\n",
packet.hardware_type(),
packet.hardware_address_length());
klog() << "handle_arp: Hardware type not ethernet (" << String::format("%w", packet.hardware_type()) << ", len=" << packet.hardware_address_length() << ")";
return;
}
if (packet.protocol_type() != EtherType::IPv4 || packet.protocol_address_length() != sizeof(IPv4Address)) {
kprintf("handle_arp: Protocol type not IPv4 (%w, len=%u)\n",
packet.hardware_type(),
packet.protocol_address_length());
klog() << "handle_arp: Protocol type not IPv4 (" << String::format("%w", packet.hardware_type()) << ", len=" << packet.protocol_address_length() << ")";
return;
}
#ifdef ARP_DEBUG
kprintf("handle_arp: operation=%w, sender=%s/%s, target=%s/%s\n",
packet.operation(),
packet.sender_hardware_address().to_string().characters(),
packet.sender_protocol_address().to_string().characters(),
packet.target_hardware_address().to_string().characters(),
packet.target_protocol_address().to_string().characters());
klog() << "handle_arp: operation=" << String::format("%w", packet.operation()) << ", sender=" << packet.sender_hardware_address().to_string().characters() << "/" << packet.sender_protocol_address().to_string().characters() << ", target=" << packet.target_hardware_address().to_string().characters() << "/" << packet.target_protocol_address().to_string().characters();
#endif
if (!packet.sender_hardware_address().is_zero() && !packet.sender_protocol_address().is_zero()) {
@ -198,9 +180,9 @@ void handle_arp(const EthernetFrameHeader& eth, size_t frame_size)
LOCKER(arp_table().lock());
arp_table().resource().set(packet.sender_protocol_address(), packet.sender_hardware_address());
kprintf("ARP table (%d entries):\n", arp_table().resource().size());
klog() << "ARP table (" << arp_table().resource().size() << " entries):";
for (auto& it : arp_table().resource()) {
kprintf("%s :: %s\n", it.value.to_string().characters(), it.key.to_string().characters());
klog() << it.value.to_string().characters() << " :: " << it.key.to_string().characters();
}
}
@ -208,8 +190,7 @@ void handle_arp(const EthernetFrameHeader& eth, size_t frame_size)
// Who has this IP address?
if (auto adapter = NetworkAdapter::from_ipv4_address(packet.target_protocol_address())) {
// We do!
kprintf("handle_arp: Responding to ARP request for my IPv4 address (%s)\n",
adapter->ipv4_address().to_string().characters());
klog() << "handle_arp: Responding to ARP request for my IPv4 address (" << adapter->ipv4_address().to_string().characters() << ")";
ARPPacket response;
response.set_operation(ARPOperation::Response);
response.set_target_hardware_address(packet.sender_hardware_address());
@ -227,26 +208,24 @@ void handle_ipv4(const EthernetFrameHeader& eth, size_t frame_size)
{
constexpr size_t minimum_ipv4_frame_size = sizeof(EthernetFrameHeader) + sizeof(IPv4Packet);
if (frame_size < minimum_ipv4_frame_size) {
kprintf("handle_ipv4: Frame too small (%d, need %d)\n", frame_size, minimum_ipv4_frame_size);
klog() << "handle_ipv4: Frame too small (" << frame_size << ", need " << minimum_ipv4_frame_size << ")";
return;
}
auto& packet = *static_cast<const IPv4Packet*>(eth.payload());
if (packet.length() < sizeof(IPv4Packet)) {
kprintf("handle_ipv4: IPv4 packet too short (%u, need %u)\n", packet.length(), sizeof(IPv4Packet));
klog() << "handle_ipv4: IPv4 packet too short (" << packet.length() << ", need " << sizeof(IPv4Packet) << ")";
return;
}
size_t actual_ipv4_packet_length = frame_size - sizeof(EthernetFrameHeader);
if (packet.length() > actual_ipv4_packet_length) {
kprintf("handle_ipv4: IPv4 packet claims to be longer than it is (%u, actually %zu)\n", packet.length(), actual_ipv4_packet_length);
klog() << "handle_ipv4: IPv4 packet claims to be longer than it is (" << packet.length() << ", actually " << actual_ipv4_packet_length << ")";
return;
}
#ifdef IPV4_DEBUG
kprintf("handle_ipv4: source=%s, target=%s\n",
packet.source().to_string().characters(),
packet.destination().to_string().characters());
klog() << "handle_ipv4: source=" << packet.source().to_string().characters() << ", target=" << packet.destination().to_string().characters();
#endif
switch ((IPv4Protocol)packet.protocol()) {
@ -257,7 +236,7 @@ void handle_ipv4(const EthernetFrameHeader& eth, size_t frame_size)
case IPv4Protocol::TCP:
return handle_tcp(packet);
default:
kprintf("handle_ipv4: Unhandled protocol %u\n", packet.protocol());
klog() << "handle_ipv4: Unhandled protocol " << packet.protocol();
break;
}
}
@ -266,11 +245,7 @@ void handle_icmp(const EthernetFrameHeader& eth, const IPv4Packet& ipv4_packet)
{
auto& icmp_header = *static_cast<const ICMPHeader*>(ipv4_packet.payload());
#ifdef ICMP_DEBUG
kprintf("handle_icmp: source=%s, destination=%s, type=%b, code=%b\n",
ipv4_packet.source().to_string().characters(),
ipv4_packet.destination().to_string().characters(),
icmp_header.type(),
icmp_header.code());
klog() << "handle_icmp: source=" << ipv4_packet.source().to_string().characters() << ", destination=" << ipv4_packet.destination().to_string().characters() << ", type=" << String::format("%b", icmp_header.type()) << ", code=" << String::format("%b", icmp_header.code());
#endif
{
@ -289,10 +264,7 @@ void handle_icmp(const EthernetFrameHeader& eth, const IPv4Packet& ipv4_packet)
if (icmp_header.type() == ICMPType::EchoRequest) {
auto& request = reinterpret_cast<const ICMPEchoPacket&>(icmp_header);
kprintf("handle_icmp: EchoRequest from %s: id=%u, seq=%u\n",
ipv4_packet.source().to_string().characters(),
(u16)request.identifier,
(u16)request.sequence_number);
klog() << "handle_icmp: EchoRequest from " << ipv4_packet.source().to_string().characters() << ": id=" << (u16)request.identifier << ", seq=" << (u16)request.sequence_number;
size_t icmp_packet_size = ipv4_packet.payload_size();
auto buffer = ByteBuffer::create_zeroed(icmp_packet_size);
auto& response = *(ICMPEchoPacket*)buffer.data();
@ -311,29 +283,24 @@ void handle_icmp(const EthernetFrameHeader& eth, const IPv4Packet& ipv4_packet)
void handle_udp(const IPv4Packet& ipv4_packet)
{
if (ipv4_packet.payload_size() < sizeof(UDPPacket)) {
kprintf("handle_udp: Packet too small (%u, need %zu)\n", ipv4_packet.payload_size());
klog() << "handle_udp: Packet too small (" << ipv4_packet.payload_size() << ", need " << sizeof(UDPPacket) << ")";
return;
}
auto adapter = NetworkAdapter::from_ipv4_address(ipv4_packet.destination());
if (!adapter) {
kprintf("handle_udp: this packet is not for me, it's for %s\n", ipv4_packet.destination().to_string().characters());
klog() << "handle_udp: this packet is not for me, it's for " << ipv4_packet.destination().to_string().characters();
return;
}
auto& udp_packet = *static_cast<const UDPPacket*>(ipv4_packet.payload());
#ifdef UDP_DEBUG
kprintf("handle_udp: source=%s:%u, destination=%s:%u length=%u\n",
ipv4_packet.source().to_string().characters(),
udp_packet.source_port(),
ipv4_packet.destination().to_string().characters(),
udp_packet.destination_port(),
udp_packet.length());
klog() << "handle_udp: source=" << ipv4_packet.source().to_string().characters() << ":" << udp_packet.source_port() << ", destination=" << ipv4_packet.destination().to_string().characters() << ":" << udp_packet.destination_port() << " length=" << udp_packet.length();
#endif
auto socket = UDPSocket::from_port(udp_packet.destination_port());
if (!socket) {
kprintf("handle_udp: No UDP socket for port %u\n", udp_packet.destination_port());
klog() << "handle_udp: No UDP socket for port " << udp_packet.destination_port();
return;
}
@ -345,7 +312,7 @@ void handle_udp(const IPv4Packet& ipv4_packet)
void handle_tcp(const IPv4Packet& ipv4_packet)
{
if (ipv4_packet.payload_size() < sizeof(TCPPacket)) {
kprintf("handle_tcp: IPv4 payload is too small to be a TCP packet (%u, need %zu)\n", ipv4_packet.payload_size(), sizeof(TCPPacket));
klog() << "handle_tcp: IPv4 payload is too small to be a TCP packet (" << ipv4_packet.payload_size() << ", need " << sizeof(TCPPacket) << ")";
return;
}
@ -354,62 +321,36 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
size_t minimum_tcp_header_size = 5 * sizeof(u32);
size_t maximum_tcp_header_size = 15 * sizeof(u32);
if (tcp_packet.header_size() < minimum_tcp_header_size || tcp_packet.header_size() > maximum_tcp_header_size) {
kprintf("handle_tcp: TCP packet header has invalid size %zu\n", tcp_packet.header_size());
klog() << "handle_tcp: TCP packet header has invalid size " << tcp_packet.header_size();
}
if (ipv4_packet.payload_size() < tcp_packet.header_size()) {
kprintf("handle_tcp: IPv4 payload is smaller than TCP header claims (%u, supposedly %u)\n", ipv4_packet.payload_size(), tcp_packet.header_size());
klog() << "handle_tcp: IPv4 payload is smaller than TCP header claims (" << ipv4_packet.payload_size() << ", supposedly " << tcp_packet.header_size() << ")";
return;
}
size_t payload_size = ipv4_packet.payload_size() - tcp_packet.header_size();
#ifdef TCP_DEBUG
kprintf("handle_tcp: source=%s:%u, destination=%s:%u seq_no=%u, ack_no=%u, flags=%w (%s%s%s%s), window_size=%u, payload_size=%u\n",
ipv4_packet.source().to_string().characters(),
tcp_packet.source_port(),
ipv4_packet.destination().to_string().characters(),
tcp_packet.destination_port(),
tcp_packet.sequence_number(),
tcp_packet.ack_number(),
tcp_packet.flags(),
tcp_packet.has_syn() ? "SYN " : "",
tcp_packet.has_ack() ? "ACK " : "",
tcp_packet.has_fin() ? "FIN " : "",
tcp_packet.has_rst() ? "RST " : "",
tcp_packet.window_size(),
payload_size);
klog() << "handle_tcp: source=" << ipv4_packet.source().to_string().characters() << ":" << tcp_packet.source_port() << ", destination=" << ipv4_packet.destination().to_string().characters() << ":" << tcp_packet.destination_port() << " seq_no=" << tcp_packet.sequence_number() << ", ack_no=" << tcp_packet.ack_number() << ", flags=" << String::format("%w", tcp_packet.flags()) << " (" << (tcp_packet.has_syn() ? "SYN " : "") << (tcp_packet.has_ack() ? "ACK " : "") << (tcp_packet.has_fin() ? "FIN " : "") << (tcp_packet.has_rst() ? "RST " : "") << "), window_size=" << tcp_packet.window_size() << ", payload_size=" << payload_size;
#endif
auto adapter = NetworkAdapter::from_ipv4_address(ipv4_packet.destination());
if (!adapter) {
kprintf("handle_tcp: this packet is not for me, it's for %s\n", ipv4_packet.destination().to_string().characters());
klog() << "handle_tcp: this packet is not for me, it's for " << ipv4_packet.destination().to_string().characters();
return;
}
IPv4SocketTuple tuple(ipv4_packet.destination(), tcp_packet.destination_port(), ipv4_packet.source(), tcp_packet.source_port());
#ifdef TCP_DEBUG
kprintf("handle_tcp: looking for socket; tuple=%s\n", tuple.to_string().characters());
klog() << "handle_tcp: looking for socket; tuple=" << tuple.to_string().characters();
#endif
auto socket = TCPSocket::from_tuple(tuple);
if (!socket) {
kprintf("handle_tcp: No TCP socket for tuple %s\n", tuple.to_string().characters());
kprintf("handle_tcp: source=%s:%u, destination=%s:%u seq_no=%u, ack_no=%u, flags=%w (%s%s%s%s), window_size=%u, payload_size=%u\n",
ipv4_packet.source().to_string().characters(),
tcp_packet.source_port(),
ipv4_packet.destination().to_string().characters(),
tcp_packet.destination_port(),
tcp_packet.sequence_number(),
tcp_packet.ack_number(),
tcp_packet.flags(),
tcp_packet.has_syn() ? "SYN " : "",
tcp_packet.has_ack() ? "ACK " : "",
tcp_packet.has_fin() ? "FIN " : "",
tcp_packet.has_rst() ? "RST " : "",
tcp_packet.window_size(),
payload_size);
klog() << "handle_tcp: No TCP socket for tuple " << tuple.to_string().characters();
klog() << "handle_tcp: source=" << ipv4_packet.source().to_string().characters() << ":" << tcp_packet.source_port() << ", destination=" << ipv4_packet.destination().to_string().characters() << ":" << tcp_packet.destination_port() << " seq_no=" << tcp_packet.sequence_number() << ", ack_no=" << tcp_packet.ack_number() << ", flags=" << String::format("%w", tcp_packet.flags()) << " (" << (tcp_packet.has_syn() ? "SYN " : "") << (tcp_packet.has_ack() ? "ACK " : "") << (tcp_packet.has_fin() ? "FIN " : "") << (tcp_packet.has_rst() ? "RST " : "") << "), window_size=" << tcp_packet.window_size() << ", payload_size=" << payload_size;
return;
}
@ -417,18 +358,18 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
ASSERT(socket->local_port() == tcp_packet.destination_port());
#ifdef TCP_DEBUG
kprintf("handle_tcp: got socket; state=%s\n", socket->tuple().to_string().characters(), TCPSocket::to_string(socket->state()));
klog() << "handle_tcp: got socket; state=" << socket->tuple().to_string().characters() << " " << TCPSocket::to_string(socket->state());
#endif
socket->receive_tcp_packet(tcp_packet, ipv4_packet.payload_size());
switch (socket->state()) {
case TCPSocket::State::Closed:
kprintf("handle_tcp: unexpected flags in Closed state\n");
klog() << "handle_tcp: unexpected flags in Closed state";
// TODO: we may want to send an RST here, maybe as a configurable option
return;
case TCPSocket::State::TimeWait:
kprintf("handle_tcp: unexpected flags in TimeWait state\n");
klog() << "handle_tcp: unexpected flags in TimeWait state";
socket->send_tcp_packet(TCPFlags::RST);
socket->set_state(TCPSocket::State::Closed);
return;
@ -436,17 +377,17 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
switch (tcp_packet.flags()) {
case TCPFlags::SYN: {
#ifdef TCP_DEBUG
kprintf("handle_tcp: incoming connection\n");
klog() << "handle_tcp: incoming connection";
#endif
auto& local_address = ipv4_packet.destination();
auto& peer_address = ipv4_packet.source();
auto client = socket->create_client(local_address, tcp_packet.destination_port(), peer_address, tcp_packet.source_port());
if (!client) {
kprintf("handle_tcp: couldn't create client socket\n");
klog() << "handle_tcp: couldn't create client socket";
return;
}
#ifdef TCP_DEBUG
kprintf("handle_tcp: created new client socket with tuple %s\n", client->tuple().to_string().characters());
klog() << "handle_tcp: created new client socket with tuple " << client->tuple().to_string().characters();
#endif
client->set_sequence_number(1000);
client->set_ack_number(tcp_packet.sequence_number() + payload_size + 1);
@ -455,7 +396,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
return;
}
default:
kprintf("handle_tcp: unexpected flags in Listen state\n");
klog() << "handle_tcp: unexpected flags in Listen state";
// socket->send_tcp_packet(TCPFlags::RST);
return;
}
@ -488,7 +429,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
socket->set_setup_state(Socket::SetupState::Completed);
return;
default:
kprintf("handle_tcp: unexpected flags in SynSent state\n");
klog() << "handle_tcp: unexpected flags in SynSent state";
socket->send_tcp_packet(TCPFlags::RST);
socket->set_state(TCPSocket::State::Closed);
socket->set_error(TCPSocket::Error::UnexpectedFlagsDuringConnect);
@ -503,7 +444,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
switch (socket->direction()) {
case TCPSocket::Direction::Incoming:
if (!socket->has_originator()) {
kprintf("handle_tcp: connection doesn't have an originating socket; maybe it went away?\n");
klog() << "handle_tcp: connection doesn't have an originating socket; maybe it went away?";
socket->send_tcp_packet(TCPFlags::RST);
socket->set_state(TCPSocket::State::Closed);
return;
@ -519,7 +460,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
socket->set_connected(true);
return;
default:
kprintf("handle_tcp: got ACK in SynReceived state but direction is invalid (%s)\n", TCPSocket::to_string(socket->direction()));
klog() << "handle_tcp: got ACK in SynReceived state but direction is invalid (" << TCPSocket::to_string(socket->direction()) << ")";
socket->send_tcp_packet(TCPFlags::RST);
socket->set_state(TCPSocket::State::Closed);
return;
@ -527,7 +468,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
return;
default:
kprintf("handle_tcp: unexpected flags in SynReceived state\n");
klog() << "handle_tcp: unexpected flags in SynReceived state";
socket->send_tcp_packet(TCPFlags::RST);
socket->set_state(TCPSocket::State::Closed);
return;
@ -535,7 +476,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
case TCPSocket::State::CloseWait:
switch (tcp_packet.flags()) {
default:
kprintf("handle_tcp: unexpected flags in CloseWait state\n");
klog() << "handle_tcp: unexpected flags in CloseWait state";
socket->send_tcp_packet(TCPFlags::RST);
socket->set_state(TCPSocket::State::Closed);
return;
@ -547,7 +488,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
socket->set_state(TCPSocket::State::Closed);
return;
default:
kprintf("handle_tcp: unexpected flags in LastAck state\n");
klog() << "handle_tcp: unexpected flags in LastAck state";
socket->send_tcp_packet(TCPFlags::RST);
socket->set_state(TCPSocket::State::Closed);
return;
@ -563,7 +504,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
socket->set_state(TCPSocket::State::Closing);
return;
default:
kprintf("handle_tcp: unexpected flags in FinWait1 state\n");
klog() << "handle_tcp: unexpected flags in FinWait1 state";
socket->send_tcp_packet(TCPFlags::RST);
socket->set_state(TCPSocket::State::Closed);
return;
@ -578,7 +519,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
socket->set_state(TCPSocket::State::Closed);
return;
default:
kprintf("handle_tcp: unexpected flags in FinWait2 state\n");
klog() << "handle_tcp: unexpected flags in FinWait2 state";
socket->send_tcp_packet(TCPFlags::RST);
socket->set_state(TCPSocket::State::Closed);
return;
@ -590,7 +531,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
socket->set_state(TCPSocket::State::TimeWait);
return;
default:
kprintf("handle_tcp: unexpected flags in Closing state\n");
klog() << "handle_tcp: unexpected flags in Closing state";
socket->send_tcp_packet(TCPFlags::RST);
socket->set_state(TCPSocket::State::Closed);
return;
@ -610,12 +551,7 @@ void handle_tcp(const IPv4Packet& ipv4_packet)
socket->set_ack_number(tcp_packet.sequence_number() + payload_size);
#ifdef TCP_DEBUG
kprintf("Got packet with ack_no=%u, seq_no=%u, payload_size=%u, acking it with new ack_no=%u, seq_no=%u\n",
tcp_packet.ack_number(),
tcp_packet.sequence_number(),
payload_size,
socket->ack_number(),
socket->sequence_number());
klog() << "Got packet with ack_no=" << tcp_packet.ack_number() << ", seq_no=" << tcp_packet.sequence_number() << ", payload_size=" << payload_size << ", acking it with new ack_no=" << socket->ack_number() << ", seq_no=" << socket->sequence_number();
#endif
if (payload_size) {

View file

@ -76,8 +76,7 @@ RoutingDecision route_to(const IPv4Address& target, const IPv4Address& source)
if (!local_adapter && !gateway_adapter) {
#ifdef ROUTING_DEBUG
kprintf("Routing: Couldn't find a suitable adapter for route to %s\n",
target.to_string().characters());
klog() << "Routing: Couldn't find a suitable adapter for route to " << target.to_string().characters();
#endif
return { nullptr, {} };
}
@ -87,22 +86,13 @@ RoutingDecision route_to(const IPv4Address& target, const IPv4Address& source)
if (local_adapter) {
#ifdef ROUTING_DEBUG
kprintf("Routing: Got adapter for route (direct): %s (%s/%s) for %s\n",
local_adapter->name().characters(),
local_adapter->ipv4_address().to_string().characters(),
local_adapter->ipv4_netmask().to_string().characters(),
target.to_string().characters());
klog() << "Routing: Got adapter for route (direct): " << local_adapter->name().characters() << " (" << local_adapter->ipv4_address().to_string().characters() << "/" << local_adapter->ipv4_netmask().to_string().characters() << ") for " << target.to_string().characters();
#endif
adapter = local_adapter;
next_hop_ip = target;
} else if (gateway_adapter) {
#ifdef ROUTING_DEBUG
kprintf("Routing: Got adapter for route (using gateway %s): %s (%s/%s) for %s\n",
gateway_adapter->ipv4_gateway().to_string().characters(),
gateway_adapter->name().characters(),
gateway_adapter->ipv4_address().to_string().characters(),
gateway_adapter->ipv4_netmask().to_string().characters(),
target.to_string().characters());
klog() << "Routing: Got adapter for route (using gateway " << gateway_adapter->ipv4_gateway().to_string().characters() << "): " << gateway_adapter->name().characters() << " (" << gateway_adapter->ipv4_address().to_string().characters() << "/" << gateway_adapter->ipv4_netmask().to_string().characters() << ") for " << target.to_string().characters();
#endif
adapter = gateway_adapter;
next_hop_ip = gateway_adapter->ipv4_gateway();
@ -115,18 +105,14 @@ RoutingDecision route_to(const IPv4Address& target, const IPv4Address& source)
auto addr = arp_table().resource().get(next_hop_ip);
if (addr.has_value()) {
#ifdef ROUTING_DEBUG
kprintf("Routing: Using cached ARP entry for %s (%s)\n",
next_hop_ip.to_string().characters(),
addr.value().to_string().characters());
klog() << "Routing: Using cached ARP entry for " << next_hop_ip.to_string().characters() << " (" << addr.value().to_string().characters() << ")";
#endif
return { adapter, addr.value() };
}
}
#ifdef ROUTING_DEBUG
kprintf("Routing: Sending ARP request via adapter %s for IPv4 address %s\n",
adapter->name().characters(),
next_hop_ip.to_string().characters());
klog() << "Routing: Sending ARP request via adapter " << adapter->name().characters() << " for IPv4 address " << next_hop_ip.to_string().characters();
#endif
ARPPacket request;
@ -146,19 +132,14 @@ RoutingDecision route_to(const IPv4Address& target, const IPv4Address& source)
auto addr = arp_table().resource().get(next_hop_ip);
if (addr.has_value()) {
#ifdef ROUTING_DEBUG
kprintf("Routing: Got ARP response using adapter %s for %s (%s)\n",
adapter->name().characters(),
next_hop_ip.to_string().characters(),
addr.value().to_string().characters());
klog() << "Routing: Got ARP response using adapter " << adapter->name().characters() << " for " << next_hop_ip.to_string().characters() << " (" << addr.value().to_string().characters() << ")";
#endif
return { adapter, addr.value() };
}
}
#ifdef ROUTING_DEBUG
kprintf("Routing: Couldn't find route using adapter %s for %s\n",
adapter->name().characters(),
target.to_string().characters());
klog() << "Routing: Couldn't find route using adapter " << adapter->name().characters() << " for " << target.to_string().characters();
#endif
return { nullptr, {} };

View file

@ -65,7 +65,7 @@ Socket::~Socket()
void Socket::set_setup_state(SetupState new_setup_state)
{
#ifdef SOCKET_DEBUG
kprintf("%s(%u) Socket{%p} setup state moving from %s to %s\n", Process::current->name().characters(), Process::current->pid(), this, to_string(m_setup_state), to_string(new_setup_state));
dbg() << "Socket{" << this << "} setup state moving from " << to_string(m_setup_state) << " to " << to_string(new_setup_state);
#endif
m_setup_state = new_setup_state;
@ -77,7 +77,7 @@ RefPtr<Socket> Socket::accept()
if (m_pending.is_empty())
return nullptr;
#ifdef SOCKET_DEBUG
kprintf("%s(%u) Socket{%p} de-queueing connection\n", Process::current->name().characters(), Process::current->pid(), this);
dbg() << "Socket{" << this << "} de-queueing connection";
#endif
auto client = m_pending.take_first();
ASSERT(!client->is_connected());
@ -91,7 +91,7 @@ RefPtr<Socket> Socket::accept()
KResult Socket::queue_connection_from(NonnullRefPtr<Socket> peer)
{
#ifdef SOCKET_DEBUG
kprintf("%s(%u) Socket{%p} queueing connection\n", Process::current->name().characters(), Process::current->pid(), this);
dbg() << "Socket{" << this << "} queueing connection";
#endif
LOCKER(m_lock);
if (m_pending.size() >= m_backlog)

View file

@ -48,9 +48,7 @@ void TCPSocket::for_each(Function<void(TCPSocket&)> callback)
void TCPSocket::set_state(State new_state)
{
#ifdef TCP_SOCKET_DEBUG
kprintf("%s(%u) TCPSocket{%p} state moving from %s to %s\n",
Process::current->name().characters(), Process::current->pid(), this,
to_string(m_state), to_string(new_state));
dbg() << "TCPSocket{" << this << "} state moving from " << to_string(m_state) << " to " << to_string(new_state);
#endif
m_state = new_state;
@ -170,7 +168,7 @@ int TCPSocket::protocol_receive(const KBuffer& packet_buffer, void* buffer, size
auto& tcp_packet = *static_cast<const TCPPacket*>(ipv4_packet.payload());
size_t payload_size = packet_buffer.size() - sizeof(IPv4Packet) - tcp_packet.header_size();
#ifdef TCP_SOCKET_DEBUG
kprintf("payload_size %u, will it fit in %u?\n", payload_size, buffer_size);
klog() << "payload_size " << payload_size << ", will it fit in " << buffer_size << "?";
#endif
ASSERT(buffer_size >= payload_size);
memcpy(buffer, tcp_packet.payload(), payload_size);
@ -243,18 +241,7 @@ void TCPSocket::send_outgoing_packets()
#ifdef TCP_SOCKET_DEBUG
auto& tcp_packet = *(TCPPacket*)(packet.buffer.data());
kprintf("sending tcp packet from %s:%u to %s:%u with (%s%s%s%s) seq_no=%u, ack_no=%u, tx_counter=%u\n",
local_address().to_string().characters(),
local_port(),
peer_address().to_string().characters(),
peer_port(),
tcp_packet.has_syn() ? "SYN " : "",
tcp_packet.has_ack() ? "ACK " : "",
tcp_packet.has_fin() ? "FIN " : "",
tcp_packet.has_rst() ? "RST " : "",
tcp_packet.sequence_number(),
tcp_packet.ack_number(),
packet.tx_counter);
klog() << "sending tcp packet from " << local_address().to_string().characters() << ":" << local_port() << " to " << peer_address().to_string().characters() << ":" << peer_port() << " with (" << (tcp_packet.has_syn() ? "SYN " : "") << (tcp_packet.has_ack() ? "ACK " : "") << (tcp_packet.has_fin() ? "FIN " : "") << (tcp_packet.has_rst() ? "RST " : "") << ") seq_no=" << tcp_packet.sequence_number() << ", ack_no=" << tcp_packet.ack_number() << ", tx_counter=" << packet.tx_counter;
#endif
routing_decision.adapter->send_ipv4(
routing_decision.next_hop, peer_address(), IPv4Protocol::TCP,

View file

@ -101,11 +101,7 @@ int UDPSocket::protocol_send(const void* data, size_t data_length)
udp_packet.set_destination_port(peer_port());
udp_packet.set_length(sizeof(UDPPacket) + data_length);
memcpy(udp_packet.payload(), data, data_length);
kprintf("sending as udp packet from %s:%u to %s:%u!\n",
routing_decision.adapter->ipv4_address().to_string().characters(),
local_port(),
peer_address().to_string().characters(),
peer_port());
klog() << "sending as udp packet from " << routing_decision.adapter->ipv4_address().to_string().characters() << ":" << local_port() << " to " << peer_address().to_string().characters() << ":" << peer_port() << "!";
routing_decision.adapter->send_ipv4(routing_decision.next_hop, peer_address(), IPv4Protocol::UDP, buffer.data(), buffer.size(), ttl());
return data_length;
}