test_client.cpp: SetPath # /home/runner/.ya/build/build_root/4xc1/003f5b/r3tmp/tmpCShoZi/pdisk_1.dat
2025-11-05T13:42:19.547765Z node 1 :PQ_READ_PROXY DEBUG: Direct read cache: : Created
2025-11-05T13:42:19.555083Z node 1 :METADATA_PROVIDER ERROR: fline=accessor_snapshot_base.cpp:69;action=cannot detect path existence;path=//Root/.metadata/initialization/migrations;error=incorrect path status: LookupError;
2025-11-05T13:42:19.577498Z node 1 :CONFIGS_DISPATCHER ERROR: Notification cookie mismatch for subscription [1:7569236211284705917:2081] 1762350139499712 != 1762350139499715
2025-11-05T13:42:19.577715Z node 1 :IMPORT WARN: Table profiles were not loaded
TServer::EnableGrpc on GrpcPort 1706, node 1
2025-11-05T13:42:19.595751Z node 1 :NET_CLASSIFIER WARN: distributable config is empty, broken or outdated, will use file: /home/runner/.ya/build/build_root/4xc1/003f5b/r3tmp/yandexK2wdNk.tmp
2025-11-05T13:42:19.595765Z node 1 :NET_CLASSIFIER WARN: will try to initialize from file: /home/runner/.ya/build/build_root/4xc1/003f5b/r3tmp/yandexK2wdNk.tmp
2025-11-05T13:42:19.595842Z node 1 :NET_CLASSIFIER WARN: successfully initialized from file: /home/runner/.ya/build/build_root/4xc1/003f5b/r3tmp/yandexK2wdNk.tmp
2025-11-05T13:42:19.595869Z node 1 :NET_CLASSIFIER ERROR: got bad distributable configuration
2025-11-05T13:42:19.598434Z INFO: TTestServer started on Port 28345 GrpcPort 1706
TClient is connected to server localhost:28345
PQClient connected to localhost:1706
WaitRootIsUp 'Root'...
TClient::Ls request: Root
TClient::Ls response: Status: 1
StatusCode: SUCCESS
SchemeStatus: 0
PathDescription {
  Self {
    Name: "Root"
    PathId: 1
    SchemeshardId: 72057594046644480
    PathType: EPathTypeDir
    CreateFinished: true
    CreateTxId: 1
    CreateStep: 0
    ParentPathId: 1
    PathState: EPathStateNoChanges
    Owner: "root@builtin"
    ACL: ""
    EffectiveACL: ""
    PathVersion: 2
    PathSubType: EPathSubTypeEmpty
    Version {
      GeneralVersion: 2
      ACLVersion: 0
      EffectiveACLVersion: 0
      UserAttrsVersion: 1
      ChildrenVersion: 1
      SubDomainVersion: 0
      SecurityStateVersion: 0
    }
    ChildrenExist: false
  }
  Children {
    Name: ".sys"
    PathId: 18446744073709551615
    SchemeshardId: 72057594046644480
    PathType: EPathTypeDir
    CreateFinished: true
    CreateTxId: 0
    CreateStep: 0
    ParentPathId: 18446744073709551615
  }
  DomainDescription {
    SchemeShardId_Depricated: 72057594046644480
    PathId_Depricated: 1
    ProcessingParams {
      Version: 0
      Pl...
(TRUNCATED)
WaitRootIsUp 'Root' success.
waiting...
2025-11-05T13:42:19.641834Z node 1 :HIVE WARN: HIVE#72057594037968897 Node(1, (0,0,0,0)) VolatileState: Unknown -> Disconnected
2025-11-05T13:42:19.641874Z node 1 :HIVE WARN: HIVE#72057594037968897 Node(1, (0,0,0,0)) VolatileState: Disconnected -> Connecting
2025-11-05T13:42:19.642691Z node 1 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpAlterSubDomain, opId: 281474976715657:0, at schemeshard:  72057594046644480
2025-11-05T13:42:19.645235Z node 1 :FLAT_TX_SCHEMESHARD WARN: NotifyTxCompletion, unknown transaction, txId: 281474976715657, at schemeshard: 72057594046644480
2025-11-05T13:42:19.645523Z node 1 :HIVE WARN: HIVE#72057594037968897 Node(1, (0,0,0,0)) VolatileState: Connecting -> Connected
waiting...
2025-11-05T13:42:19.655708Z node 1 :FLAT_TX_SCHEMESHARD WARN: NotifyTxCompletion, unknown transaction, txId: 281474976715658, at schemeshard: 72057594046644480
2025-11-05T13:42:19.657217Z node 1 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976715659:0, at schemeshard:  72057594046644480
waiting...
waiting...
waiting...
2025-11-05T13:42:19.904374Z node 1 :KQP_COMPILE_ACTOR ERROR: Compilation failed, self: [1:7569236211284706688:2316], status: SCHEME_ERROR, issues: <main>: Error: Type annotation, code: 1030
    <main>:3:16: Error: At function: KiReadTable!
        <main>:3:16: Error: Cannot find table 'db.[/Root/PQ/Config/V2/Cluster]' because it does not exist or you do not have access permissions. Please check correctness of table path and user permissions., code: 2003
2025-11-05T13:42:19.904791Z node 1 :KQP_SESSION WARN: SessionId: ydb://session/3?node_id=1&id=OTQyYTk4MDktM2NmZTVlZmUtOWViMjVhNWEtYjA5NjZlMjM=, ActorId: [1:7569236211284706685:2314], ActorState: ExecuteState, TraceId: 01k9a422eq3x91wh27cz3gv7ac, ReplyQueryCompileError, status SCHEME_ERROR remove tx with tx_id: 
2025-11-05T13:42:19.905190Z node 1 :PERSQUEUE_CLUSTER_TRACKER ERROR: failed to list clusters: { Response { QueryIssues { message: "Type annotation" issue_code: 1030 severity: 1 issues { position { row: 3 column: 16 } message: "At function: KiReadTable!" end_position { row: 3 column: 16 } severity: 1 issues { position { row: 3 column: 16 } message: "Cannot find table \'db.[/Root/PQ/Config/V2/Cluster]\' because it does not exist or you do not have access permissions. Please check correctness of table path and user permissions." end_position { row: 3 column: 16 } issue_code: 2003 severity: 1 } } } TxMeta { } } YdbStatus: SCHEME_ERROR ConsumedRu: 1 }
2025-11-05T13:42:19.918334Z node 1 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976715662:0, at schemeshard:  72057594046644480
2025-11-05T13:42:19.941227Z node 1 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976715663:0, at schemeshard:  72057594046644480
2025-11-05T13:42:19.983268Z node 1 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976715664:0, at schemeshard:  72057594046644480
=== Init DC: UPSERT INTO `/Root/PQ/Config/V2/Cluster` (name, balancer, local, enabled, weight) VALUES ("dc1", "localhost", true, true, 1000), ("dc2", "dc2.logbroker.yandex.net", false, true, 1000);
=== CheckClustersList. Subcribe to ClusterTracker from [1:7569236215579674260:2565] 
2025-11-05T13:42:20.519402Z node 1 :TX_CONVEYOR ERROR: fline=service.h:53;problem=unexpected event for task executor;ev_type=NActors::TEvents::TEvWakeup;
=== CheckClustersList. Ok
2025-11-05T13:42:25.185066Z :Statistics INFO: TTopicSdkTestSetup started
2025-11-05T13:42:25.194224Z node 1 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:42:25.198701Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][] pipe [1:7569236237054511039:2730] connected; active server actors: 1
2025-11-05T13:42:25.198756Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] updating configuration. Deleted partitions []. Added partitions [0]
2025-11-05T13:42:25.199623Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:42:25.199659Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] BALANCER INIT DONE for test-topic: (0, 72075186224037892) 
2025-11-05T13:42:25.199747Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:42:25.199863Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:42:25.199976Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:42:25.200004Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] doesn't have tx info
2025-11-05T13:42:25.200007Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-11-05T13:42:25.200010Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] no config, start with empty partitions and default config
2025-11-05T13:42:25.200013Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:42:25.200018Z node 1 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:42:25.200028Z node 1 :PERSQUEUE INFO: [PQ: 72075186224037892] doesn't have tx writes info
2025-11-05T13:42:25.200040Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72057594046644480, NodeId 1, Generation 2
2025-11-05T13:42:25.200219Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72075186224037892, NodeId 1, Generation 1
2025-11-05T13:42:25.200237Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511073:2422], now have 1 active actors on pipe
2025-11-05T13:42:25.247772Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511038:2729], now have 1 active actors on pipe
2025-11-05T13:42:25.251181Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236211284706360 RawX2: 4294969499 } TxId: 281474976715671 Config { TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 } } }
2025-11-05T13:42:25.251247Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] Propose TxId 281474976715671, WriteId (empty maybe)
2025-11-05T13:42:25.251258Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state UNKNOWN
2025-11-05T13:42:25.251262Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State UNKNOWN
2025-11-05T13:42:25.251266Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] schedule TEvProposeTransactionResult(PREPARED)
2025-11-05T13:42:25.251271Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from UNKNOWN to PREPARING
2025-11-05T13:42:25.251280Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:25.251336Z node 1 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PREPARED MinStep: 1762350145234 MaxStep: 18446744073709551615 Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236211284706360 RawX2: 4294969499 } Partitions { }
2025-11-05T13:42:25.251365Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:25.255980Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:25.256017Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARING
2025-11-05T13:42:25.256020Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARING
2025-11-05T13:42:25.256025Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARING to PREPARED
2025-11-05T13:42:25.257161Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037892 TxId: 281474976715671
2025-11-05T13:42:25.257191Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511090:2758], now have 1 active actors on pipe
2025-11-05T13:42:25.258083Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976715671 AckTo { RawX1: 0 RawX2: 0 } } Step: 1762350145304 MediatorID: 72057594046382081 TabletID: 72075186224037892
2025-11-05T13:42:25.258109Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARED
2025-11-05T13:42:25.258111Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARED
2025-11-05T13:42:25.258115Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARED to PLANNING
2025-11-05T13:42:25.258121Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] PlanStep 1762350145304, PlanTxId 281474976715671
2025-11-05T13:42:25.258127Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:25.258227Z node 1 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PLANNED MinStep: 1762350145234 MaxStep: 18446744073709551615 Step: 1762350145304 Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236211284706360 RawX2: 4294969499 } Partitions { }
2025-11-05T13:42:25.258260Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:25.261879Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:25.261899Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PLANNING
2025-11-05T13:42:25.261902Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PLANNING
2025-11-05T13:42:25.261907Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNING to PLANNED
2025-11-05T13:42:25.261921Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxQueue.size 1
2025-11-05T13:42:25.261926Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] New ExecStep 1762350145304, ExecTxId 281474976715671
2025-11-05T13:42:25.262092Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNED to CALCULATING
2025-11-05T13:42:25.262123Z node 1 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:42:25.262138Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-11-05T13:42:25.262194Z node 1 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:42:25.262307Z node 1 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] bootstrapping 0 [1:7569236237054511098:2426]
2025-11-05T13:42:25.264957Z node 1 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Initializing completed.
2025-11-05T13:42:25.264974Z node 1 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] init complete for topic 'test-topic' partition 0 generation 1 [1:7569236237054511098:2426]
2025-11-05T13:42:25.264993Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateInit] SYNC INIT topic test-topic partitition 0 so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:42:25.265144Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-11-05T13:42:25.265150Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.265183Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.265188Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:42:25.265189Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.265191Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.265193Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:42:25.265201Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 user test-consumer readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:42:25.265255Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPQ::TEvProposePartitionConfigResult Step 1762350145304, TxId 281474976715671, Partition 0
2025-11-05T13:42:25.265259Z node 1 :PQ_TX DEBUG: [TxId: 281474976715671] Handle TEvProposePartitionConfigResult
2025-11-05T13:42:25.265262Z node 1 :PQ_TX DEBUG: [TxId: 281474976715671] Partition responses 1/1
2025-11-05T13:42:25.265265Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATING
2025-11-05T13:42:25.265266Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATING
2025-11-05T13:42:25.265271Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATING FrontTxId 281474976715671
2025-11-05T13:42:25.265275Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:42:25.265279Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATING to CALCULATED
2025-11-05T13:42:25.265283Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:25.265407Z node 1 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: CALCULATED MinStep: 1762350145234 MaxStep: 18446744073709551615 Step: 1762350145304 Predicate: true Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236211284706360 RawX2: 4294969499 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:42:25.265462Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:25.267062Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:25.267074Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATED
2025-11-05T13:42:25.267077Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATED
2025-11-05T13:42:25.267080Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATED FrontTxId 281474976715671
2025-11-05T13:42:25.267083Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATED to WAIT_RS
2025-11-05T13:42:25.267097Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-11-05T13:42:25.267101Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveParticipantsDecision 1
2025-11-05T13:42:25.267115Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS to EXECUTING
2025-11-05T13:42:25.267118Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 0, Expected 1
2025-11-05T13:42:25.267145Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1762350145304, TxId 281474976715671
2025-11-05T13:42:25.267154Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.267156Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.267194Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.267239Z node 1 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:25.270625Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:42:25.270885Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:42:25.270893Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:1706
2025-11-05T13:42:25.267560Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] Handle TEvPQ::TEvTxCommitDone Step 1762350145304, TxId 281474976715671, Partition 0
2025-11-05T13:42:25.267564Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:25.267569Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.267571Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.267573Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTING
2025-11-05T13:42:25.267575Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTING
2025-11-05T13:42:25.267577Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTING FrontTxId 281474976715671
2025-11-05T13:42:25.267581Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:42:25.267587Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId: 281474976715671 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-11-05T13:42:25.267595Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] complete TxId 281474976715671
2025-11-05T13:42:25.267672Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Apply new config PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 }
2025-11-05T13:42:25.267693Z node 1 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:42:25.267703Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] delete partitions for TxId 281474976715671
2025-11-05T13:42:25.267705Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTING to EXECUTED
2025-11-05T13:42:25.267710Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:25.267789Z node 1 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: EXECUTED MinStep: 1762350145234 MaxStep: 18446744073709551615 Step: 1762350145304 Predicate: true Kind: KIND_CONFIG TabletConfig { PartitionConfig { MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 } PartitionIds: 0 TopicName: "test-topic" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic" YcCloudId: "" YcFolderId: "" YdbDatabaseId: "" YdbDatabasePath: "/Root" Partitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } ReadRuleGenerations: 0 AllPartitions { PartitionId: 0 Status: Active CreateVersion: 1 TabletId: 0 } Consumers { Name: "test-consumer" ReadFromTimestampsMs: 0 FormatVersion: 0 Codec { } ServiceType: "data-streams" Version: 0 Generation: 0 } } BootstrapConfig { } SourceActor { RawX1: 7569236211284706360 RawX2: 4294969499 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:42:25.267851Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:25.269127Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:25.269134Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTED
2025-11-05T13:42:25.269136Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTED
2025-11-05T13:42:25.269142Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTED FrontTxId 281474976715671
2025-11-05T13:42:25.269146Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TPersQueue::SendEvReadSetAckToSenders
2025-11-05T13:42:25.269148Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTED to WAIT_RS_ACKS
2025-11-05T13:42:25.269151Z node 1 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:42:25.269153Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-11-05T13:42:25.269154Z node 1 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:42:25.269160Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] add an TxId 281474976715671 to the list for deletion
2025-11-05T13:42:25.269168Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS_ACKS to DELETING
2025-11-05T13:42:25.269176Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] delete key for TxId 281474976715671
2025-11-05T13:42:25.269191Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:25.269480Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:42:25.269603Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:42:25.269637Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:25.269640Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state DELETING
2025-11-05T13:42:25.269641Z node 1 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State DELETING
2025-11-05T13:42:25.269644Z node 1 :PQ_TX INFO: [PQ: 72075186224037892] delete TxId 281474976715671
2025-11-05T13:42:25.273605Z node 1 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:25.273617Z node 1 :PQ_WRITE_PROXY DEBUG: new session created cookie 1
2025-11-05T13:42:25.274989Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "test-topic" message_group_id: "src" }
2025-11-05T13:42:25.275918Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 1 sessionId:  grpc read done: success: 1 data: init_request { topic: "test-topic" message_group_id: "src" }
2025-11-05T13:42:25.275981Z node 1 :PQ_WRITE_PROXY INFO: session request cookie: 1 topic: "test-topic" message_group_id: "src" from ipv6:[::1]:57350
2025-11-05T13:42:25.275995Z node 1 :PQ_WRITE_PROXY INFO: write session:  cookie=1 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:57350 proto=v1  topic=test-topic durationSec=0
2025-11-05T13:42:25.276000Z node 1 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:25.277015Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId:  describe result for acl check
2025-11-05T13:42:25.277061Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint64; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `//Root/.metadata/TopicPartitionsMapping` WHERE Hash == $Hash AND Topic == $Topic AND ProducerId == $SourceId;
2025-11-05T13:42:25.277066Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64; DECLARE $SeqNo AS Uint64;
UPSERT INTO `//Root/.metadata/TopicPartitionsMapping` (Hash, Topic, ProducerId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-11-05T13:42:25.277068Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `//Root/.metadata/TopicPartitionsMapping` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND ProducerId = $SourceId AND Partition = $Partition;
2025-11-05T13:42:25.277085Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [1:7569236237054511142:2434] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:25.277107Z node 1 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 1 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:42:25.277243Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511145:2434], now have 1 active actors on pipe
2025-11-05T13:42:25.277256Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.277262Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.277300Z node 1 :PERSQUEUE INFO: new Cookie src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0 generated for partition 0 topic 'test-topic' owner src
2025-11-05T13:42:25.277313Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.277321Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.277331Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.277346Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:25.277360Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 1, Generation: 1
2025-11-05T13:42:25.277369Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:25.277413Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.277417Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.277452Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:25.277477Z node 1 :PQ_WRITE_PROXY INFO: session inited cookie: 1 partition: 0 MaxSeqNo: 0 sessionId: src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0
2025-11-05T13:42:25.278275Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350145278 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:25.278303Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0" topic: "test-topic"
2025-11-05T13:42:25.278483Z :INFO: [/Root] MessageGroupId [src] SessionId [src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0] Write session: close. Timeout = 0 ms
2025-11-05T13:42:25.278489Z :INFO: [/Root] MessageGroupId [src] SessionId [src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0] Write session will now close
2025-11-05T13:42:25.278494Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0] Write session: aborting
2025-11-05T13:42:25.278622Z :INFO: [/Root] MessageGroupId [src] SessionId [src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:42:25.278640Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0] Write session: destroy
2025-11-05T13:42:25.279581Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 1 sessionId: src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0 grpc read done: success: 0 data: 
2025-11-05T13:42:25.279593Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0 grpc read failed
2025-11-05T13:42:25.279615Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0 grpc closed
2025-11-05T13:42:25.279619Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|e939a8c2-1158f1e3-61798f5a-14d1acf4_0 is DEAD
2025-11-05T13:42:25.279888Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:25.280091Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236237054511145:2434] destroyed
2025-11-05T13:42:25.280107Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:25.280114Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.280117Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.287423Z :Statistics INFO: Topic created
2025-11-05T13:42:25.292666Z node 1 :PQ_READ_PROXY ERROR: new Describe topic request
2025-11-05T13:42:25.292737Z node 1 :PQ_READ_PROXY DEBUG: Describe topic actor for path test-topic
2025-11-05T13:42:25.293205Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511162:2445] connected; active server actors: 1
2025-11-05T13:42:25.293229Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511161:2444], now have 1 active actors on pipe
2025-11-05T13:42:25.293323Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic PartitionStatus PartitionSize: 0 UsedReserveSize: 0 ReserveSize: 0 PartitionConfig{ MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 }
2025-11-05T13:42:25.295952Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236237054511161:2444] destroyed
2025-11-05T13:42:25.298085Z node 1 :PQ_READ_PROXY DEBUG: new Describe consumer request
2025-11-05T13:42:25.298480Z node 1 :PQ_READ_PROXY DEBUG: TDescribeConsumerActor for request operation_params {
}
path: "test-topic"
consumer: "test-consumer"
include_stats: true
2025-11-05T13:42:25.298753Z node 1 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [1:7569236237054511167:2447]: Request sessions
2025-11-05T13:42:25.298865Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511169:2448], now have 1 active actors on pipe
2025-11-05T13:42:25.298901Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511170:2449] connected; active server actors: 1
2025-11-05T13:42:25.298970Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic PartitionStatus PartitionSize: 0 UsedReserveSize: 0 ReserveSize: 0 PartitionConfig{ MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 }
2025-11-05T13:42:25.299150Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236237054511169:2448] destroyed
2025-11-05T13:42:25.299162Z node 1 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [1:7569236237054511167:2447]: Got sessions
2025-11-05T13:42:25.300065Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511170:2449] disconnected; active server actors: 1
2025-11-05T13:42:25.300078Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511170:2449] disconnected no session
2025-11-05T13:42:25.300134Z node 1 :PQ_READ_PROXY DEBUG: new Describe partition request
2025-11-05T13:42:25.300170Z node 1 :PQ_READ_PROXY DEBUG: TDescribePartitionActor for request operation_params {
}
path: "test-topic"
include_stats: true
2025-11-05T13:42:25.300184Z node 1 :PQ_READ_PROXY DEBUG: TDescribePartitionActor[1:7569236237054511175:2451]: Bootstrap
2025-11-05T13:42:25.300541Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511177:2452], now have 1 active actors on pipe
2025-11-05T13:42:25.300558Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511178:2453] connected; active server actors: 1
2025-11-05T13:42:25.300667Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic PartitionStatus PartitionSize: 0 UsedReserveSize: 0 ReserveSize: 0 PartitionConfig{ MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 }
2025-11-05T13:42:25.301161Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: try to update token
2025-11-05T13:42:25.301451Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Start write session. Will connect to nodeId: 0
2025-11-05T13:42:25.302773Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: write to message_group: test-message_group_id
2025-11-05T13:42:25.302797Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: send init request: init_request { path: "test-topic" message_group_id: "test-message_group_id" }
2025-11-05T13:42:25.302801Z :TRACE: [/Root] TRACE_EVENT InitRequest 
2025-11-05T13:42:25.302864Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:42:25.305491Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236237054511177:2452] destroyed
2025-11-05T13:42:25.305610Z node 1 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:25.305622Z node 1 :PQ_WRITE_PROXY DEBUG: new session created cookie 2
2025-11-05T13:42:25.305802Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId:  grpc read done: success: 1 data: init_request { path: "test-topic" message_group_id: "test-message_group_id" }
2025-11-05T13:42:25.305829Z node 1 :PQ_WRITE_PROXY INFO: session request cookie: 2 path: "test-topic" message_group_id: "test-message_group_id" from ipv6:[::1]:57350
2025-11-05T13:42:25.305833Z node 1 :PQ_WRITE_PROXY INFO: write session:  cookie=2 sessionId= userAgent="topic server" ip=ipv6:[::1]:57350 proto=topic  topic=test-topic durationSec=0
2025-11-05T13:42:25.305837Z node 1 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:25.306206Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId:  describe result for acl check
2025-11-05T13:42:25.306268Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint64; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `//Root/.metadata/TopicPartitionsMapping` WHERE Hash == $Hash AND Topic == $Topic AND ProducerId == $SourceId;
2025-11-05T13:42:25.306276Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64; DECLARE $SeqNo AS Uint64;
UPSERT INTO `//Root/.metadata/TopicPartitionsMapping` (Hash, Topic, ProducerId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-11-05T13:42:25.306277Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `//Root/.metadata/TopicPartitionsMapping` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND ProducerId = $SourceId AND Partition = $Partition;
2025-11-05T13:42:25.306290Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [1:7569236237054511185:2456] (SourceId=test-message_group_id, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:25.306295Z node 1 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 2 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:42:25.306616Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 1, Generation: 1
2025-11-05T13:42:25.306632Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511188:2456], now have 1 active actors on pipe
2025-11-05T13:42:25.306697Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.306705Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.306729Z node 1 :PERSQUEUE INFO: new Cookie test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0 generated for partition 0 topic 'test-topic' owner test-message_group_id
2025-11-05T13:42:25.306743Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.306751Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.306762Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.306776Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:25.306800Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:25.306884Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.306893Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.306907Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:25.306931Z node 1 :PQ_WRITE_PROXY INFO: session inited cookie: 2 partition: 0 MaxSeqNo: 0 sessionId: test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0
2025-11-05T13:42:25.307215Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:25.307233Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350145307 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:25.307248Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session established. Init response: session_id: "test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0"
2025-11-05T13:42:25.307254Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0
2025-11-05T13:42:25.307257Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  MessageGroupId [test-message_group_id] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:42:25.307312Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.000000s
2025-11-05T13:42:25.307323Z :TRACE: [/Root] TRACE_EVENT DescribePartitionRequest  path=/Root/test-topic partition_id=0
2025-11-05T13:42:25.307359Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-11-05T13:42:25.310011Z node 1 :PQ_READ_PROXY DEBUG: new Describe partition request
2025-11-05T13:42:25.310047Z node 1 :PQ_READ_PROXY DEBUG: TDescribePartitionActor for request path: "/Root/test-topic"
include_location: true
2025-11-05T13:42:25.310057Z node 1 :PQ_READ_PROXY DEBUG: TDescribePartitionActor[1:7569236237054511191:2458]: Bootstrap
2025-11-05T13:42:25.310223Z node 1 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [1:7569236237054511191:2458]: Request location
2025-11-05T13:42:25.310324Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511193:2459] connected; active server actors: 1
2025-11-05T13:42:25.310340Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] addPartitionToResponse tabletId 72075186224037892, partitionId 0, NodeId 1, Generation 1
2025-11-05T13:42:25.310345Z node 1 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [1:7569236237054511191:2458]: Got location
2025-11-05T13:42:25.310507Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511193:2459] disconnected; active server actors: 1
2025-11-05T13:42:25.310515Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511193:2459] disconnected no session
2025-11-05T13:42:25.310640Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 1
    generation: 1
  }
}
2025-11-05T13:42:25.310653Z :TRACE: [/Root] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=1 pl_generation=1
2025-11-05T13:42:25.310661Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 1 exists in the endpoint pool.
2025-11-05T13:42:25.310667Z :TRACE: [/Root] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=1 Generation=1
2025-11-05T13:42:25.310671Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  PartitionId [0]  Generation [1] Start write session. Will connect to nodeId: 1
2025-11-05T13:42:25.310898Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 1, Msg: CANCELLED, Details: , InternalError: 0
2025-11-05T13:42:25.310935Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId: test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0 grpc read done: success: 0 data: 
2025-11-05T13:42:25.310945Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0 grpc read failed
2025-11-05T13:42:25.310954Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0 grpc closed
2025-11-05T13:42:25.310959Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0 is DEAD
2025-11-05T13:42:25.311027Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  PartitionId [0]  Generation [1] Write session: direct write to partition: 0, generation 1
2025-11-05T13:42:25.311050Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  PartitionId [0]  Generation [1] Write session: send init request: init_request { path: "test-topic" partition_with_generation { generation: 1 } }
2025-11-05T13:42:25.311057Z :TRACE: [/Root] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=1
2025-11-05T13:42:25.311137Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  PartitionId [0]  Generation [1] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:42:25.311144Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:25.311182Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236237054511188:2456] destroyed
2025-11-05T13:42:25.311207Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:25.311216Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.311221Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.312065Z node 1 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:25.312076Z node 1 :PQ_WRITE_PROXY DEBUG: new session created cookie 3
2025-11-05T13:42:25.312159Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId:  grpc read done: success: 1 data: init_request { path: "test-topic" partition_with_generation { generation: 1 } }
2025-11-05T13:42:25.312192Z node 1 :PQ_WRITE_PROXY INFO: session request cookie: 3 path: "test-topic" partition_with_generation { generation: 1 } from ipv6:[::1]:57350
2025-11-05T13:42:25.312198Z node 1 :PQ_WRITE_PROXY DEBUG: session request cookie: 3. Disable deduplication for empty producer id
2025-11-05T13:42:25.312201Z node 1 :PQ_WRITE_PROXY INFO: write session:  cookie=3 sessionId= userAgent="topic server" ip=ipv6:[::1]:57350 proto=topic  topic=test-topic durationSec=0
2025-11-05T13:42:25.312204Z node 1 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:25.312209Z node 1 :PQ_WRITE_PROXY INFO: session to partition: 0, generation: 1
2025-11-05T13:42:25.312441Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId:  describe result for acl check
2025-11-05T13:42:25.312490Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint64; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `//Root/.metadata/TopicPartitionsMapping` WHERE Hash == $Hash AND Topic == $Topic AND ProducerId == $SourceId;
2025-11-05T13:42:25.312495Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64; DECLARE $SeqNo AS Uint64;
UPSERT INTO `//Root/.metadata/TopicPartitionsMapping` (Hash, Topic, ProducerId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-11-05T13:42:25.312497Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `//Root/.metadata/TopicPartitionsMapping` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND ProducerId = $SourceId AND Partition = $Partition;
2025-11-05T13:42:25.312504Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [1:7569236237054511198:2461] (SourceId=, PreferedPartition=0) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:25.312509Z node 1 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 3 sessionId:  partition: 0 expectedGeneration: 1
2025-11-05T13:42:25.312606Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 1, Generation: 1
2025-11-05T13:42:25.312620Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511201:2461], now have 1 active actors on pipe
2025-11-05T13:42:25.312626Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.312633Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.312653Z node 1 :PERSQUEUE INFO: new Cookie 3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0 generated for partition 0 topic 'test-topic' owner 3b8a9f0a-2010387d-52f4bc79-e1b83e0e
2025-11-05T13:42:25.312664Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.312667Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.312675Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.312683Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:25.312699Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:25.312801Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.312806Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.312817Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:25.312832Z node 1 :PQ_WRITE_PROXY INFO: session inited cookie: 3 partition: 0 MaxSeqNo: 0 sessionId: 3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0
2025-11-05T13:42:25.313055Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:25.313074Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|387cea57-a3e940c5-ae32a3-75af9ec6_0]  PartitionId [0]  Generation [1] Write session established. Init response: session_id: "3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0"
2025-11-05T13:42:25.313086Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0
2025-11-05T13:42:25.313091Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:42:25.364676Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.364694Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.374437Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 1 to 1
2025-11-05T13:42:25.411008Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:42:25.411027Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 1
2025-11-05T13:42:25.445660Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Estimated memory usage 33554432[B] reached maximum (20971520[B])
2025-11-05T13:42:25.445684Z :INFO: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session: close. Timeout 18446744073709.551615s
2025-11-05T13:42:25.465745Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.465759Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.501021Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: 3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:42:25.510361Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::NPQ::TEvPartitionWriter::TEvWriteRequest
2025-11-05T13:42:25.510423Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.510430Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.510473Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 1
2025-11-05T13:42:25.510498Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:25.510521Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.510526Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.510604Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 0 messageNo: 1 size: 511966
2025-11-05T13:42:25.510662Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 1 messageNo: 1 size: 511966
2025-11-05T13:42:25.510727Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 2 messageNo: 1 size: 511966
2025-11-05T13:42:25.510828Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 3 messageNo: 1 size: 511966
2025-11-05T13:42:25.510905Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 4 messageNo: 1 size: 511966
2025-11-05T13:42:25.510965Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 5 messageNo: 1 size: 511966
2025-11-05T13:42:25.511024Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 6 messageNo: 1 size: 511966
2025-11-05T13:42:25.511085Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 7 messageNo: 1 size: 511966
2025-11-05T13:42:25.511346Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 8 messageNo: 1 size: 511966
2025-11-05T13:42:25.511408Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 9 messageNo: 1 size: 511966
2025-11-05T13:42:25.511660Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 10 messageNo: 1 size: 511966
2025-11-05T13:42:25.511760Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 11 messageNo: 1 size: 511966
2025-11-05T13:42:25.511851Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 12 messageNo: 1 size: 511966
2025-11-05T13:42:25.511960Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 13 messageNo: 1 size: 511966
2025-11-05T13:42:25.512376Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 14 messageNo: 1 size: 511966
2025-11-05T13:42:25.512773Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 15 messageNo: 1 size: 511966
2025-11-05T13:42:25.513386Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 16 messageNo: 1 size: 511966
2025-11-05T13:42:25.513858Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 17 messageNo: 1 size: 511966
2025-11-05T13:42:25.514314Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 18 messageNo: 1 size: 511966
2025-11-05T13:42:25.514758Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 19 messageNo: 1 size: 511966
2025-11-05T13:42:25.515263Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 20 messageNo: 1 size: 511966
2025-11-05T13:42:25.515366Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 21 messageNo: 1 size: 511966
2025-11-05T13:42:25.515617Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 22 messageNo: 1 size: 511966
2025-11-05T13:42:25.516043Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 23 messageNo: 1 size: 511966
2025-11-05T13:42:25.516464Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 24 messageNo: 1 size: 511966
2025-11-05T13:42:25.516831Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 25 messageNo: 1 size: 511966
2025-11-05T13:42:25.517242Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 26 messageNo: 1 size: 511966
2025-11-05T13:42:25.517728Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 27 messageNo: 1 size: 511966
2025-11-05T13:42:25.518192Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 28 messageNo: 1 size: 511966
2025-11-05T13:42:25.518602Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 29 messageNo: 1 size: 511966
2025-11-05T13:42:25.518947Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 30 messageNo: 1 size: 511966
2025-11-05T13:42:25.519293Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 31 messageNo: 1 size: 511966
2025-11-05T13:42:25.519672Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 32 messageNo: 1 size: 511966
2025-11-05T13:42:25.520036Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 33 messageNo: 1 size: 511966
2025-11-05T13:42:25.520373Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 34 messageNo: 1 size: 511966
2025-11-05T13:42:25.520717Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 35 messageNo: 1 size: 511966
2025-11-05T13:42:25.521117Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 36 messageNo: 1 size: 511966
2025-11-05T13:42:25.521498Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 37 messageNo: 1 size: 511966
2025-11-05T13:42:25.521844Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 38 messageNo: 1 size: 511966
2025-11-05T13:42:25.522208Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 39 messageNo: 1 size: 511966
2025-11-05T13:42:25.522579Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 40 messageNo: 1 size: 511966
2025-11-05T13:42:25.522988Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 41 messageNo: 1 size: 511966
2025-11-05T13:42:25.523324Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 42 messageNo: 1 size: 511966
2025-11-05T13:42:25.523746Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 43 messageNo: 1 size: 511966
2025-11-05T13:42:25.524104Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 44 messageNo: 1 size: 511966
2025-11-05T13:42:25.524475Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 45 messageNo: 1 size: 511966
2025-11-05T13:42:25.524822Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 46 messageNo: 1 size: 511966
2025-11-05T13:42:25.525172Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 47 messageNo: 1 size: 511966
2025-11-05T13:42:25.525670Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 48 messageNo: 1 size: 511966
2025-11-05T13:42:25.526084Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 49 messageNo: 1 size: 511966
2025-11-05T13:42:25.526500Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 50 messageNo: 1 size: 511966
2025-11-05T13:42:25.526864Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 51 messageNo: 1 size: 511966
2025-11-05T13:42:25.527233Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 52 messageNo: 1 size: 511966
2025-11-05T13:42:25.527609Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 53 messageNo: 1 size: 511966
2025-11-05T13:42:25.528179Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 54 messageNo: 1 size: 511966
2025-11-05T13:42:25.529060Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 55 messageNo: 1 size: 511966
2025-11-05T13:42:25.529438Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 56 messageNo: 1 size: 511966
2025-11-05T13:42:25.529900Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 57 messageNo: 1 size: 511966
2025-11-05T13:42:25.530295Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 58 messageNo: 1 size: 511966
2025-11-05T13:42:25.530669Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 59 messageNo: 1 size: 511966
2025-11-05T13:42:25.531052Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 60 messageNo: 1 size: 511966
2025-11-05T13:42:25.531413Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 61 messageNo: 1 size: 511966
2025-11-05T13:42:25.531829Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 62 messageNo: 1 size: 511966
2025-11-05T13:42:25.532248Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 63 messageNo: 1 size: 511966
2025-11-05T13:42:25.532604Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 64 messageNo: 1 size: 511966
2025-11-05T13:42:25.532784Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client PART message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 65 messageNo: 1 size: 276716
2025-11-05T13:42:25.532791Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 65 messageNo: 1 size 276716 offset: -1
2025-11-05T13:42:25.532909Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.532930Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.532961Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 0
2025-11-05T13:42:25.532985Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 1
2025-11-05T13:42:25.532991Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 2
2025-11-05T13:42:25.532995Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 3
2025-11-05T13:42:25.533001Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 4
2025-11-05T13:42:25.533004Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 5
2025-11-05T13:42:25.533007Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 6
2025-11-05T13:42:25.533013Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 7
2025-11-05T13:42:25.533015Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 8
2025-11-05T13:42:25.533018Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 9
2025-11-05T13:42:25.533020Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 10
2025-11-05T13:42:25.533022Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 11
2025-11-05T13:42:25.533029Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 12
2025-11-05T13:42:25.533031Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 13
2025-11-05T13:42:25.533037Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 14
2025-11-05T13:42:25.533040Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 15
2025-11-05T13:42:25.533045Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 16
2025-11-05T13:42:25.535163Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob sourceId '' seqNo 1 partNo 16 result is x0000000000_00000000000000000000_00000_0000000000_00016 size 8191804
2025-11-05T13:42:25.535190Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 17
2025-11-05T13:42:25.535197Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 18
2025-11-05T13:42:25.535202Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 19
2025-11-05T13:42:25.535205Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 20
2025-11-05T13:42:25.535208Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 21
2025-11-05T13:42:25.535210Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 22
2025-11-05T13:42:25.535213Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 23
2025-11-05T13:42:25.535216Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 24
2025-11-05T13:42:25.535218Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 25
2025-11-05T13:42:25.535221Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 26
2025-11-05T13:42:25.535223Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 27
2025-11-05T13:42:25.535226Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 28
2025-11-05T13:42:25.535229Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 29
2025-11-05T13:42:25.535231Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 30
2025-11-05T13:42:25.535234Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 31
2025-11-05T13:42:25.535242Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 32
2025-11-05T13:42:25.537649Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob sourceId '' seqNo 1 partNo 32 result is x0000000000_00000000000000000000_00016_0000000000_00016 size 8191779
2025-11-05T13:42:25.537669Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 33
2025-11-05T13:42:25.537675Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 34
2025-11-05T13:42:25.537678Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 35
2025-11-05T13:42:25.537681Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 36
2025-11-05T13:42:25.537684Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 37
2025-11-05T13:42:25.537687Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 38
2025-11-05T13:42:25.537689Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 39
2025-11-05T13:42:25.537692Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 40
2025-11-05T13:42:25.537703Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 41
2025-11-05T13:42:25.537707Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 42
2025-11-05T13:42:25.537709Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 43
2025-11-05T13:42:25.537714Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 44
2025-11-05T13:42:25.537716Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 45
2025-11-05T13:42:25.537719Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 46
2025-11-05T13:42:25.537721Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 47
2025-11-05T13:42:25.537723Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 48
2025-11-05T13:42:25.539551Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob sourceId '' seqNo 1 partNo 48 result is x0000000000_00000000000000000000_00032_0000000000_00016 size 8191779
2025-11-05T13:42:25.539572Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 49
2025-11-05T13:42:25.539576Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 50
2025-11-05T13:42:25.539578Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 51
2025-11-05T13:42:25.539580Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 52
2025-11-05T13:42:25.539582Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 53
2025-11-05T13:42:25.539585Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 54
2025-11-05T13:42:25.539587Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 55
2025-11-05T13:42:25.539589Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 56
2025-11-05T13:42:25.539590Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 57
2025-11-05T13:42:25.539592Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 58
2025-11-05T13:42:25.539594Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 59
2025-11-05T13:42:25.539596Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 60
2025-11-05T13:42:25.539597Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 61
2025-11-05T13:42:25.539600Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 62
2025-11-05T13:42:25.539602Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 63
2025-11-05T13:42:25.539603Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 64
2025-11-05T13:42:25.546854Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob sourceId '' seqNo 1 partNo 64 result is x0000000000_00000000000000000000_00048_0000000000_00016 size 8191779
2025-11-05T13:42:25.546880Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 65
2025-11-05T13:42:25.546895Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] writing blob: topic 'test-topic' partition 0 old key x0000000000_00000000000000000000_00000_0000000000_00016 new key d0000000000_00000000000000000000_00000_0000000000_00016 size 8191804 WTime 1762350145546
2025-11-05T13:42:25.546901Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] writing blob: topic 'test-topic' partition 0 old key x0000000000_00000000000000000000_00016_0000000000_00016 new key d0000000000_00000000000000000000_00016_0000000000_00016 size 8191779 WTime 1762350145546
2025-11-05T13:42:25.546905Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] writing blob: topic 'test-topic' partition 0 old key x0000000000_00000000000000000000_00032_0000000000_00016 new key d0000000000_00000000000000000000_00032_0000000000_00016 size 8191779 WTime 1762350145546
2025-11-05T13:42:25.546909Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] writing blob: topic 'test-topic' partition 0 old key x0000000000_00000000000000000000_00048_0000000000_00016 new key d0000000000_00000000000000000000_00048_0000000000_00016 size 8191779 WTime 1762350145546
2025-11-05T13:42:25.547410Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob complete sourceId '' seqNo 1 partNo 65 FormedBlobsCount 4 NewHead: Offset 0 PartNo 64 PackedSize 788814 count 1 nextOffset 1 batches 2
2025-11-05T13:42:25.547432Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.547704Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Add new write blob: topic 'test-topic' partition 0 compactOffset 0,1 HeadOffset 0 endOffset 0 curOffset 1 d0000000000_00000000000000000000_00064_0000000001_00001| size 788804 WTime 1762350145547
2025-11-05T13:42:25.547839Z node 1 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:25.547848Z node 1 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 0 partNo 0 count 0 size 8191804
2025-11-05T13:42:25.547851Z node 1 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 0 partNo 16 count 0 size 8191779
2025-11-05T13:42:25.547854Z node 1 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 0 partNo 32 count 0 size 8191779
2025-11-05T13:42:25.547857Z node 1 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 0 partNo 48 count 0 size 8191779
2025-11-05T13:42:25.547861Z node 1 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 0 partNo 64 count 1 size 788804
2025-11-05T13:42:25.548222Z node 1 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 0 count 0 size 8191804 actorID [1:7569236237054511072:2425]
2025-11-05T13:42:25.548229Z node 1 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 0 count 0 size 8191779 actorID [1:7569236237054511072:2425]
2025-11-05T13:42:25.548230Z node 1 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 0 count 0 size 8191779 actorID [1:7569236237054511072:2425]
2025-11-05T13:42:25.548231Z node 1 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 0 count 0 size 8191779 actorID [1:7569236237054511072:2425]
2025-11-05T13:42:25.548234Z node 1 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 0 count 1 size 788804 actorID [1:7569236237054511072:2425]
2025-11-05T13:42:25.548263Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 33554506 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:25.548263Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037892' partition 0 offset 0 partno 0 count 0 parts 16 size 8191804
2025-11-05T13:42:25.548268Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037892' partition 0 offset 0 partno 16 count 0 parts 16 size 8191779
2025-11-05T13:42:25.548270Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037892' partition 0 offset 0 partno 32 count 0 parts 16 size 8191779
2025-11-05T13:42:25.548272Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548273Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037892' partition 0 offset 0 partno 48 count 0 parts 16 size 8191779
2025-11-05T13:42:25.548276Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Evicting blob. Tablet '72075186224037892' partition 0 offset 0 partno 0 count 0 parts 16 size 8191804
2025-11-05T13:42:25.548279Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037892' partition 0 offset 0 partno 64 count 1 parts 1 size 788804
2025-11-05T13:42:25.548279Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 0, Offset: 0 is stored on disk
2025-11-05T13:42:25.548286Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548289Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 1, Offset: 0 is stored on disk
2025-11-05T13:42:25.548291Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548293Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 2, Offset: 0 is stored on disk
2025-11-05T13:42:25.548295Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548298Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 3, Offset: 0 is stored on disk
2025-11-05T13:42:25.548300Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548302Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 4, Offset: 0 is stored on disk
2025-11-05T13:42:25.548304Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548308Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 5, Offset: 0 is stored on disk
2025-11-05T13:42:25.548310Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548313Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 6, Offset: 0 is stored on disk
2025-11-05T13:42:25.548315Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548318Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 7, Offset: 0 is stored on disk
2025-11-05T13:42:25.548321Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548324Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 8, Offset: 0 is stored on disk
2025-11-05T13:42:25.548326Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548329Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 9, Offset: 0 is stored on disk
2025-11-05T13:42:25.548331Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548336Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 10, Offset: 0 is stored on disk
2025-11-05T13:42:25.548339Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548349Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 11, Offset: 0 is stored on disk
2025-11-05T13:42:25.548352Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548355Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 12, Offset: 0 is stored on disk
2025-11-05T13:42:25.548358Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548362Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 13, Offset: 0 is stored on disk
2025-11-05T13:42:25.548366Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548368Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 14, Offset: 0 is stored on disk
2025-11-05T13:42:25.548371Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548373Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 15, Offset: 0 is stored on disk
2025-11-05T13:42:25.548374Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548377Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 16, Offset: 0 is stored on disk
2025-11-05T13:42:25.548379Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548385Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 17, Offset: 0 is stored on disk
2025-11-05T13:42:25.548386Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548387Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 18, Offset: 0 is stored on disk
2025-11-05T13:42:25.548388Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548390Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 19, Offset: 0 is stored on disk
2025-11-05T13:42:25.548391Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548392Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 20, Offset: 0 is stored on disk
2025-11-05T13:42:25.548394Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548395Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 21, Offset: 0 is stored on disk
2025-11-05T13:42:25.548396Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548398Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 22, Offset: 0 is stored on disk
2025-11-05T13:42:25.548400Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548403Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 23, Offset: 0 is stored on disk
2025-11-05T13:42:25.548404Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548406Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 24, Offset: 0 is stored on disk
2025-11-05T13:42:25.548408Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548409Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 25, Offset: 0 is stored on disk
2025-11-05T13:42:25.548410Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548412Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 26, Offset: 0 is stored on disk
2025-11-05T13:42:25.548414Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548415Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 27, Offset: 0 is stored on disk
2025-11-05T13:42:25.548416Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548417Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 28, Offset: 0 is stored on disk
2025-11-05T13:42:25.548420Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548422Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 29, Offset: 0 is stored on disk
2025-11-05T13:42:25.548423Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548425Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 30, Offset: 0 is stored on disk
2025-11-05T13:42:25.548426Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548428Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 31, Offset: 0 is stored on disk
2025-11-05T13:42:25.548429Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548430Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 32, Offset: 0 is stored on disk
2025-11-05T13:42:25.548432Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548433Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 33, Offset: 0 is stored on disk
2025-11-05T13:42:25.548434Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548436Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 34, Offset: 0 is stored on disk
2025-11-05T13:42:25.548437Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548439Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 35, Offset: 0 is stored on disk
2025-11-05T13:42:25.548440Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548441Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 36, Offset: 0 is stored on disk
2025-11-05T13:42:25.548442Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548444Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 37, Offset: 0 is stored on disk
2025-11-05T13:42:25.548445Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548446Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 38, Offset: 0 is stored on disk
2025-11-05T13:42:25.548447Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548449Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 39, Offset: 0 is stored on disk
2025-11-05T13:42:25.548450Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548451Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 40, Offset: 0 is stored on disk
2025-11-05T13:42:25.548453Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548455Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 41, Offset: 0 is stored on disk
2025-11-05T13:42:25.548456Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548463Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 42, Offset: 0 is stored on disk
2025-11-05T13:42:25.548465Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548466Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 43, Offset: 0 is stored on disk
2025-11-05T13:42:25.548467Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548469Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 44, Offset: 0 is stored on disk
2025-11-05T13:42:25.548470Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548472Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 45, Offset: 0 is stored on disk
2025-11-05T13:42:25.548474Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548475Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 46, Offset: 0 is stored on disk
2025-11-05T13:42:25.548477Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548479Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 47, Offset: 0 is stored on disk
2025-11-05T13:42:25.548480Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548481Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 48, Offset: 0 is stored on disk
2025-11-05T13:42:25.548483Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548484Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 49, Offset: 0 is stored on disk
2025-11-05T13:42:25.548485Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548487Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 50, Offset: 0 is stored on disk
2025-11-05T13:42:25.548488Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548489Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 51, Offset: 0 is stored on disk
2025-11-05T13:42:25.548490Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548492Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 52, Offset: 0 is stored on disk
2025-11-05T13:42:25.548493Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548495Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 53, Offset: 0 is stored on disk
2025-11-05T13:42:25.548496Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548497Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 54, Offset: 0 is stored on disk
2025-11-05T13:42:25.548498Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548500Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 55, Offset: 0 is stored on disk
2025-11-05T13:42:25.548500Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548502Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 56, Offset: 0 is stored on disk
2025-11-05T13:42:25.548503Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548504Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 57, Offset: 0 is stored on disk
2025-11-05T13:42:25.548505Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548507Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 58, Offset: 0 is stored on disk
2025-11-05T13:42:25.548508Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548509Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 59, Offset: 0 is stored on disk
2025-11-05T13:42:25.548510Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548511Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 60, Offset: 0 is stored on disk
2025-11-05T13:42:25.548513Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548516Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 61, Offset: 0 is stored on disk
2025-11-05T13:42:25.548518Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548519Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 62, Offset: 0 is stored on disk
2025-11-05T13:42:25.548521Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548527Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 63, Offset: 0 is stored on disk
2025-11-05T13:42:25.548528Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548530Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 64, Offset: 0 is stored on disk
2025-11-05T13:42:25.548533Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.548534Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 65, Offset: 0 is stored on disk
2025-11-05T13:42:25.548642Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 user test-consumer readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:42:25.548654Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 user test-consumer send read request for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 1 rrg 0
2025-11-05T13:42:25.548659Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.548660Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.548712Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 1  requestId: <none> cookie: 1
2025-11-05T13:42:25.548724Z node 1 :PERSQUEUE DEBUG: Erasing blob in L1. Partition 0 offset 0 size 8191804 cause it's been evicted from L2. Actual L1 size: 4
2025-11-05T13:42:25.548725Z node 1 :PERSQUEUE NOTICE: Have to remove new data from cache. Topic test-topic, tablet id72075186224037892, cookie 0
2025-11-05T13:42:25.548746Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:25.548891Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] read cookie 0 Topic 'test-topic' partition 0 user test-consumer offset 0 count 1 size 1024000 endOffset 1 max time lag 0ms effective offset 0
2025-11-05T13:42:25.548912Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] read cookie 0 added 4 blobs, size 32767141 count 0 last offset 0, current partition end offset: 1
2025-11-05T13:42:25.549013Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Reading cookie 0. Send blob request.
2025-11-05T13:42:25.549023Z node 1 :PERSQUEUE DEBUG: No blob in L1. Partition 0 offset 0 actorID [1:7569236237054511072:2425]
2025-11-05T13:42:25.549028Z node 1 :PERSQUEUE DEBUG: Got data from cache. Partition 0 offset 0 count 0 source 1 size 8191779 accessed 0 times before, last time 2025-11-05T13:42:25.000000Z
2025-11-05T13:42:25.549034Z node 1 :PERSQUEUE DEBUG: Got data from cache. Partition 0 offset 0 count 0 source 1 size 8191779 accessed 0 times before, last time 2025-11-05T13:42:25.000000Z
2025-11-05T13:42:25.549036Z node 1 :PERSQUEUE DEBUG: Got data from cache. Partition 0 offset 0 count 0 source 1 size 8191779 accessed 0 times before, last time 2025-11-05T13:42:25.000000Z
2025-11-05T13:42:25.549044Z node 1 :PERSQUEUE DEBUG: Reading cookie 0. Have to read 1 of 4 from KV
2025-11-05T13:42:25.549062Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Touched. Tablet '72075186224037892' partition 0 offset 0 partno 16 count 0 parts 16
2025-11-05T13:42:25.549069Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Touched. Tablet '72075186224037892' partition 0 offset 0 partno 32 count 0 parts 16
2025-11-05T13:42:25.549071Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Touched. Tablet '72075186224037892' partition 0 offset 0 partno 48 count 0 parts 16
2025-11-05T13:42:25.549073Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Missed blob. tabletId '72075186224037892' partition 0 offset 0
2025-11-05T13:42:25.549887Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:25.549958Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 1 written { } } write_statistics { persisting_time { nanos: 15000000 } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-11-05T13:42:25.549964Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] OnAck: seqNo=1, txId=?
2025-11-05T13:42:25.549968Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 1
2025-11-05T13:42:25.549972Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Estimated memory usage got back to normal 0[B]
2025-11-05T13:42:25.550120Z node 1 :PERSQUEUE DEBUG: Got results. 1 of 4 from KV. Status 1
2025-11-05T13:42:25.550129Z node 1 :PERSQUEUE DEBUG: Got results. result 0 from KV. Status 0
2025-11-05T13:42:25.550135Z node 1 :PERSQUEUE DEBUG: Prefetched blob in L1. Partition 0 offset 0 count 0 size 8191804 actorID [1:7569236237054511072:2425]
2025-11-05T13:42:25.550157Z node 1 :PERSQUEUE WARN: Cropped PQ response. Tablet: [1:7569236237054511098:2426]cookie 0 partition 0 size 32767141. Cropped 1 blobs of 4
2025-11-05T13:42:25.550163Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Evicting blob. Tablet '72075186224037892' partition 0 offset 0 partno 64 count 1 parts 1 size 788804
2025-11-05T13:42:25.550166Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037892' partition 0 offset 0 partno 0 count 0 parts 16 size 8191804
2025-11-05T13:42:25.550171Z node 1 :PERSQUEUE DEBUG: FormAnswer for 4 blobs
2025-11-05T13:42:25.550700Z node 1 :PERSQUEUE DEBUG: Erasing blob in L1. Partition 0 offset 0 size 788804 cause it's been evicted from L2. Actual L1 size: 4
2025-11-05T13:42:25.550709Z node 1 :PERSQUEUE NOTICE: Have to remove new data from cache. Topic test-topic, tablet id72075186224037892, cookie 0
2025-11-05T13:42:25.553175Z node 1 :PERSQUEUE DEBUG: FormAnswer processing batch offset 0 totakecount 0 count 0 size 8191780 from pos 0 cbcount 16
2025-11-05T13:42:25.555640Z node 1 :PERSQUEUE DEBUG: FormAnswer processing batch offset 0 totakecount 0 count 0 size 8191755 from pos 0 cbcount 16
2025-11-05T13:42:25.558240Z node 1 :PERSQUEUE DEBUG: FormAnswer processing batch offset 0 totakecount 0 count 0 size 8191755 from pos 0 cbcount 16
2025-11-05T13:42:25.558275Z node 1 :PERSQUEUE DEBUG: Not full answer here!
2025-11-05T13:42:25.558326Z node 1 :PERSQUEUE DEBUG: Topic 'test-topic' partition 0 user test-consumer readTimeStamp done, result 1762350145537 queuesize 0 startOffset 0
2025-11-05T13:42:25.569555Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.569582Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.649533Z :INFO: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session will now close
2025-11-05T13:42:25.649557Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session: aborting
2025-11-05T13:42:25.649754Z :INFO: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session: gracefully shut down, all writes complete
2025-11-05T13:42:25.653680Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 1, Msg: CANCELLED, Details: , InternalError: 0
2025-11-05T13:42:25.653711Z :TRACE: [/Root] TRACE_EVENT Error  status=CLIENT_CANCELLED
2025-11-05T13:42:25.653715Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session is aborting and will not restart
2025-11-05T13:42:25.656253Z :DEBUG: [/Root]  TraceId []  SessionId [3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0]  PartitionId [0]  Generation [1] Write session: destroy
2025-11-05T13:42:25.656440Z :INFO: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] Starting read session
2025-11-05T13:42:25.656446Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] Starting single session
2025-11-05T13:42:25.656481Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] In Reconnect, ReadSizeBudget = 52428800, ReadSizeServerDelta = 0
2025-11-05T13:42:25.656484Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] New values: ReadSizeBudget = 52428800, ReadSizeServerDelta = 0
2025-11-05T13:42:25.656488Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] Reconnecting session to cluster  in 0.000000s
2025-11-05T13:42:25.657503Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] Successfully connected. Initializing session
2025-11-05T13:42:25.657483Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: 3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0 grpc read done: success: 0 data: 
2025-11-05T13:42:25.657500Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: 3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0 grpc read failed
2025-11-05T13:42:25.657511Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: 3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0 grpc closed
2025-11-05T13:42:25.657515Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: 3b8a9f0a-2010387d-52f4bc79-e1b83e0e|173adbe9-2a66f153-289c47a5-b68139be_0 is DEAD
2025-11-05T13:42:25.657928Z node 1 :PQ_READ_PROXY DEBUG: new grpc connection
2025-11-05T13:42:25.657936Z node 1 :PQ_READ_PROXY DEBUG: new session created cookie 1
2025-11-05T13:42:25.661715Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:25.663250Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236237054511201:2461] destroyed
2025-11-05T13:42:25.663414Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer  session  grpc read done: success# 1, data# { init_request { topics_read_settings { path: "test-topic" } consumer: "test-consumer" } }
2025-11-05T13:42:25.663486Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 read init: from# ipv6:[::1]:57350, request# { init_request { topics_read_settings { path: "test-topic" } consumer: "test-consumer" } }
2025-11-05T13:42:25.663546Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:25.663553Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.663556Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.663573Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 auth for : test-consumer
2025-11-05T13:42:25.663770Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 Handle describe topics response
2025-11-05T13:42:25.663788Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 auth is DEAD
2025-11-05T13:42:25.663802Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 auth ok: topics# 1, initDone# 0
2025-11-05T13:42:25.664082Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 register session: topic# /Root/test-topic
2025-11-05T13:42:25.664642Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511219:2465] connected; active server actors: 1
2025-11-05T13:42:25.664699Z node 1 :PERSQUEUE_READ_BALANCER NOTICE: [72075186224037893][test-topic] consumer "test-consumer" register session for pipe [1:7569236237054511219:2465] session test-consumer_1_1_15965003278184400605_v1
2025-11-05T13:42:25.664707Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] consumer test-consumer register readable partition 0
2025-11-05T13:42:25.664716Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] consumer test-consumer family created family=1 (Status=Free, Partitions=[0])
2025-11-05T13:42:25.665525Z :INFO: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] Server session id: test-consumer_1_1_15965003278184400605_v1
2025-11-05T13:42:25.665549Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] In ContinueReadingDataImpl, ReadSizeBudget = 52428800, ReadSizeServerDelta = 0
2025-11-05T13:42:25.664721Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] consumer test-consumer register reading session ReadingSession "test-consumer_1_1_15965003278184400605_v1" (Sender=[1:7569236237054511215:2465], Pipe=[1:7569236237054511219:2465], Partitions=[], ActiveFamilyCount=0)
2025-11-05T13:42:25.664725Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] consumer test-consumer rebalancing was scheduled
2025-11-05T13:42:25.664735Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] consumer test-consumer balancing. Sessions=1, Families=1, UnradableFamilies=1 [1 (0), ], RequireBalancing=0 []
2025-11-05T13:42:25.664742Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] consumer test-consumer balancing family=1 (Status=Free, Partitions=[0]) for ReadingSession "test-consumer_1_1_15965003278184400605_v1" (Sender=[1:7569236237054511215:2465], Pipe=[1:7569236237054511219:2465], Partitions=[], ActiveFamilyCount=0)
2025-11-05T13:42:25.664752Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] consumer test-consumer family 1 status Active partitions [0] session "test-consumer_1_1_15965003278184400605_v1" sender [1:7569236237054511215:2465] lock partition 0 for ReadingSession "test-consumer_1_1_15965003278184400605_v1" (Sender=[1:7569236237054511215:2465], Pipe=[1:7569236237054511219:2465], Partitions=[], ActiveFamilyCount=1) generation 1 step 1
2025-11-05T13:42:25.664760Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] consumer test-consumer start rebalancing. familyCount=1, sessionCount=1, desiredFamilyCount=1, allowPlusOne=0
2025-11-05T13:42:25.664764Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] consumer test-consumer balancing duration: 0.000026s
2025-11-05T13:42:25.664873Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 assign: record# { Partition: 0 TabletId: 72075186224037892 Topic: "test-topic" Generation: 1 Step: 1 Session: "test-consumer_1_1_15965003278184400605_v1" ClientId: "test-consumer" PipeClient { RawX1: 7569236237054511219 RawX2: 4503603922340257 } Path: "/Root/test-topic" }
2025-11-05T13:42:25.664886Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 INITING TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1)
2025-11-05T13:42:25.665215Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1) pipe restart attempt 0 pipe creation result: OK TabletId: 72075186224037892 Generation: 1, pipe: [1:7569236237054511222:2468]
2025-11-05T13:42:25.665225Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511222:2468], now have 1 active actors on pipe
2025-11-05T13:42:25.665280Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.665285Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.665292Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Created session test-consumer_1_1_15965003278184400605_v1 on pipe: [1:7569236237054511222:2468]
2025-11-05T13:42:25.665305Z node 1 :PQ_READ_PROXY DEBUG: Direct read cache: registered server session: test-consumer_1_1_15965003278184400605_v1:1 with generation 1
2025-11-05T13:42:25.665320Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.665325Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.665656Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 52428800
2025-11-05T13:42:25.665341Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 user test-consumer session is set to 0 (startOffset 0) session test-consumer_1_1_15965003278184400605_v1
2025-11-05T13:42:25.665344Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.665372Z node 1 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:25.665744Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:25.665756Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.665758Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.665770Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 18446744073709551615
2025-11-05T13:42:25.665794Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 grpc read done: success# 1, data# { read_request { bytes_size: 52428800 } }
2025-11-05T13:42:25.665855Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 got read request: guid# 3b050944-b528af65-c8706a4f-7456ed05
2025-11-05T13:42:25.667065Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1) initDone 0 event { CmdGetClientOffsetResult { Offset: 0 EndOffset: 1 WriteTimestampMS: 1762350145537 CreateTimestampMS: 1762350045341 SizeLag: 33555970 WriteTimestampEstimateMS: 1762350145546 ClientHasAnyCommits: false } Cookie: 18446744073709551615 }
2025-11-05T13:42:25.667078Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 INIT DONE TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1) EndOffset 1 readOffset 0 committedOffset 0
2025-11-05T13:42:25.667098Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 sending to client partition status
2025-11-05T13:42:25.669731Z :INFO: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] Confirm partition stream create. Partition stream id: 1. Cluster: "-". Topic: "test-topic". Partition: 0. Read offset: (NULL)
2025-11-05T13:42:25.673284Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 grpc read done: success# 1, data# { start_partition_session_response { partition_session_id: 1 } }
2025-11-05T13:42:25.673382Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 got StartRead from client: partition# TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1), readOffset# 0, commitOffset# (empty maybe)
2025-11-05T13:42:25.673398Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.673401Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.673419Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 Start reading TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1) EndOffset 1 readOffset 0 committedOffset 0 clientCommitOffset (empty maybe) clientReadOffset 0
2025-11-05T13:42:25.673421Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1) ready for read with readOffset 0 endOffset 1
2025-11-05T13:42:25.673449Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 partition ready for read: partition# TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1), readOffset# 0, endOffset# 1, WTime# 1762350145537, sizeLag# 33555970
2025-11-05T13:42:25.673452Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1TEvPartitionReady. Aval parts: 1
2025-11-05T13:42:25.673460Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 performing read request: guid# 82efded3-cc149afa-55f685d4-7737aa7, from# TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1), count# 1, size# 40267164, partitionsAsked# 1, maxTimeLag# 0ms
2025-11-05T13:42:25.673476Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 READ FROM TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1)maxCount 1 maxSize 40267164 maxTimeLagMs 0 readTimestampMs 0 readOffset 0 EndOffset 1 ClientCommitOffset 0 committedOffset 0 Guid 82efded3-cc149afa-55f685d4-7737aa7
2025-11-05T13:42:25.673614Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.673623Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.673655Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] read cookie 1 Topic 'test-topic' partition 0 user test-consumer offset 0 count 1 size 26214400 endOffset 1 max time lag 0ms effective offset 0
2025-11-05T13:42:25.673693Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] read cookie 1 added 4 blobs, size 32767141 count 0 last offset 0, current partition end offset: 1
2025-11-05T13:42:25.673832Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Reading cookie 1. Send blob request.
2025-11-05T13:42:25.673854Z node 1 :PERSQUEUE DEBUG: Got data from cache. Partition 0 offset 0 count 0 source 0 size 8191804 accessed 0 times before, last time 2025-11-05T13:42:25.000000Z
2025-11-05T13:42:25.673857Z node 1 :PERSQUEUE DEBUG: Got data from cache. Partition 0 offset 0 count 0 source 1 size 8191779 accessed 1 times before, last time 2025-11-05T13:42:25.000000Z
2025-11-05T13:42:25.673860Z node 1 :PERSQUEUE DEBUG: Got data from cache. Partition 0 offset 0 count 0 source 1 size 8191779 accessed 1 times before, last time 2025-11-05T13:42:25.000000Z
2025-11-05T13:42:25.673862Z node 1 :PERSQUEUE DEBUG: Got data from cache. Partition 0 offset 0 count 0 source 1 size 8191779 accessed 1 times before, last time 2025-11-05T13:42:25.000000Z
2025-11-05T13:42:25.673872Z node 1 :PERSQUEUE DEBUG: Reading cookie 1. All 4 blobs are from cache.
2025-11-05T13:42:25.673892Z node 1 :PERSQUEUE WARN: Cropped PQ response. Tablet: [1:7569236237054511098:2426]cookie 1 partition 0 size 32767141. Cropped 1 blobs of 4
2025-11-05T13:42:25.673901Z node 1 :PERSQUEUE DEBUG: FormAnswer for 4 blobs
2025-11-05T13:42:25.676822Z node 1 :PERSQUEUE DEBUG: FormAnswer processing batch offset 0 totakecount 0 count 0 size 8191780 from pos 0 cbcount 16
2025-11-05T13:42:25.677655Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Touched. Tablet '72075186224037892' partition 0 offset 0 partno 0 count 0 parts 16
2025-11-05T13:42:25.677660Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Touched. Tablet '72075186224037892' partition 0 offset 0 partno 16 count 0 parts 16
2025-11-05T13:42:25.677663Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Touched. Tablet '72075186224037892' partition 0 offset 0 partno 32 count 0 parts 16
2025-11-05T13:42:25.677665Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Touched. Tablet '72075186224037892' partition 0 offset 0 partno 48 count 0 parts 16
2025-11-05T13:42:25.681411Z node 1 :PERSQUEUE DEBUG: FormAnswer processing batch offset 0 totakecount 0 count 0 size 8191755 from pos 0 cbcount 16
2025-11-05T13:42:25.684476Z node 1 :PERSQUEUE DEBUG: FormAnswer processing batch offset 0 totakecount 0 count 0 size 8191755 from pos 0 cbcount 16
2025-11-05T13:42:25.684519Z node 1 :PERSQUEUE DEBUG: Not full answer here!
2025-11-05T13:42:25.684617Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:25.711581Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: __TMP__REQUEST__MARKER__
2025-11-05T13:42:25.711600Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.711646Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] read cookie 2 Topic 'test-topic' partition 0 user test-consumer offset 0 count 1 size 26214400 endOffset 1 max time lag 0ms effective offset 0
2025-11-05T13:42:25.711669Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] read cookie 2 added 1 blobs, size 8191779 count 0 last offset 0, current partition end offset: 1
2025-11-05T13:42:25.711806Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Reading cookie 2. Send blob request.
2025-11-05T13:42:25.711824Z node 1 :PERSQUEUE DEBUG: Got data from cache. Partition 0 offset 0 count 0 source 1 size 8191779 accessed 2 times before, last time 2025-11-05T13:42:25.000000Z
2025-11-05T13:42:25.711840Z node 1 :PERSQUEUE DEBUG: Reading cookie 2. All 1 blobs are from cache.
2025-11-05T13:42:25.711858Z node 1 :PERSQUEUE DEBUG: FormAnswer for 1 blobs
2025-11-05T13:42:25.713587Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Touched. Tablet '72075186224037892' partition 0 offset 0 partno 48 count 0 parts 16
2025-11-05T13:42:25.715430Z node 1 :PERSQUEUE DEBUG: FormAnswer processing batch offset 0 totakecount 0 count 0 size 8191755 from pos 0 cbcount 16
2025-11-05T13:42:25.715527Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: __TMP__REQUEST__MARKER__ cookie: 0
2025-11-05T13:42:25.726899Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1) initDone 1 event { CmdReadResult { MaxOffset: 1 Result { Offset: 0 Data: "... 33554506 bytes ..." SourceId: "" SeqNo: 1 PartNo: 65 TotalParts: 66 TotalSize: 33554506 WriteTimestampMS: 1762350145532 CreateTimestampMS: 1762350045341 UncompressedSize: 33554432 PartitionKey: "" ExplicitHash: "" } BlobsFromDisk: 0 BlobsFromCache: 4 SizeLag: 24575130 RealReadOffset: 0 WaitQuotaTimeMs: 0 EndOffset: 1 StartOffset: 0 } Cookie: 0 }
2025-11-05T13:42:25.756825Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1) wait data in partition inited, cookie 1 from offset1
2025-11-05T13:42:25.756857Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 after read state TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1) EndOffset 1 ReadOffset 1 ReadGuid 82efded3-cc149afa-55f685d4-7737aa7 has messages 1
2025-11-05T13:42:25.756928Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 read done: guid# 82efded3-cc149afa-55f685d4-7737aa7, partition# TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1), size# 33554591
2025-11-05T13:42:25.756939Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 response to read: guid# 82efded3-cc149afa-55f685d4-7737aa7
2025-11-05T13:42:25.763223Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 Process answer. Aval parts: 0
2025-11-05T13:42:25.777619Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.777636Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.803069Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] Got ReadResponse, serverBytesSize = 33554591, now ReadSizeBudget = 0, ReadSizeServerDelta = 18874209
2025-11-05T13:42:25.803117Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] In ContinueReadingDataImpl, ReadSizeBudget = 0, ReadSizeServerDelta = 18874209
2025-11-05T13:42:25.803253Z :DEBUG: [/Root] Decompression task done. Partition/PartitionSessionId: 1 (0-0)
2025-11-05T13:42:25.803273Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] Returning serverBytesSize = 33554591 to budget
2025-11-05T13:42:25.803282Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] In ContinueReadingDataImpl, ReadSizeBudget = 33554591, ReadSizeServerDelta = 18874209
2025-11-05T13:42:25.803442Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 52428800
2025-11-05T13:42:25.808028Z :DEBUG: [/Root] Take Data. Partition 0. Read: {0, 0} (0-0)
2025-11-05T13:42:25.808064Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] The application data is transferred to the client. Number of messages 1, size 33554432 bytes
2025-11-05T13:42:25.808079Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] Returning serverBytesSize = 0 to budget
2025-11-05T13:42:25.808111Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] Commit offsets [0, 1). Partition stream id: 1
2025-11-05T13:42:25.805818Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 grpc read done: success# 1, data# { read_request { bytes_size: 33554591 } }
2025-11-05T13:42:25.805944Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 got read request: guid# 81748a9a-540f4afb-e0cb750a-906f7c83
2025-11-05T13:42:25.809849Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 grpc read done: success# 1, data# { commit_offset_request { commit_offsets { partition_session_id: 1 offsets { end: 1 } } } }
2025-11-05T13:42:25.809935Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1) committing to position 1 prev 0 end 1 by cookie 2
2025-11-05T13:42:25.810060Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.810069Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.810094Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.810099Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.810121Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 user test-consumer offset is set to 1 (startOffset 0) session test-consumer_1_1_15965003278184400605_v1
2025-11-05T13:42:25.810128Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.810162Z node 1 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:25.811082Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 user test-consumer readTimeStamp for offset 1 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:42:25.811109Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:25.811119Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.811122Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.811143Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 2
2025-11-05T13:42:25.811180Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1) initDone 1 event { Cookie: 2 }
2025-11-05T13:42:25.811187Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 TopicId: Topic /Root/test-topic in database: Root, partition 0(assignId:1) commit done to position 1 endOffset 1 with cookie 2
2025-11-05T13:42:25.811201Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 replying for commits: assignId# 1, from# 2, to# 2, offset# 1
2025-11-05T13:42:25.816846Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] Committed response: { partitions_committed_offsets { partition_session_id: 1 committed_offset: 1 } }
2025-11-05T13:42:25.817605Z :INFO: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] Closing read session. Close timeout: 0.000000s
2025-11-05T13:42:25.817633Z :INFO: [/Root] Read/commit by partition streams (cluster:topic:partition:stream-id:read-offset:committed-offset): -:test-topic:0:1:0:1
2025-11-05T13:42:25.817644Z :INFO: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] Counters: { Errors: 0 CurrentSessionLifetimeMs: 161 BytesRead: 33554432 MessagesRead: 1 BytesReadCompressed: 33554432 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:25.817664Z :NOTICE: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Close with zero timeout " }
2025-11-05T13:42:25.817672Z :DEBUG: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] [] Abort session to cluster
2025-11-05T13:42:25.817811Z :NOTICE: [/Root] [/Root] [8b5ffd1e-560a3c5e-6f1de9b4-ea053554] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Aborted " }
2025-11-05T13:42:25.817878Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: try to update token
2025-11-05T13:42:25.817894Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Start write session. Will connect to nodeId: 0
2025-11-05T13:42:25.818149Z node 1 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 grpc read done: success# 0, data# {  }
2025-11-05T13:42:25.818161Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 grpc read failed
2025-11-05T13:42:25.818169Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 grpc closed
2025-11-05T13:42:25.818186Z node 1 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_1_1_15965003278184400605_v1 is DEAD
2025-11-05T13:42:25.818638Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511219:2465] disconnected; active server actors: 1
2025-11-05T13:42:25.818648Z node 1 :PERSQUEUE_READ_BALANCER NOTICE: [72075186224037893][test-topic] pipe [1:7569236237054511219:2465] client test-consumer disconnected session test-consumer_1_1_15965003278184400605_v1
2025-11-05T13:42:25.818678Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Destroy direct read session test-consumer_1_1_15965003278184400605_v1
2025-11-05T13:42:25.818685Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236237054511222:2468] destroyed
2025-11-05T13:42:25.818711Z node 1 :PQ_READ_PROXY DEBUG: Direct read cache: server session deregistered: test-consumer_1_1_15965003278184400605_v1
2025-11-05T13:42:25.818922Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: write to message_group: test-message_group_id
2025-11-05T13:42:25.818948Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: send init request: init_request { path: "test-topic" message_group_id: "test-message_group_id" }
2025-11-05T13:42:25.818952Z :TRACE: [/Root] TRACE_EVENT InitRequest 
2025-11-05T13:42:25.819004Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:42:25.827499Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:25.827520Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350145827 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:25.827535Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session established. Init response: session_id: "test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0"
2025-11-05T13:42:25.827540Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0
2025-11-05T13:42:25.827543Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  MessageGroupId [test-message_group_id] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:42:25.827605Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.000000s
2025-11-05T13:42:25.827616Z :TRACE: [/Root] TRACE_EVENT DescribePartitionRequest  path=/Root/test-topic partition_id=0
2025-11-05T13:42:25.828409Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-11-05T13:42:25.825978Z node 1 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:25.825991Z node 1 :PQ_WRITE_PROXY DEBUG: new session created cookie 4
2025-11-05T13:42:25.826148Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId:  grpc read done: success: 1 data: init_request { path: "test-topic" message_group_id: "test-message_group_id" }
2025-11-05T13:42:25.826169Z node 1 :PQ_WRITE_PROXY INFO: session request cookie: 4 path: "test-topic" message_group_id: "test-message_group_id" from ipv6:[::1]:57350
2025-11-05T13:42:25.826175Z node 1 :PQ_WRITE_PROXY INFO: write session:  cookie=4 sessionId= userAgent="topic server" ip=ipv6:[::1]:57350 proto=topic  topic=test-topic durationSec=0
2025-11-05T13:42:25.826180Z node 1 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:25.826493Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId:  describe result for acl check
2025-11-05T13:42:25.826533Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint64; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `//Root/.metadata/TopicPartitionsMapping` WHERE Hash == $Hash AND Topic == $Topic AND ProducerId == $SourceId;
2025-11-05T13:42:25.826534Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64; DECLARE $SeqNo AS Uint64;
UPSERT INTO `//Root/.metadata/TopicPartitionsMapping` (Hash, Topic, ProducerId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-11-05T13:42:25.826536Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `//Root/.metadata/TopicPartitionsMapping` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND ProducerId = $SourceId AND Partition = $Partition;
2025-11-05T13:42:25.826548Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [1:7569236237054511235:2471] (SourceId=test-message_group_id, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:25.826552Z node 1 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 4 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:42:25.826758Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511238:2471], now have 1 active actors on pipe
2025-11-05T13:42:25.826773Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 1, Generation: 1
2025-11-05T13:42:25.826830Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.826834Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.826861Z node 1 :PERSQUEUE INFO: new Cookie test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0 generated for partition 0 topic 'test-topic' owner test-message_group_id
2025-11-05T13:42:25.826869Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.826875Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.826886Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.826897Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:25.826914Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:25.826981Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.826983Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.826995Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:25.827010Z node 1 :PQ_WRITE_PROXY INFO: session inited cookie: 4 partition: 0 MaxSeqNo: 0 sessionId: test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0
2025-11-05T13:42:25.829629Z node 1 :PQ_READ_PROXY DEBUG: new Describe partition request
2025-11-05T13:42:25.829655Z node 1 :PQ_READ_PROXY DEBUG: TDescribePartitionActor for request path: "/Root/test-topic"
include_location: true
2025-11-05T13:42:25.829666Z node 1 :PQ_READ_PROXY DEBUG: TDescribePartitionActor[1:7569236237054511241:2473]: Bootstrap
2025-11-05T13:42:25.830229Z node 1 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [1:7569236237054511241:2473]: Request location
2025-11-05T13:42:25.830423Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511244:2474] connected; active server actors: 1
2025-11-05T13:42:25.830494Z node 1 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] addPartitionToResponse tabletId 72075186224037892, partitionId 0, NodeId 1, Generation 1
2025-11-05T13:42:25.830501Z node 1 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [1:7569236237054511241:2473]: Got location
2025-11-05T13:42:25.830836Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 1
    generation: 1
  }
}
2025-11-05T13:42:25.830844Z :TRACE: [/Root] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=1 pl_generation=1
2025-11-05T13:42:25.830851Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 1 exists in the endpoint pool.
2025-11-05T13:42:25.830857Z :TRACE: [/Root] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=1 Generation=1
2025-11-05T13:42:25.830861Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  PartitionId [0]  Generation [1] Start write session. Will connect to nodeId: 1
2025-11-05T13:42:25.833640Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511244:2474] disconnected; active server actors: 1
2025-11-05T13:42:25.833651Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236237054511244:2474] disconnected no session
2025-11-05T13:42:25.833935Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  PartitionId [0]  Generation [1] Write session: direct write to partition: 0, generation 1
2025-11-05T13:42:25.833964Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  PartitionId [0]  Generation [1] Write session: send init request: init_request { path: "test-topic" partition_with_generation { generation: 1 } }
2025-11-05T13:42:25.833969Z :TRACE: [/Root] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=1
2025-11-05T13:42:25.834074Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 1, Msg: CANCELLED, Details: , InternalError: 0
2025-11-05T13:42:25.834141Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  PartitionId [0]  Generation [1] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:42:25.837315Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0 grpc read done: success: 0 data: 
2025-11-05T13:42:25.837329Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0 grpc read failed
2025-11-05T13:42:25.837340Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0 grpc closed
2025-11-05T13:42:25.837344Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0 is DEAD
2025-11-05T13:42:25.837578Z node 1 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:25.837579Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:25.837583Z node 1 :PQ_WRITE_PROXY DEBUG: new session created cookie 5
2025-11-05T13:42:25.837791Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236237054511238:2471] destroyed
2025-11-05T13:42:25.837804Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:25.837812Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.837814Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.844754Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:25.844780Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|224b9342-72b4f534-dffcb85-13065cd5_0]  PartitionId [0]  Generation [1] Write session established. Init response: session_id: "145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0"
2025-11-05T13:42:25.844785Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0
2025-11-05T13:42:25.844790Z :DEBUG: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:42:25.844855Z :DEBUG: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 1 to 1
2025-11-05T13:42:25.844870Z :DEBUG: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:42:25.844876Z :DEBUG: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 1
2025-11-05T13:42:25.844914Z :INFO: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Write session: close. Timeout 18446744073709.551615s
2025-11-05T13:42:25.843504Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId:  grpc read done: success: 1 data: init_request { path: "test-topic" partition_with_generation { generation: 1 } }
2025-11-05T13:42:25.843543Z node 1 :PQ_WRITE_PROXY INFO: session request cookie: 5 path: "test-topic" partition_with_generation { generation: 1 } from ipv6:[::1]:57350
2025-11-05T13:42:25.843545Z node 1 :PQ_WRITE_PROXY DEBUG: session request cookie: 5. Disable deduplication for empty producer id
2025-11-05T13:42:25.843550Z node 1 :PQ_WRITE_PROXY INFO: write session:  cookie=5 sessionId= userAgent="topic server" ip=ipv6:[::1]:57350 proto=topic  topic=test-topic durationSec=0
2025-11-05T13:42:25.843554Z node 1 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:25.843568Z node 1 :PQ_WRITE_PROXY INFO: session to partition: 0, generation: 1
2025-11-05T13:42:25.843913Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId:  describe result for acl check
2025-11-05T13:42:25.843952Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper SelectQuery: --!syntax_v1
DECLARE $Hash AS Uint64; DECLARE $Topic AS Utf8; DECLARE $SourceId AS Utf8;
SELECT Partition, CreateTime, AccessTime, SeqNo FROM `//Root/.metadata/TopicPartitionsMapping` WHERE Hash == $Hash AND Topic == $Topic AND ProducerId == $SourceId;
2025-11-05T13:42:25.843954Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64; DECLARE $SeqNo AS Uint64;
UPSERT INTO `//Root/.metadata/TopicPartitionsMapping` (Hash, Topic, ProducerId, CreateTime, AccessTime, Partition, SeqNo) VALUES ($Hash, $Topic, $SourceId, $CreateTime, $AccessTime, $Partition, $SeqNo);
2025-11-05T13:42:25.843955Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TTableHelper UpdateAccessTimeQuery: --!syntax_v1
DECLARE $SourceId AS Utf8; DECLARE $Topic AS Utf8; DECLARE $Hash AS Uint64; DECLARE $Partition AS Uint32; DECLARE $CreateTime AS Uint64; DECLARE $AccessTime AS Uint64;
UPDATE `//Root/.metadata/TopicPartitionsMapping` SET AccessTime = $AccessTime WHERE Hash = $Hash AND Topic = $Topic AND ProducerId = $SourceId AND Partition = $Partition;
2025-11-05T13:42:25.843964Z node 1 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [1:7569236237054511249:2476] (SourceId=, PreferedPartition=0) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:25.843969Z node 1 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 5 sessionId:  partition: 0 expectedGeneration: 1
2025-11-05T13:42:25.844214Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 1, Generation: 1
2025-11-05T13:42:25.844228Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236237054511252:2476], now have 1 active actors on pipe
2025-11-05T13:42:25.844284Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.844289Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.844310Z node 1 :PERSQUEUE INFO: new Cookie 145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0 generated for partition 0 topic 'test-topic' owner 145cd5f5-76b08cf4-2ce7ea94-ce883ebb
2025-11-05T13:42:25.844320Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.844326Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.844336Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.844347Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:25.844363Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:25.844432Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.844433Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.844443Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:25.844458Z node 1 :PQ_WRITE_PROXY INFO: session inited cookie: 5 partition: 0 MaxSeqNo: 0 sessionId: 145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0
2025-11-05T13:42:25.848221Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: 145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:42:25.848354Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::NPQ::TEvPartitionWriter::TEvWriteRequest
2025-11-05T13:42:25.848508Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.848515Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.848556Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 1
2025-11-05T13:42:25.848571Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:25.848648Z node 1 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:25.848654Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:25.848665Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 0 messageNo: 1 size 103 offset: -1
2025-11-05T13:42:25.848687Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.848695Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.848724Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob processing sourceId '' seqNo 1 partNo 0
2025-11-05T13:42:25.848763Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 part blob complete sourceId '' seqNo 1 partNo 0 FormedBlobsCount 0 NewHead: Offset 1 PartNo 0 PackedSize 170 count 1 nextOffset 2 batches 1
2025-11-05T13:42:25.848771Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.848814Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Add new write blob: topic 'test-topic' partition 0 compactOffset 1,1 HeadOffset 0 endOffset 1 curOffset 2 d0000000000_00000000000000000001_00000_0000000001_00000| size 158 WTime 1762350145848
2025-11-05T13:42:25.848837Z node 1 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:25.848847Z node 1 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 1 partNo 0 count 1 size 158
2025-11-05T13:42:25.849234Z node 1 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 1 count 1 size 158 actorID [1:7569236237054511072:2425]
2025-11-05T13:42:25.849288Z node 1 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037892' partition 0 offset 1 partno 0 count 1 parts 0 size 158
2025-11-05T13:42:25.853608Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 103 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:25.853631Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyWrite. Partition: 0
2025-11-05T13:42:25.853650Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: 0, SeqNo: 1, partNo: 0, Offset: 1 is stored on disk
2025-11-05T13:42:25.853698Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 user test-consumer readTimeStamp for offset 1 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:42:25.853704Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic 'test-topic' partition 0 user test-consumer send read request for offset 1 initiated  queuesize 0 startOffset 0 ReadingTimestamp 1 rrg 0
2025-11-05T13:42:25.853709Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.853714Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.853750Z node 1 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 1  requestId: <none> cookie: 1
2025-11-05T13:42:25.853786Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:25.853927Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] read cookie 3 Topic 'test-topic' partition 0 user test-consumer offset 1 count 1 size 1024000 endOffset 2 max time lag 0ms effective offset 1
2025-11-05T13:42:25.853936Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] read cookie 3 added 0 blobs, size 0 count 0 last offset 1, current partition end offset: 2
2025-11-05T13:42:25.853943Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Reading cookie 3. All data is from uncompacted head.
2025-11-05T13:42:25.853948Z node 1 :PERSQUEUE DEBUG: FormAnswer for 0 blobs
2025-11-05T13:42:25.853968Z node 1 :PERSQUEUE DEBUG: Topic 'test-topic' partition 0 user test-consumer readTimeStamp done, result 1762350145848 queuesize 0 startOffset 0
2025-11-05T13:42:25.854265Z :DEBUG: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:25.854325Z :DEBUG: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 1 written { offset: 1 } } write_statistics { persisting_time { nanos: 4000000 } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-11-05T13:42:25.854332Z :DEBUG: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] OnAck: seqNo=1, txId=?
2025-11-05T13:42:25.854339Z :DEBUG: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 1
2025-11-05T13:42:25.881749Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.881767Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.945510Z :INFO: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Write session will now close
2025-11-05T13:42:25.945533Z :DEBUG: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Write session: aborting
2025-11-05T13:42:25.945723Z :INFO: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Write session: gracefully shut down, all writes complete
2025-11-05T13:42:25.945733Z :DEBUG: [/Root]  TraceId []  SessionId [145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0]  PartitionId [0]  Generation [1] Write session: destroy
2025-11-05T13:42:25.946147Z node 1 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: 145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0 grpc read done: success: 0 data: 
2025-11-05T13:42:25.946160Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: 145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0 grpc read failed
2025-11-05T13:42:25.946171Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: 145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0 grpc closed
2025-11-05T13:42:25.946174Z node 1 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: 145cd5f5-76b08cf4-2ce7ea94-ce883ebb|d4f838b3-a48ec9a7-f8065115-d0f77d9_0 is DEAD
2025-11-05T13:42:25.946351Z node 1 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:25.946690Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236237054511252:2476] destroyed
2025-11-05T13:42:25.946707Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:25.946715Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.946717Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:25.985523Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:25.985540Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:26.084748Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:26.084763Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:26.184860Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:26.184875Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:26.285231Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:26.285252Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:26.386037Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:26.386053Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:26.489491Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:26.489508Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:26.593481Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:26.593496Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:26.700534Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:26.700552Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:26.800829Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:26.800854Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:26.901480Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:26.901499Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:27.001555Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:27.001582Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:27.101840Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:27.101854Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:27.202209Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:27.202222Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:27.302558Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:27.302572Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:27.405548Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:27.405573Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:27.505941Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:27.505955Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:27.606412Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:27.606429Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:27.707901Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:27.707914Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:27.809973Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:27.809986Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:27.911511Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:27.911528Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:28.013591Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:28.013606Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:28.114163Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:28.114179Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:28.214471Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:28.214490Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:28.314868Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:28.314890Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:28.415181Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:28.415198Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:28.515530Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:28.515543Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:28.616455Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:28.616471Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:28.716724Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:28.716740Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:28.817859Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:28.817877Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:28.918022Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:28.918038Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:28.954192Z node 1 :PQ_READ_PROXY ERROR: new Describe topic request
2025-11-05T13:42:28.954262Z node 1 :PQ_READ_PROXY DEBUG: Describe topic actor for path test-topic
2025-11-05T13:42:28.954899Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236249939413302:2515], now have 1 active actors on pipe
2025-11-05T13:42:28.954919Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236249939413303:2516] connected; active server actors: 1
2025-11-05T13:42:28.955079Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic PartitionStatus PartitionSize: 25364299 UsedReserveSize: 0 ReserveSize: 0 PartitionConfig{ MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 }
2025-11-05T13:42:28.955521Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236249939413302:2515] destroyed
2025-11-05T13:42:28.961989Z node 1 :PQ_READ_PROXY DEBUG: new Describe consumer request
2025-11-05T13:42:28.962047Z node 1 :PQ_READ_PROXY DEBUG: TDescribeConsumerActor for request operation_params {
}
path: "test-topic"
consumer: "test-consumer"
include_stats: true
2025-11-05T13:42:28.962370Z node 1 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [1:7569236249939413308:2518]: Request sessions
2025-11-05T13:42:28.962575Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236249939413310:2519], now have 1 active actors on pipe
2025-11-05T13:42:28.962592Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236249939413311:2520] connected; active server actors: 1
2025-11-05T13:42:28.962753Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic PartitionStatus PartitionSize: 25364299 UsedReserveSize: 0 ReserveSize: 0 PartitionConfig{ MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 }
2025-11-05T13:42:28.962770Z node 1 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [1:7569236249939413308:2518]: Got sessions
2025-11-05T13:42:28.963158Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236249939413311:2520] disconnected; active server actors: 1
2025-11-05T13:42:28.963163Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236249939413311:2520] disconnected no session
2025-11-05T13:42:28.963171Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236249939413310:2519] destroyed
2025-11-05T13:42:28.969830Z node 1 :PQ_READ_PROXY DEBUG: new Describe partition request
2025-11-05T13:42:28.969884Z node 1 :PQ_READ_PROXY DEBUG: TDescribePartitionActor for request operation_params {
}
path: "test-topic"
include_stats: true
2025-11-05T13:42:28.969895Z node 1 :PQ_READ_PROXY DEBUG: TDescribePartitionActor[1:7569236249939413316:2522]: Bootstrap
2025-11-05T13:42:28.970503Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [1:7569236249939413319:2523], now have 1 active actors on pipe
2025-11-05T13:42:28.970524Z node 1 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [1:7569236249939413320:2524] connected; active server actors: 1
2025-11-05T13:42:28.970672Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Topic PartitionStatus PartitionSize: 25364299 UsedReserveSize: 0 ReserveSize: 0 PartitionConfig{ MaxCountInPartition: 2147483647 LifetimeSeconds: 3600 SourceIdLifetimeSeconds: 1382400 WriteSpeedInBytesPerSecond: 1048576 BurstSize: 1048576 TotalPartitions: 1 ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } ExplicitChannelProfiles { PoolKind: "test" } SourceIdMaxCounts: 6000000 }
2025-11-05T13:42:28.971030Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [1:7569236249939413319:2523] destroyed
2025-11-05T13:42:29.021243Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:29.021260Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:29.119868Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:29.119889Z node 1 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
