pubsub/pstest: message ordering fails

[larryanz]

Client

pstest

Environment

• go version go1.23.4 darwin/arm64

Code and Dependencies

Not any changes. But we can use this command to test the functionality without cached:

go test -timeout 30s -run ^TestSubscriptionMessageOrdering$ cloud.google.com/go/pubsub/pstest -count=1

Expected behavior

Message ordering test must pass.

Actual behavior

Message ordering unit test fails. Not always but sometimes.

Screenshots

Additional context

I printed the time of published messages and the received messages, and there's an issue with the time accuracy.
Publish Time of published messages are time.Time, but for received messages, It's protobuf *timestamppb.Timestamp

My Mac :: Documents/google-cloud-go/pubsub ‹main*› » go test -timeout 30s -run ^TestSubscriptionMessageOrdering$ cloud.google.com/go/pubsub/pstest -count=1
received_msg: m0 2025-02-18 14:53:41.862569 +0700 +07 m=+0.007351459 2025-02-18 14:53:41.862569000 0
....
received_msg: m18 2025-02-18 14:53:41.862595 +0700 +07 m=+0.007377293 2025-02-18 14:53:41.862595000 0
received_msg: m19 2025-02-18 14:53:41.862596 +0700 +07 m=+0.007378168 2025-02-18 14:53:41.862596000 0
received_msg: m20 2025-02-18 14:53:41.862596 +0700 +07 m=+0.007379126 2025-02-18 14:53:41.862596000 0
received_msg: m21 2025-02-18 14:53:41.862597 +0700 +07 m=+0.007380001 2025-02-18 14:53:41.862597000 0
received_msg: m22 2025-02-18 14:53:41.862598 +0700 +07 m=+0.007380918 2025-02-18 14:53:41.862598000 0
...
received_msg: m49 2025-02-18 14:53:41.862679 +0700 +07 m=+0.007461834 2025-02-18 14:53:41.862679000 0
msgs [ack_id:"m0"  message:{data:"hello"  message_id:"m0"  publish_time:{seconds:1739865221  nanos:862569000}  ordering_key:"ordering-key"}]
msgs [ack_id:"m1"  message:{data:"hello"  message_id:"m1"  publish_time:{seconds:1739865221  nanos:862570000}  ordering_key:"ordering-key"}]
msgs [ack_id:"m2"  message:{data:"hello"  message_id:"m2"  publish_time:{seconds:1739865221  nanos:862571000}  ordering_key:"ordering-key"}]
...
msgs [ack_id:"m18"  message:{data:"hello"  message_id:"m18"  publish_time:{seconds:1739865221  nanos:862595000}  ordering_key:"ordering-key"}]
msgs [ack_id:"m20"  message:{data:"hello"  message_id:"m20"  publish_time:{seconds:1739865221  nanos:862596000}  ordering_key:"ordering-key"}]
msgs [ack_id:"m19"  message:{data:"hello"  message_id:"m19"  publish_time:{seconds:1739865221  nanos:862596000}  ordering_key:"ordering-key"}]
msgs [ack_id:"m21"  message:{data:"hello"  message_id:"m21"  publish_time:{seconds:1739865221  nanos:862597000}  ordering_key:"ordering-key"}]
--- FAIL: TestSubscriptionMessageOrdering (0.02s)
    fake_test.go:1716: want m19, got m20
    fake_test.go:1716: want m20, got m19
FAIL
FAIL    cloud.google.com/go/pubsub/pstest       0.334s
FAIL