从套接字读取逐行数据时的行为

编程语言 2026-07-10

我有一个外部天气传感器，它会定期输出按行格式的NMEA数据：

$WIMWV,357.0,R,5.2,M,A*1A\r\n$WIMWV,123.0,T,5.2,M,A*1A\r\n

数据结构恰好包含两个行（R和 T），并由换行符 \r\n 结束，按顺序发送。约半秒后，下一组两行再发送。我可以用例如Putty验证这一点。因此Putty的输出就像一个数据流，总是收到一组两行，之间有延迟：

$WIMWV,357.0,R,5.2,M,A*1A\r\n
$WIMWV,123.0,T,5.2,M,A*1A\r\n
//time delay ~0.5s
$WIMWV,357.0,R,5.2,M,A*1A\r\n
$WIMWV,123.0,T,5.2,M,A*1A\r\n
//time delay ~0.5s
and so on ...

看起来还可以！现在，我希望基于原生Java服务来消费这个数据流。从套接字读取的过程被放在一个线程中。下面是一个最小示例：

Main.java:

public class Main {
    public static void main(String[] args) throws InterruptedException {

        Receiver receiver = new Receiver(args[0], Integer.parseInt(args[1]));
        Thread t = new Thread(receiver);
        t.setDaemon(true);
        t.start();

        while(true) {
            //Do something else in main app ...
            Thread.sleep(1000);
        }
    }
}

Receiver.java:

package org.example;

import java.io.IOException;
import java.io.InputStream;
import java.io.InputStreamReader;
import java.net.Socket;
import java.time.Instant;
import java.time.temporal.ChronoUnit;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Receiver implements Runnable {

    private final Logger log = LoggerFactory.getLogger(Receiver.class);
    private Socket socket;
    private boolean running = true;

    private String hostname;
    private int port;

    public Receiver(String hostname, int port) {
        this.hostname = hostname;
        this.port = port;
    }

    private String getNanoTime() {
        return String.valueOf(Instant.now().truncatedTo(ChronoUnit.NANOS));
    };

    @Override
    public void run() {

        while (running) {
            try {
                log.info("Try to connect to {}:{}", hostname, port);
                socket = new Socket(hostname, port);
                socket.setTcpNoDelay(true);

                InputStreamReader isr = new InputStreamReader(socket.getInputStream());
                StringBuilder line = new StringBuilder();
                int ch;
                while ((ch = isr.read()) != -1) {
                    if (ch == '\n') {
                        log.info("Time: {}, Message: {}", getNanoTime(), line.toString());
                        // Do something with line.toString()
                        line = new StringBuilder();
                    } else if (ch != '\r') {  // CR ignorieren
                        line.append((char) ch);
                    }
                }

            } catch (Exception e) {
                log.error("Exception at ({},{}):", hostname, port, e);
            } finally {
                try {
                    if (socket != null) socket.close();
                } catch (IOException e) {
                    log.warn("Exception at:", e);
                }
            }

            //Time delay for reconnect
            try {
                Thread.sleep(10000);
            } catch (InterruptedException e) {
                log.error("InterruptedException at: {}", e.toString());
            }
        }
        log.warn("TCPLineReceiver stopped for {}:{}", hostname, port);
    }
}

现在，控制台/日志中的输出如下：

12:40:22.354 INFO o.e.R -- Time: 2026-04-17T12:40:22.354808600Z, Message: $WIMWV,171.8,R,0.3,M,A*2C
12:40:22.354 INFO o.e.R -- Time: 2026-04-17T12:40:22.354808600Z, Message: $WIMWV,175.1,T,0.7,M,A*23
12:40:22.354 INFO o.e.R -- Time: 2026-04-17T12:40:22.354808600Z, Message: $WIMWV,153.7,R,0.2,M,A*22
12:40:22.354 INFO o.e.R -- Time: 2026-04-17T12:40:22.354808600Z, Message: $WIMWV,172.3,T,0.8,M,A*29
12:40:23.359 INFO o.e.R -- Time: 2026-04-17T12:40:23.359554800Z, Message: $WIMWV,156.3,R,0.3,M,A*22
12:40:23.359 INFO o.e.R -- Time: 2026-04-17T12:40:23.359554800Z, Message: $WIMWV,172.3,T,0.9,M,A*28
12:40:23.359 INFO o.e.R -- Time: 2026-04-17T12:40:23.359554800Z, Message: $WIMWV,148.2,R,0.4,M,A*2B
12:40:23.359 INFO o.e.R -- Time: 2026-04-17T12:40:23.359554800Z, Message: $WIMWV,166.5,T,1.0,M,A*23
12:40:24.348 INFO o.e.R -- Time: 2026-04-17T12:40:24.348462800Z, Message: $WIMWV,143.4,R,0.5,M,A*27
12:40:24.348 INFO o.e.R -- Time: 2026-04-17T12:40:24.348462800Z, Message: $WIMWV,162.8,T,1.1,M,A*2B
12:40:24.348 INFO o.e.R -- Time: 2026-04-17T12:40:24.348462800Z, Message: $WIMWV,124.6,R,0.5,M,A*24
12:40:24.348 INFO o.e.R -- Time: 2026-04-17T12:40:24.348462800Z, Message: $WIMWV,155.4,T,1.0,M,A*22

这意味着，我始终在同一个纳秒时间戳下得到一组四行——甚至日志记录的时间戳也完全相同。其后果是，数据的一半的时间戳以某种方式被偏移了（相对于Putty的输出）。有人能解释这种行为吗？这与套接字的缓冲区有关吗？有没有需要设置的套接字选项？

目标是像Putty一样原样接收数据流，并包含时间延迟。我想用系统时间给句子打上时间戳，因为这类NMEA数据本身不包含时间戳；因此我需要时间延迟信息。

补充说明（Java版本与依赖）：

    <properties>
        <version.java>17</version.java>
        <maven.compiler.source>${version.java}</maven.compiler.source>
        <maven.compiler.target>${version.java}</maven.compiler.target>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <version.logback>1.5.32</version.logback>
        <version.slf4j>2.0.17</version.slf4j>
        <version.maven-compiler-plugin>3.15.0</version.maven-compiler-plugin>
        <version.maven-shade-plugin>3.6.2</version.maven-shade-plugin>
        <version.maven-jar-plugin>3.5.0</version.maven-jar-plugin>
    </properties>

我使用了Adopt OpenJDK 17.0.18和 Maven 3.9.14

解决方案

据我所知，让你惊讶的是getNanoTime() 会连续多次返回完全相同的时间戳。

不幸的是，这是可能的，而且非常典型，因为nano-time获取的粒度相当粗糙，而且还取决于操作系统和硬件。

在我的电脑上，System.nanoTime() 的执行时间（延迟）大约是26ns。

然而，确实会出现3-4次连续调用返回完全相同的结果。在某些操作系统（某些Windows版本）上，甚至更多次调用也会返回相同的结果。

示例：

int N = 1_000_000;
long[] arr = new long[N];

// warmup
for (int i = 0; i < N; i++) {
    arr[i] = System.nanoTime();
}
// fill the array
for (int i = 0; i < N; i++) {
    arr[i] = System.nanoTime();
}

// print last 10 measures
for (int i = N-10; i < N ; i++) {
    System.out.println("i="+i+", time="+arr[i]);
}

// output
i=999990, time=302580986026200
i=999991, time=302580986026200
i=999992, time=302580986026200
i=999993, time=302580986026200
i=999994, time=302580986026200
i=999995, time=302580986026300
i=999996, time=302580986026300
i=999997, time=302580986026300
i=999998, time=302580986026300
i=999999, time=302580986026400

可以看到，纳秒时间时钟在我的操作系统+硬件上的精度大约在100ns左右，因此平均每4 次连续调用会得到相同的nano时间。

如果你需要每一行都具有唯一时间戳，可以在System.nanoTime() 返回相同时间戳时创建一个计数器，并对其自增：

static int offset = 0;
static long lastNanoTime;

static long  getNanoTime() {
    long nano = System.nanoTime();
    if (nano != lastNanoTime) {
        lastNanoTime = nano;
        offset = 0;
        return nano;
    } else {
        offset++;
        return nano + offset;
    }
}

for (int i = 0; i < N; i++) {
    arr[i] = getNanoTime();
}

//output
i=999990, time=303170080528502
i=999991, time=303170080528503
i=999992, time=303170080528600
i=999993, time=303170080528601
i=999994, time=303170080528602
i=999995, time=303170080528603
i=999996, time=303170080528700
i=999997, time=303170080528701
i=999998, time=303170080528702
i=999999, time=303170080528703

当然，你必须记住，System.nanoTime() 返回的是从某个任意点起的纳秒数；这不是墙钟时间。

站内所有文章版权归属LeftHeroAI导航站，无授权禁止任何主体转载、抄袭、复制内容，亦不得私自架设镜像站点。一经侵权，本站将通过法律途径追责。