test_client.cpp: SetPath # /home/runner/.ya/build/build_root/4xc1/003f47/r3tmp/tmpagu6OX/pdisk_1.dat
2025-11-05T13:42:25.474726Z node 2 :PQ_READ_PROXY DEBUG: Direct read cache: : Created
2025-11-05T13:42:25.501006Z node 2 :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:25.501877Z node 2 :IMPORT WARN: Table profiles were not loaded
2025-11-05T13:42:25.504027Z node 2 :CONFIGS_DISPATCHER ERROR: Notification cookie mismatch for subscription [2:7569236240653397405:2081] 1762350145464186 != 1762350145464189
TServer::EnableGrpc on GrpcPort 21480, node 2
2025-11-05T13:42:25.517988Z node 2 :NET_CLASSIFIER WARN: distributable config is empty, broken or outdated, will use file: /home/runner/.ya/build/build_root/4xc1/003f47/r3tmp/yandexITf996.tmp
2025-11-05T13:42:25.518000Z node 2 :NET_CLASSIFIER WARN: will try to initialize from file: /home/runner/.ya/build/build_root/4xc1/003f47/r3tmp/yandexITf996.tmp
2025-11-05T13:42:25.518051Z node 2 :NET_CLASSIFIER WARN: successfully initialized from file: /home/runner/.ya/build/build_root/4xc1/003f47/r3tmp/yandexITf996.tmp
2025-11-05T13:42:25.518091Z node 2 :NET_CLASSIFIER ERROR: got bad distributable configuration
2025-11-05T13:42:25.521234Z INFO: TTestServer started on Port 2840 GrpcPort 21480
TClient is connected to server localhost:2840
PQClient connected to localhost:21480
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.
2025-11-05T13:42:25.581710Z node 2 :HIVE WARN: HIVE#72057594037968897 Node(2, (0,0,0,0)) VolatileState: Unknown -> Disconnected
2025-11-05T13:42:25.581750Z node 2 :HIVE WARN: HIVE#72057594037968897 Node(2, (0,0,0,0)) VolatileState: Disconnected -> Connecting
2025-11-05T13:42:25.582240Z node 2 :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:25.582715Z node 2 :HIVE WARN: HIVE#72057594037968897 Node(2, (0,0,0,0)) VolatileState: Connecting -> Connected
waiting...
2025-11-05T13:42:25.589490Z node 2 :FLAT_TX_SCHEMESHARD WARN: NotifyTxCompletion, unknown transaction, txId: 281474976715657, at schemeshard: 72057594046644480
waiting...
2025-11-05T13:42:25.602421Z node 2 :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:25.649840Z node 2 :FLAT_TX_SCHEMESHARD WARN: NotifyTxCompletion, unknown transaction, txId: 281474976715661, at schemeshard: 72057594046644480
2025-11-05T13:42:25.812085Z node 2 :KQP_COMPILE_ACTOR ERROR: Compilation failed, self: [2:7569236240653398172: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:25.812588Z node 2 :KQP_SESSION WARN: SessionId: ydb://session/3?node_id=2&id=N2FkMjE4NmUtYmIzNDc1ZjUtOTA3YzhjMzEtMTg1NmM0Njc=, ActorId: [2:7569236240653398169:2314], ActorState: ExecuteState, TraceId: 01k9a4288fcyze9p8xtjh98nee, ReplyQueryCompileError, status SCHEME_ERROR remove tx with tx_id: 
2025-11-05T13:42:25.812717Z node 2 :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:25.823863Z node 2 :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:25.843504Z node 2 :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:25.866303Z node 2 :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 [2:7569236240653398447:2564] 
2025-11-05T13:42:26.466247Z node 2 :TX_CONVEYOR ERROR: fline=service.h:53;problem=unexpected event for task executor;ev_type=NActors::TEvents::TEvWakeup;
=== CheckClustersList. Ok
2025-11-05T13:42:31.023852Z :WriteToTopic_Two_WriteSession INFO: TTopicSdkTestSetup started
2025-11-05T13:42:31.049342Z node 2 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:42:31.078774Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][] pipe [2:7569236266423202515:2724] connected; active server actors: 1
2025-11-05T13:42:31.078855Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] updating configuration. Deleted partitions []. Added partitions [0]
2025-11-05T13:42:31.078940Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:42:31.079593Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:42:31.079641Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:42:31.079678Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] doesn't have tx info
2025-11-05T13:42:31.079682Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-11-05T13:42:31.079684Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] no config, start with empty partitions and default config
2025-11-05T13:42:31.079688Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:42:31.079694Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:42:31.079704Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037892] doesn't have tx writes info
2025-11-05T13:42:31.079739Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:42:31.079755Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] BALANCER INIT DONE for test-topic: (0, 72075186224037892) 
2025-11-05T13:42:31.080092Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236266423202514:2723], now have 1 active actors on pipe
2025-11-05T13:42:31.080199Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236240653397741 RawX2: 8589936736 } 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:31.080226Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] Propose TxId 281474976715671, WriteId (empty maybe)
2025-11-05T13:42:31.080231Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state UNKNOWN
2025-11-05T13:42:31.080234Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State UNKNOWN
2025-11-05T13:42:31.080238Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] schedule TEvProposeTransactionResult(PREPARED)
2025-11-05T13:42:31.080240Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from UNKNOWN to PREPARING
2025-11-05T13:42:31.080247Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:31.080297Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PREPARED MinStep: 1762350151065 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: 7569236240653397741 RawX2: 8589936736 } Partitions { }
2025-11-05T13:42:31.080315Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.080431Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236266423202560:2422], now have 1 active actors on pipe
2025-11-05T13:42:31.080483Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72075186224037892, NodeId 2, Generation 1
2025-11-05T13:42:31.080486Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72057594046644480, NodeId 2, Generation 2
2025-11-05T13:42:31.080639Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.080643Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARING
2025-11-05T13:42:31.080644Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARING
2025-11-05T13:42:31.080646Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARING to PREPARED
2025-11-05T13:42:31.081156Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037892 TxId: 281474976715671
2025-11-05T13:42:31.081164Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236266423202570:2754], now have 1 active actors on pipe
2025-11-05T13:42:31.081177Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976715671 AckTo { RawX1: 0 RawX2: 0 } } Step: 1762350151128 MediatorID: 72057594046382081 TabletID: 72075186224037892
2025-11-05T13:42:31.081181Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARED
2025-11-05T13:42:31.081183Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARED
2025-11-05T13:42:31.081185Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARED to PLANNING
2025-11-05T13:42:31.081190Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] PlanStep 1762350151128, PlanTxId 281474976715671
2025-11-05T13:42:31.081193Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:31.081249Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PLANNED MinStep: 1762350151065 MaxStep: 18446744073709551615 Step: 1762350151128 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: 7569236240653397741 RawX2: 8589936736 } Partitions { }
2025-11-05T13:42:31.081262Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.081498Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.081502Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PLANNING
2025-11-05T13:42:31.081504Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PLANNING
2025-11-05T13:42:31.081505Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNING to PLANNED
2025-11-05T13:42:31.081508Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxQueue.size 1
2025-11-05T13:42:31.081511Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] New ExecStep 1762350151128, ExecTxId 281474976715671
2025-11-05T13:42:31.081696Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNED to CALCULATING
2025-11-05T13:42:31.081712Z node 2 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:42:31.081720Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-11-05T13:42:31.081757Z node 2 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:42:31.081828Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] bootstrapping 0 [2:7569236266423202576:2426]
2025-11-05T13:42:31.082058Z node 2 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Initializing completed.
2025-11-05T13:42:31.082063Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] init complete for topic 'test-topic' partition 0 generation 1 [2:7569236266423202576:2426]
2025-11-05T13:42:31.082069Z node 2 :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:31.082143Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-11-05T13:42:31.082148Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.082163Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.082167Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:42:31.082169Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.082171Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.082173Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:42:31.082180Z node 2 :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:31.082217Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPQ::TEvProposePartitionConfigResult Step 1762350151128, TxId 281474976715671, Partition 0
2025-11-05T13:42:31.082218Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] Handle TEvProposePartitionConfigResult
2025-11-05T13:42:31.082222Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] Partition responses 1/1
2025-11-05T13:42:31.082224Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATING
2025-11-05T13:42:31.082226Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATING
2025-11-05T13:42:31.082228Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATING FrontTxId 281474976715671
2025-11-05T13:42:31.082230Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:42:31.082233Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATING to CALCULATED
2025-11-05T13:42:31.082235Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:31.082304Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: CALCULATED MinStep: 1762350151065 MaxStep: 18446744073709551615 Step: 1762350151128 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: 7569236240653397741 RawX2: 8589936736 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:42:31.082319Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.083210Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.083216Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATED
2025-11-05T13:42:31.083218Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATED
2025-11-05T13:42:31.083220Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATED FrontTxId 281474976715671
2025-11-05T13:42:31.083222Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATED to WAIT_RS
2025-11-05T13:42:31.083230Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-11-05T13:42:31.083232Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveParticipantsDecision 1
2025-11-05T13:42:31.083238Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS to EXECUTING
2025-11-05T13:42:31.083240Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 0, Expected 1
2025-11-05T13:42:31.083250Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1762350151128, TxId 281474976715671
2025-11-05T13:42:31.083254Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.083255Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.083281Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.083311Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:31.089454Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:31.089472Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.089475Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.089526Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] Handle TEvPQ::TEvTxCommitDone Step 1762350151128, TxId 281474976715671, Partition 0
2025-11-05T13:42:31.089532Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTING
2025-11-05T13:42:31.089533Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTING
2025-11-05T13:42:31.089537Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTING FrontTxId 281474976715671
2025-11-05T13:42:31.089542Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:42:31.089549Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId: 281474976715671 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-11-05T13:42:31.089567Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] complete TxId 281474976715671
2025-11-05T13:42:31.089671Z node 2 :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:31.089687Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:42:31.089694Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] delete partitions for TxId 281474976715671
2025-11-05T13:42:31.089697Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTING to EXECUTED
2025-11-05T13:42:31.089704Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:42:31.089766Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: EXECUTED MinStep: 1762350151065 MaxStep: 18446744073709551615 Step: 1762350151128 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: 7569236240653397741 RawX2: 8589936736 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:42:31.089803Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.090965Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:42:31.092684Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:42:31.092751Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.092757Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTED
2025-11-05T13:42:31.092759Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTED
2025-11-05T13:42:31.092763Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTED FrontTxId 281474976715671
2025-11-05T13:42:31.092767Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TPersQueue::SendEvReadSetAckToSenders
2025-11-05T13:42:31.092769Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTED to WAIT_RS_ACKS
2025-11-05T13:42:31.092772Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:42:31.092775Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-11-05T13:42:31.092777Z node 2 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:42:31.092780Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] add an TxId 281474976715671 to the list for deletion
2025-11-05T13:42:31.092782Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS_ACKS to DELETING
2025-11-05T13:42:31.092787Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] delete key for TxId 281474976715671
2025-11-05T13:42:31.092797Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.093075Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.093079Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state DELETING
2025-11-05T13:42:31.093080Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State DELETING
2025-11-05T13:42:31.093083Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] delete TxId 281474976715671
2025-11-05T13:42:31.098061Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:42:31.098334Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:42:31.098340Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:21480
2025-11-05T13:42:31.101385Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "test-topic" message_group_id: "src" }
2025-11-05T13:42:31.104080Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:31.104096Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 1
2025-11-05T13:42:31.104280Z node 2 :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:31.104299Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 1 topic: "test-topic" message_group_id: "src" from ipv6:[::1]:46902
2025-11-05T13:42:31.104304Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=1 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:46902 proto=v1  topic=test-topic durationSec=0
2025-11-05T13:42:31.104309Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:31.106441Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId:  describe result for acl check
2025-11-05T13:42:31.106478Z node 2 :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:31.106480Z node 2 :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:31.106481Z node 2 :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:31.106493Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236266423202623:2434] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:31.106497Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 1 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:42:31.106811Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 2, Generation: 1
2025-11-05T13:42:31.106826Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236266423202626:2434], now have 1 active actors on pipe
2025-11-05T13:42:31.106908Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:31.106916Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:31.106945Z node 2 :PERSQUEUE INFO: new Cookie src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0 generated for partition 0 topic 'test-topic' owner src
2025-11-05T13:42:31.106953Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.106957Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.106970Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.106981Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:31.106999Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.107116Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:31.107121Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:31.107136Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.107153Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 1 partition: 0 MaxSeqNo: 0 sessionId: src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0
2025-11-05T13:42:31.109260Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350151109 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:31.109295Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0" topic: "test-topic"
2025-11-05T13:42:31.109406Z :INFO: [/Root] MessageGroupId [src] SessionId [src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0] Write session: close. Timeout = 0 ms
2025-11-05T13:42:31.109411Z :INFO: [/Root] MessageGroupId [src] SessionId [src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0] Write session will now close
2025-11-05T13:42:31.109417Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0] Write session: aborting
2025-11-05T13:42:31.109533Z :INFO: [/Root] MessageGroupId [src] SessionId [src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:42:31.109539Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0] Write session: destroy
2025-11-05T13:42:31.112784Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 1 sessionId: src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0 grpc read done: success: 0 data: 
2025-11-05T13:42:31.112802Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0 grpc read failed
2025-11-05T13:42:31.112810Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0 grpc closed
2025-11-05T13:42:31.112814Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|a2ee59c4-6f2cd1d-e7bfa540-4b26a32f_0 is DEAD
2025-11-05T13:42:31.113011Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:31.113071Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [2:7569236266423202626:2434] destroyed
2025-11-05T13:42:31.113089Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:31.113095Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.113098Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.118597Z :WriteToTopic_Two_WriteSession INFO: Topic created
2025-11-05T13:42:31.133616Z node 2 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:42:31.136652Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:42:31.136876Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:42:31.139280Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][] pipe [2:7569236266423202673:2801] connected; active server actors: 1
2025-11-05T13:42:31.139340Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][test-topic_2] updating configuration. Deleted partitions []. Added partitions [0]
2025-11-05T13:42:31.139393Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:42:31.139676Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Registered with mediator time cast
2025-11-05T13:42:31.139725Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:42:31.139755Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] doesn't have tx info
2025-11-05T13:42:31.139759Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-11-05T13:42:31.139762Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] no config, start with empty partitions and default config
2025-11-05T13:42:31.139766Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:42:31.139773Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037894] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:42:31.139786Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894] doesn't have tx writes info
2025-11-05T13:42:31.139815Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][test-topic_2] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037895
2025-11-05T13:42:31.139837Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][test-topic_2] BALANCER INIT DONE for test-topic_2: (0, 72075186224037894) 
2025-11-05T13:42:31.140176Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236266423202671:2799], now have 1 active actors on pipe
2025-11-05T13:42:31.140268Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236240653397741 RawX2: 8589936736 } TxId: 281474976715672 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_2" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic_2" 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:31.140349Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] Propose TxId 281474976715672, WriteId (empty maybe)
2025-11-05T13:42:31.140355Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state UNKNOWN
2025-11-05T13:42:31.140357Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State UNKNOWN
2025-11-05T13:42:31.140361Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] schedule TEvProposeTransactionResult(PREPARED)
2025-11-05T13:42:31.140364Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from UNKNOWN to PREPARING
2025-11-05T13:42:31.140371Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:42:31.140418Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: PREPARED MinStep: 1762350151135 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_2" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic_2" 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: 7569236240653397741 RawX2: 8589936736 } Partitions { }
2025-11-05T13:42:31.140435Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.140586Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236266423202703:2448], now have 1 active actors on pipe
2025-11-05T13:42:31.140643Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][test-topic_2] TEvClientConnected TabletId 72075186224037894, NodeId 2, Generation 1
2025-11-05T13:42:31.140646Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][test-topic_2] TEvClientConnected TabletId 72057594046644480, NodeId 2, Generation 2
2025-11-05T13:42:31.140809Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.140816Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PREPARING
2025-11-05T13:42:31.140817Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PREPARING
2025-11-05T13:42:31.140819Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PREPARING to PREPARED
2025-11-05T13:42:31.141328Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037894 TxId: 281474976715672
2025-11-05T13:42:31.141338Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236266423202715:2826], now have 1 active actors on pipe
2025-11-05T13:42:31.141352Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976715672 AckTo { RawX1: 0 RawX2: 0 } } Step: 1762350151191 MediatorID: 72057594046382081 TabletID: 72075186224037894
2025-11-05T13:42:31.141357Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PREPARED
2025-11-05T13:42:31.141359Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PREPARED
2025-11-05T13:42:31.141362Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PREPARED to PLANNING
2025-11-05T13:42:31.141367Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] PlanStep 1762350151191, PlanTxId 281474976715672
2025-11-05T13:42:31.141370Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:42:31.141422Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: PLANNED MinStep: 1762350151135 MaxStep: 18446744073709551615 Step: 1762350151191 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_2" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic_2" 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: 7569236240653397741 RawX2: 8589936736 } Partitions { }
2025-11-05T13:42:31.141450Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.141703Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.141710Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PLANNING
2025-11-05T13:42:31.141712Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PLANNING
2025-11-05T13:42:31.141714Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PLANNING to PLANNED
2025-11-05T13:42:31.141717Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxQueue.size 1
2025-11-05T13:42:31.141719Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] New ExecStep 1762350151191, ExecTxId 281474976715672
2025-11-05T13:42:31.141913Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PLANNED to CALCULATING
2025-11-05T13:42:31.141922Z node 2 :PERSQUEUE DEBUG: [test-topic_2:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:42:31.141931Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-11-05T13:42:31.141964Z node 2 :PERSQUEUE DEBUG: [test-topic_2:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:42:31.142027Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] bootstrapping 0 [2:7569236266423202721:2452]
2025-11-05T13:42:31.142230Z node 2 :PERSQUEUE DEBUG: [test-topic_2:0:Initializer] Initializing completed.
2025-11-05T13:42:31.142233Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] init complete for topic 'test-topic_2' partition 0 generation 1 [2:7569236266423202721:2452]
2025-11-05T13:42:31.142239Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateInit] SYNC INIT topic test-topic_2 partitition 0 so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:42:31.142300Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-11-05T13:42:31.142305Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.142318Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.142321Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:42:31.142323Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.142325Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.142326Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:42:31.142334Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'test-topic_2' partition 0 user test-consumer readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:42:31.142380Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvProposePartitionConfigResult Step 1762350151191, TxId 281474976715672, Partition 0
2025-11-05T13:42:31.142382Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] Handle TEvProposePartitionConfigResult
2025-11-05T13:42:31.142385Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] Partition responses 1/1
2025-11-05T13:42:31.142387Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state CALCULATING
2025-11-05T13:42:31.142389Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State CALCULATING
2025-11-05T13:42:31.142391Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State CALCULATING FrontTxId 281474976715672
2025-11-05T13:42:31.142394Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 1, Expected 1
2025-11-05T13:42:31.142396Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from CALCULATING to CALCULATED
2025-11-05T13:42:31.142399Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:42:31.142456Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: CALCULATED MinStep: 1762350151135 MaxStep: 18446744073709551615 Step: 1762350151191 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_2" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic_2" 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: 7569236240653397741 RawX2: 8589936736 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:42:31.142469Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.142988Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.142994Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state CALCULATED
2025-11-05T13:42:31.142996Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State CALCULATED
2025-11-05T13:42:31.142998Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State CALCULATED FrontTxId 281474976715672
2025-11-05T13:42:31.142999Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from CALCULATED to WAIT_RS
2025-11-05T13:42:31.143007Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-11-05T13:42:31.143009Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] HaveParticipantsDecision 1
2025-11-05T13:42:31.143017Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from WAIT_RS to EXECUTING
2025-11-05T13:42:31.143020Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 0, Expected 1
2025-11-05T13:42:31.143028Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1762350151191, TxId 281474976715672
2025-11-05T13:42:31.143032Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.143034Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.143055Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.143085Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:31.143307Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:31.143314Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.143315Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.143332Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] Handle TEvPQ::TEvTxCommitDone Step 1762350151191, TxId 281474976715672, Partition 0
2025-11-05T13:42:31.143333Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state EXECUTING
2025-11-05T13:42:31.143334Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State EXECUTING
2025-11-05T13:42:31.143335Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State EXECUTING FrontTxId 281474976715672
2025-11-05T13:42:31.143337Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 1, Expected 1
2025-11-05T13:42:31.143341Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId: 281474976715672 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-11-05T13:42:31.143344Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] complete TxId 281474976715672
2025-11-05T13:42:31.143382Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] 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_2" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic_2" 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:31.143393Z node 2 :PERSQUEUE NOTICE: [PQ: 72075186224037894] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:42:31.143397Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] delete partitions for TxId 281474976715672
2025-11-05T13:42:31.143399Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from EXECUTING to EXECUTED
2025-11-05T13:42:31.143401Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:42:31.143441Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: EXECUTED MinStep: 1762350151135 MaxStep: 18446744073709551615 Step: 1762350151191 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_2" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/test-topic_2" 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: 7569236240653397741 RawX2: 8589936736 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:42:31.143458Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.143740Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.143744Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state EXECUTED
2025-11-05T13:42:31.143746Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State EXECUTED
2025-11-05T13:42:31.143747Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State EXECUTED FrontTxId 281474976715672
2025-11-05T13:42:31.143750Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TPersQueue::SendEvReadSetAckToSenders
2025-11-05T13:42:31.143752Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from EXECUTED to WAIT_RS_ACKS
2025-11-05T13:42:31.143754Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] PredicateAcks: 0/0
2025-11-05T13:42:31.143756Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-11-05T13:42:31.143757Z node 2 :PQ_TX DEBUG: [TxId: 281474976715672] PredicateAcks: 0/0
2025-11-05T13:42:31.143759Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] add an TxId 281474976715672 to the list for deletion
2025-11-05T13:42:31.143760Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from WAIT_RS_ACKS to DELETING
2025-11-05T13:42:31.143763Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] delete key for TxId 281474976715672
2025-11-05T13:42:31.143767Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.144205Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.144210Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state DELETING
2025-11-05T13:42:31.144211Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State DELETING
2025-11-05T13:42:31.144213Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] delete TxId 281474976715672
2025-11-05T13:42:31.144317Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:42:31.144326Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][test-topic_2] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037895
2025-11-05T13:42:31.144625Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:42:31.144633Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Registered with mediator time cast
2025-11-05T13:42:31.145622Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:42:31.145899Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:42:31.145906Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:21480
2025-11-05T13:42:31.146986Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "test-topic_2" message_group_id: "src" }
2025-11-05T13:42:31.147165Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:31.147174Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 2
2025-11-05T13:42:31.147270Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId:  grpc read done: success: 1 data: init_request { topic: "test-topic_2" message_group_id: "src" }
2025-11-05T13:42:31.147286Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 2 topic: "test-topic_2" message_group_id: "src" from ipv6:[::1]:46902
2025-11-05T13:42:31.147291Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=2 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:46902 proto=v1  topic=test-topic_2 durationSec=0
2025-11-05T13:42:31.147294Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:31.147846Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId:  describe result for acl check
2025-11-05T13:42:31.147872Z node 2 :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:31.147874Z node 2 :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:31.147875Z node 2 :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:31.147886Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236266423202757:2460] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:31.147891Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 2 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:42:31.148131Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:42:31.148146Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236266423202760:2460], now have 1 active actors on pipe
2025-11-05T13:42:31.148333Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic_2' requestId: <none>
2025-11-05T13:42:31.148340Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'test-topic_2' partition 0
2025-11-05T13:42:31.148367Z node 2 :PERSQUEUE INFO: new Cookie src|65879959-eee1a1f2-120d641-914ef8_0 generated for partition 0 topic 'test-topic_2' owner src
2025-11-05T13:42:31.148377Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.148381Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.148392Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.148404Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:31.148419Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic_2' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.148755Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350151148 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:31.148770Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|65879959-eee1a1f2-120d641-914ef8_0" topic: "test-topic_2"
2025-11-05T13:42:31.148828Z :INFO: [/Root] MessageGroupId [src] SessionId [src|65879959-eee1a1f2-120d641-914ef8_0] Write session: close. Timeout = 0 ms
2025-11-05T13:42:31.148832Z :INFO: [/Root] MessageGroupId [src] SessionId [src|65879959-eee1a1f2-120d641-914ef8_0] Write session will now close
2025-11-05T13:42:31.148836Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|65879959-eee1a1f2-120d641-914ef8_0] Write session: aborting
2025-11-05T13:42:31.148903Z :INFO: [/Root] MessageGroupId [src] SessionId [src|65879959-eee1a1f2-120d641-914ef8_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:42:31.148906Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|65879959-eee1a1f2-120d641-914ef8_0] Write session: destroy
2025-11-05T13:42:31.148535Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic_2' requestId: <none>
2025-11-05T13:42:31.148539Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'test-topic_2' partition 0
2025-11-05T13:42:31.148552Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic_2' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.148567Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 2 partition: 0 MaxSeqNo: 0 sessionId: src|65879959-eee1a1f2-120d641-914ef8_0
2025-11-05T13:42:31.149160Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId: src|65879959-eee1a1f2-120d641-914ef8_0 grpc read done: success: 0 data: 
2025-11-05T13:42:31.149165Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|65879959-eee1a1f2-120d641-914ef8_0 grpc read failed
2025-11-05T13:42:31.149169Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|65879959-eee1a1f2-120d641-914ef8_0 grpc closed
2025-11-05T13:42:31.149172Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|65879959-eee1a1f2-120d641-914ef8_0 is DEAD
2025-11-05T13:42:31.149287Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:31.149490Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236266423202760:2460] destroyed
2025-11-05T13:42:31.149499Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:31.149503Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.149506Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.152586Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: try to update token
2025-11-05T13:42:31.152749Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Start write session. Will connect to nodeId: 0
2025-11-05T13:42:31.152900Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: try to update token
2025-11-05T13:42:31.152915Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Start write session. Will connect to nodeId: 0
2025-11-05T13:42:31.153126Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: write to message_group: test-message_group_id
2025-11-05T13:42:31.153147Z :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:31.153152Z :TRACE: [/Root] TRACE_EVENT InitRequest 
2025-11-05T13:42:31.153218Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: write to message_group: test-message_group_id
2025-11-05T13:42:31.153224Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: send init request: init_request { path: "test-topic_2" message_group_id: "test-message_group_id" }
2025-11-05T13:42:31.153226Z :TRACE: [/Root] TRACE_EVENT InitRequest 
2025-11-05T13:42:31.153256Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:42:31.153262Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:42:31.153352Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:31.153360Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 3
2025-11-05T13:42:31.153372Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:31.153373Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 4
2025-11-05T13:42:31.153520Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId:  grpc read done: success: 1 data: init_request { path: "test-topic" message_group_id: "test-message_group_id" }
2025-11-05T13:42:31.153537Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 3 path: "test-topic" message_group_id: "test-message_group_id" from ipv6:[::1]:46902
2025-11-05T13:42:31.153541Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=3 sessionId= userAgent="topic server" ip=ipv6:[::1]:46902 proto=topic  topic=test-topic durationSec=0
2025-11-05T13:42:31.153544Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:31.153563Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId:  grpc read done: success: 1 data: init_request { path: "test-topic_2" message_group_id: "test-message_group_id" }
2025-11-05T13:42:31.153569Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 4 path: "test-topic_2" message_group_id: "test-message_group_id" from ipv6:[::1]:46902
2025-11-05T13:42:31.153570Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=4 sessionId= userAgent="topic server" ip=ipv6:[::1]:46902 proto=topic  topic=test-topic_2 durationSec=0
2025-11-05T13:42:31.153571Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:31.153791Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId:  describe result for acl check
2025-11-05T13:42:31.153922Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId:  describe result for acl check
2025-11-05T13:42:31.153944Z node 2 :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:31.153945Z node 2 :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:31.153946Z node 2 :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:31.153957Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236266423202775:2468] (SourceId=test-message_group_id, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:31.153962Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 3 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:42:31.154093Z node 2 :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:31.154096Z node 2 :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:31.154097Z node 2 :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:31.154100Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236266423202774:2469] (SourceId=test-message_group_id, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:31.154102Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 4 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:42:31.154688Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:31.154699Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350151154 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:31.154710Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session established. Init response: session_id: "test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0"
2025-11-05T13:42:31.154714Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0
2025-11-05T13:42:31.154717Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  MessageGroupId [test-message_group_id] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:42:31.154749Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.000000s
2025-11-05T13:42:31.154757Z :TRACE: [/Root] TRACE_EVENT DescribePartitionRequest  path=/Root/test-topic partition_id=0
2025-11-05T13:42:31.154779Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:31.154783Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350151154 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:42:31.154788Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session established. Init response: session_id: "test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0"
2025-11-05T13:42:31.154789Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0
2025-11-05T13:42:31.154791Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  MessageGroupId [test-message_group_id] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:42:31.154797Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.000000s
2025-11-05T13:42:31.154800Z :TRACE: [/Root] TRACE_EVENT DescribePartitionRequest  path=/Root/test-topic_2 partition_id=0
2025-11-05T13:42:31.154798Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-11-05T13:42:31.154254Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 2, Generation: 1
2025-11-05T13:42:31.154266Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236266423202778:2468], now have 1 active actors on pipe
2025-11-05T13:42:31.154273Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:31.154278Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:31.154291Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:42:31.154295Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236266423202781:2469], now have 1 active actors on pipe
2025-11-05T13:42:31.154296Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic_2' requestId: <none>
2025-11-05T13:42:31.154298Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'test-topic_2' partition 0
2025-11-05T13:42:31.154313Z node 2 :PERSQUEUE INFO: new Cookie test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0 generated for partition 0 topic 'test-topic' owner test-message_group_id
2025-11-05T13:42:31.154321Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.154324Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.154334Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.154344Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:31.154354Z node 2 :PERSQUEUE INFO: new Cookie test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0 generated for partition 0 topic 'test-topic_2' owner test-message_group_id
2025-11-05T13:42:31.154983Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-11-05T13:42:31.154356Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.154358Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.154361Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.154363Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:31.154373Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.154383Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic_2' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.154403Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:31.154405Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:31.154410Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic_2' requestId: <none>
2025-11-05T13:42:31.154412Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'test-topic_2' partition 0
2025-11-05T13:42:31.154421Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.154427Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic_2' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.154438Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 3 partition: 0 MaxSeqNo: 0 sessionId: test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0
2025-11-05T13:42:31.154512Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 4 partition: 0 MaxSeqNo: 0 sessionId: test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0
2025-11-05T13:42:31.155250Z node 2 :PQ_READ_PROXY DEBUG: new Describe partition request
2025-11-05T13:42:31.155266Z node 2 :PQ_READ_PROXY DEBUG: TDescribePartitionActor for request path: "/Root/test-topic"
include_location: true
2025-11-05T13:42:31.155273Z node 2 :PQ_READ_PROXY DEBUG: TDescribePartitionActor[2:7569236266423202785:2472]: Bootstrap
2025-11-05T13:42:31.155577Z node 2 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [2:7569236266423202785:2472]: Request location
2025-11-05T13:42:31.155713Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [2:7569236266423202794:2473] connected; active server actors: 1
2025-11-05T13:42:31.155768Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] addPartitionToResponse tabletId 72075186224037892, partitionId 0, NodeId 2, Generation 1
2025-11-05T13:42:31.155771Z node 2 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [2:7569236266423202785:2472]: Got location
2025-11-05T13:42:31.156085Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [2:7569236266423202794:2473] disconnected; active server actors: 1
2025-11-05T13:42:31.156087Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][test-topic] pipe [2:7569236266423202794:2473] disconnected no session
2025-11-05T13:42:31.182082Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.182092Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.156034Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 2
    generation: 1
  }
}
2025-11-05T13:42:31.186286Z :TRACE: [/Root] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=2 pl_generation=1
2025-11-05T13:42:31.186298Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 2 exists in the endpoint pool.
2025-11-05T13:42:31.186304Z :TRACE: [/Root] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=2 Generation=1
2025-11-05T13:42:31.186308Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  PartitionId [0]  Generation [1] Start write session. Will connect to nodeId: 2
2025-11-05T13:42:31.186851Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  PartitionId [0]  Generation [1] Write session: direct write to partition: 0, generation 1
2025-11-05T13:42:31.186888Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  PartitionId [0]  Generation [1] Write session: send init request: init_request { path: "test-topic" partition_with_generation { generation: 1 } }
2025-11-05T13:42:31.186893Z :TRACE: [/Root] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=1
2025-11-05T13:42:31.186971Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 1, Msg: CANCELLED, Details: , InternalError: 0
2025-11-05T13:42:31.187031Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  PartitionId [0]  Generation [1] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:42:31.186759Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0 grpc read done: success: 0 data: 
2025-11-05T13:42:31.186771Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0 grpc read failed
2025-11-05T13:42:31.186781Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0 grpc closed
2025-11-05T13:42:31.186784Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0 is DEAD
2025-11-05T13:42:31.187003Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:31.187244Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [2:7569236266423202778:2468] destroyed
2025-11-05T13:42:31.187262Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:31.187270Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.187273Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.187286Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:31.187289Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 5
2025-11-05T13:42:31.187309Z node 2 :PQ_READ_PROXY DEBUG: new Describe partition request
2025-11-05T13:42:31.187330Z node 2 :PQ_READ_PROXY DEBUG: TDescribePartitionActor for request path: "/Root/test-topic_2"
include_location: true
2025-11-05T13:42:31.187339Z node 2 :PQ_READ_PROXY DEBUG: TDescribePartitionActor[2:7569236266423202800:2475]: Bootstrap
2025-11-05T13:42:31.187387Z node 2 :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:31.187405Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 5 path: "test-topic" partition_with_generation { generation: 1 } from ipv6:[::1]:46902
2025-11-05T13:42:31.187407Z node 2 :PQ_WRITE_PROXY DEBUG: session request cookie: 5. Disable deduplication for empty producer id
2025-11-05T13:42:31.187412Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=5 sessionId= userAgent="topic server" ip=ipv6:[::1]:46902 proto=topic  topic=test-topic durationSec=0
2025-11-05T13:42:31.187415Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:31.187427Z node 2 :PQ_WRITE_PROXY INFO: session to partition: 0, generation: 1
2025-11-05T13:42:31.188259Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 2
    generation: 1
  }
}
2025-11-05T13:42:31.188268Z :TRACE: [/Root] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=2 pl_generation=1
2025-11-05T13:42:31.188279Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 2 exists in the endpoint pool.
2025-11-05T13:42:31.188286Z :TRACE: [/Root] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=2 Generation=1
2025-11-05T13:42:31.188289Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  PartitionId [0]  Generation [1] Start write session. Will connect to nodeId: 2
2025-11-05T13:42:31.187713Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId:  describe result for acl check
2025-11-05T13:42:31.187750Z node 2 :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:31.187751Z node 2 :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:31.187753Z node 2 :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:31.187759Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236266423202809:2476] (SourceId=, PreferedPartition=0) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:31.187763Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 5 sessionId:  partition: 0 expectedGeneration: 1
2025-11-05T13:42:31.187849Z node 2 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [2:7569236266423202800:2475]: Request location
2025-11-05T13:42:31.187897Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 2, Generation: 1
2025-11-05T13:42:31.187906Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236266423202813:2476], now have 1 active actors on pipe
2025-11-05T13:42:31.187913Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:31.187918Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:31.187938Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][test-topic_2] pipe [2:7569236266423202814:2478] connected; active server actors: 1
2025-11-05T13:42:31.187947Z node 2 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][test-topic_2] addPartitionToResponse tabletId 72075186224037894, partitionId 0, NodeId 2, Generation 1
2025-11-05T13:42:31.187952Z node 2 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [2:7569236266423202800:2475]: Got location
2025-11-05T13:42:31.188093Z node 2 :PERSQUEUE INFO: new Cookie 1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0 generated for partition 0 topic 'test-topic' owner 1e2cbd2e-bbb66fc2-f19e6a85-51d67e91
2025-11-05T13:42:31.188099Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.188103Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.188114Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.188124Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:31.188149Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.188181Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][test-topic_2] pipe [2:7569236266423202814:2478] disconnected; active server actors: 1
2025-11-05T13:42:31.188184Z node 2 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][test-topic_2] pipe [2:7569236266423202814:2478] disconnected no session
2025-11-05T13:42:31.188188Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:31.188191Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:31.188203Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.188217Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 5 partition: 0 MaxSeqNo: 0 sessionId: 1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0
2025-11-05T13:42:31.188560Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  PartitionId [0]  Generation [1] Write session: direct write to partition: 0, generation 1
2025-11-05T13:42:31.188575Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  PartitionId [0]  Generation [1] Write session: send init request: init_request { path: "test-topic_2" partition_with_generation { generation: 1 } }
2025-11-05T13:42:31.188579Z :TRACE: [/Root] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=1
2025-11-05T13:42:31.188632Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 1, Msg: CANCELLED, Details: , InternalError: 0
2025-11-05T13:42:31.188673Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  PartitionId [0]  Generation [1] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:42:31.188906Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:31.188921Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|d0ebc083-bab3aca8-6323f2b4-89ed5883_0]  PartitionId [0]  Generation [1] Write session established. Init response: session_id: "1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0"
2025-11-05T13:42:31.188929Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0
2025-11-05T13:42:31.188933Z :DEBUG: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:42:31.188999Z :DEBUG: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=1, txId=01k9a42dfgcvadrj144gs9211b, WriteCount=1, AckCount=0
2025-11-05T13:42:31.189009Z :DEBUG: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 1 to 1
2025-11-05T13:42:31.189151Z :DEBUG: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:42:31.189158Z :DEBUG: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 1
2025-11-05T13:42:31.188853Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0 grpc read done: success: 0 data: 
2025-11-05T13:42:31.188858Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0 grpc read failed
2025-11-05T13:42:31.188864Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0 grpc closed
2025-11-05T13:42:31.188866Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0 is DEAD
2025-11-05T13:42:31.189007Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:31.189070Z node 2 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:42:31.189072Z node 2 :PQ_WRITE_PROXY DEBUG: new session created cookie 6
2025-11-05T13:42:31.189198Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 6 sessionId:  grpc read done: success: 1 data: init_request { path: "test-topic_2" partition_with_generation { generation: 1 } }
2025-11-05T13:42:31.189225Z node 2 :PQ_WRITE_PROXY INFO: session request cookie: 6 path: "test-topic_2" partition_with_generation { generation: 1 } from ipv6:[::1]:46902
2025-11-05T13:42:31.189227Z node 2 :PQ_WRITE_PROXY DEBUG: session request cookie: 6. Disable deduplication for empty producer id
2025-11-05T13:42:31.189231Z node 2 :PQ_WRITE_PROXY INFO: write session:  cookie=6 sessionId= userAgent="topic server" ip=ipv6:[::1]:46902 proto=topic  topic=test-topic_2 durationSec=0
2025-11-05T13:42:31.189233Z node 2 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:42:31.189235Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236266423202781:2469] destroyed
2025-11-05T13:42:31.189237Z node 2 :PQ_WRITE_PROXY INFO: session to partition: 0, generation: 1
2025-11-05T13:42:31.189248Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:31.189253Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.189255Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.189380Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: 1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:42:31.189475Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Start of a request to KQP for a WriteId. SessionId: ydb://session/3?node_id=2&id=YWY0MGFmYjItZTg5ZmJjNi0yZGZkNDMwYS02NjliZmQxMg== TxId: 01k9a42dfgcvadrj144gs9211b
2025-11-05T13:42:31.189585Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 6 sessionId:  describe result for acl check
2025-11-05T13:42:31.189625Z node 2 :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:31.189631Z node 2 :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:31.189632Z node 2 :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:31.189638Z node 2 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [2:7569236266423202823:2480] (SourceId=, PreferedPartition=0) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:42:31.189642Z node 2 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 6 sessionId:  partition: 0 expectedGeneration: 1
2025-11-05T13:42:31.190088Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:31.190104Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|2c053e06-4dc2dab9-2b7fe5e1-96ab188d_0]  PartitionId [0]  Generation [1] Write session established. Init response: session_id: "99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0"
2025-11-05T13:42:31.190107Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0
2025-11-05T13:42:31.190111Z :DEBUG: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:42:31.190145Z :DEBUG: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=1, txId=01k9a42dfgcvadrj144gs9211b, WriteCount=1, AckCount=0
2025-11-05T13:42:31.190156Z :DEBUG: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 1 to 1
2025-11-05T13:42:31.189746Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 2, Generation: 1
2025-11-05T13:42:31.189750Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [2:7569236266423202821:2476], now have 1 active actors on pipe
2025-11-05T13:42:31.189764Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236266423202826:2480], now have 1 active actors on pipe
2025-11-05T13:42:31.189768Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:42:31.189769Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic_2' requestId: <none>
2025-11-05T13:42:31.189774Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'test-topic_2' partition 0
2025-11-05T13:42:31.189793Z node 2 :PERSQUEUE INFO: new Cookie 99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0 generated for partition 0 topic 'test-topic_2' owner 99ad130-2e958736-c8e61f35-4d85c738
2025-11-05T13:42:31.189798Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.189801Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.189809Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.189819Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:42:31.189836Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic_2' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.189863Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) End of the request to KQP for the WriteId. SessionId: ydb://session/3?node_id=2&id=YWY0MGFmYjItZTg5ZmJjNi0yZGZkNDMwYS02NjliZmQxMg== TxId: 01k9a42dfgcvadrj144gs9211b Status: SUCCESS
2025-11-05T13:42:31.189865Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic_2' requestId: <none>
2025-11-05T13:42:31.189866Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) SessionId: ydb://session/3?node_id=2&id=YWY0MGFmYjItZTg5ZmJjNi0yZGZkNDMwYS02NjliZmQxMg== TxId: 01k9a42dfgcvadrj144gs9211b WriteId: {2, 281474976715673}
2025-11-05T13:42:31.189867Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'test-topic_2' partition 0
2025-11-05T13:42:31.189877Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:31.189879Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:31.189882Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic_2' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.189886Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] partition {0, {2, 281474976715673}, 100000} for WriteId {2, 281474976715673}
2025-11-05T13:42:31.189900Z node 2 :PQ_WRITE_PROXY INFO: session inited cookie: 6 partition: 0 MaxSeqNo: 0 sessionId: 99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0
2025-11-05T13:42:31.190254Z :DEBUG: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:42:31.189937Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] send TEvSubscribeLock for WriteId {2, 281474976715673}
2025-11-05T13:42:31.189958Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.190260Z :DEBUG: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 1
2025-11-05T13:42:31.190280Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 2 Status: STATUS_SUBSCRIBED
2025-11-05T13:42:31.190294Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxWriteInfo: WriteId {2, 281474976715673}, TxId (empty maybe), Status STATUS_UNSPECIFIED
2025-11-05T13:42:31.190302Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] subscribed WriteId {2, 281474976715673}
2025-11-05T13:42:31.190392Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 6 sessionId: 99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:42:31.190441Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP for a WriteId. SessionId: ydb://session/3?node_id=2&id=YWY0MGFmYjItZTg5ZmJjNi0yZGZkNDMwYS02NjliZmQxMg== TxId: 01k9a42dfgcvadrj144gs9211b
2025-11-05T13:42:31.190476Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 2, Generation: 1
2025-11-05T13:42:31.190482Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [2:7569236266423202833:2480], now have 1 active actors on pipe
2025-11-05T13:42:31.190523Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.190599Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of the request to KQP for the WriteId. SessionId: ydb://session/3?node_id=2&id=YWY0MGFmYjItZTg5ZmJjNi0yZGZkNDMwYS02NjliZmQxMg== TxId: 01k9a42dfgcvadrj144gs9211b Status: SUCCESS
2025-11-05T13:42:31.190604Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) SessionId: ydb://session/3?node_id=2&id=YWY0MGFmYjItZTg5ZmJjNi0yZGZkNDMwYS02NjliZmQxMg== TxId: 01k9a42dfgcvadrj144gs9211b WriteId: {2, 281474976715673}
2025-11-05T13:42:31.190616Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic_2' requestId: <none>
2025-11-05T13:42:31.190620Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'test-topic_2' partition 0
2025-11-05T13:42:31.190624Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] partition {0, {2, 281474976715673}, 100000} for WriteId {2, 281474976715673}
2025-11-05T13:42:31.190648Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvSubscribeLock for WriteId {2, 281474976715673}
2025-11-05T13:42:31.190659Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.190668Z node 2 :PERSQUEUE DEBUG: [test-topic:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:42:31.190685Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 2 Status: STATUS_SUBSCRIBED
2025-11-05T13:42:31.190688Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {2, 281474976715673}, TxId (empty maybe), Status STATUS_UNSPECIFIED
2025-11-05T13:42:31.190690Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] subscribed WriteId {2, 281474976715673}
2025-11-05T13:42:31.190724Z node 2 :PERSQUEUE DEBUG: [test-topic:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:42:31.190850Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.190998Z node 2 :PERSQUEUE DEBUG: [test-topic_2:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:42:31.191088Z node 2 :PERSQUEUE DEBUG: [test-topic_2:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:42:31.191129Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateInit] bootstrapping {0, {2, 281474976715673}, 100000} [2:7569236266423202842:2484]
2025-11-05T13:42:31.191318Z node 2 :PERSQUEUE DEBUG: [test-topic_2:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDiskStatusStep
2025-11-05T13:42:31.191402Z node 2 :PERSQUEUE DEBUG: [test-topic_2:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitMetaStep
2025-11-05T13:42:31.191424Z node 2 :PERSQUEUE DEBUG: [test-topic_2:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitInfoRangeStep
2025-11-05T13:42:31.191457Z node 2 :PERSQUEUE DEBUG: [test-topic_2:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataRangeStep
2025-11-05T13:42:31.191471Z node 2 :PERSQUEUE DEBUG: [test-topic_2:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataStep
2025-11-05T13:42:31.191473Z node 2 :PERSQUEUE DEBUG: [test-topic_2:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitEndWriteTimestampStep
2025-11-05T13:42:31.191476Z node 2 :PERSQUEUE INFO: [test-topic_2:{0, {2, 281474976715673}, 100000}:TInitEndWriteTimestampStep] Initializing EndWriteTimestamp skipped because already initialized.
2025-11-05T13:42:31.191478Z node 2 :PERSQUEUE DEBUG: [test-topic_2:{0, {2, 281474976715673}, 100000}:Initializer] Initializing completed.
2025-11-05T13:42:31.191482Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateInit] init complete for topic 'test-topic_2' partition {0, {2, 281474976715673}, 100000} generation 1 [2:7569236266423202842:2484]
2025-11-05T13:42:31.191489Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateInit] SYNC INIT topic test-topic_2 partitition {0, {2, 281474976715673}, 100000} so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:42:31.191493Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Process pending events. Count 0
2025-11-05T13:42:31.191495Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.191497Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.191498Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateInit] bootstrapping {0, {2, 281474976715673}, 100000} [2:7569236266423202837:2482]
2025-11-05T13:42:31.191557Z node 2 :PERSQUEUE INFO: new Cookie b2242d0f-9ba04660-1a6cdce3-a8e0f5f3|976fbd86-c308d632-22b9c074-c6bc8345_0 generated for partition {0, {2, 281474976715673}, 100000} topic 'test-topic_2' owner b2242d0f-9ba04660-1a6cdce3-a8e0f5f3
2025-11-05T13:42:31.191562Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.191565Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.191572Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.191578Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyOwnerOk. Partition: {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:31.191586Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic_2' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.191594Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=2&id=YWY0MGFmYjItZTg5ZmJjNi0yZGZkNDMwYS02NjliZmQxMg== TxId: 01k9a42dfgcvadrj144gs9211b
2025-11-05T13:42:31.191660Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=2&id=YWY0MGFmYjItZTg5ZmJjNi0yZGZkNDMwYS02NjliZmQxMg== TxId: 01k9a42dfgcvadrj144gs9211b Status: SUCCESS
2025-11-05T13:42:31.191674Z node 2 :PERSQUEUE DEBUG: [test-topic:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDiskStatusStep
2025-11-05T13:42:31.191689Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic_2' requestId: <none>
2025-11-05T13:42:31.191692Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'test-topic_2' partition 0
2025-11-05T13:42:31.191708Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic_2' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.191723Z node 2 :PERSQUEUE DEBUG: [test-topic:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitMetaStep
2025-11-05T13:42:31.191740Z node 2 :PERSQUEUE DEBUG: [test-topic:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitInfoRangeStep
2025-11-05T13:42:31.191750Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic_2' requestId: <none>
2025-11-05T13:42:31.191753Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'test-topic_2' partition 0
2025-11-05T13:42:31.191769Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Reserve bytes in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:42:31.191781Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic_2' partition: 0 messageNo: 0  requestId: <none> cookie: 1
2025-11-05T13:42:31.191786Z node 2 :PERSQUEUE DEBUG: [test-topic:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataRangeStep
2025-11-05T13:42:31.191798Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:31.191804Z node 2 :PERSQUEUE DEBUG: [test-topic:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataStep
2025-11-05T13:42:31.191806Z node 2 :PERSQUEUE DEBUG: [test-topic:{0, {2, 281474976715673}, 100000}:Initializer] Start initializing step TInitEndWriteTimestampStep
2025-11-05T13:42:31.191808Z node 2 :PERSQUEUE INFO: [test-topic:{0, {2, 281474976715673}, 100000}:TInitEndWriteTimestampStep] Initializing EndWriteTimestamp skipped because already initialized.
2025-11-05T13:42:31.191809Z node 2 :PERSQUEUE DEBUG: [test-topic:{0, {2, 281474976715673}, 100000}:Initializer] Initializing completed.
2025-11-05T13:42:31.191813Z node 2 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateInit] init complete for topic 'test-topic' partition {0, {2, 281474976715673}, 100000} generation 1 [2:7569236266423202837:2482]
2025-11-05T13:42:31.191816Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateInit] SYNC INIT topic test-topic partitition {0, {2, 281474976715673}, 100000} so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:42:31.191819Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Process pending events. Count 0
2025-11-05T13:42:31.191821Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.191823Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.191824Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic_2' requestId: <none>
2025-11-05T13:42:31.191826Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'test-topic_2' partition 0
2025-11-05T13:42:31.191843Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Write in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:42:31.191850Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: test-topic_2 partition: 0 SourceId: '' SeqNo: 1 partNo : 0 messageNo: 1 size 100 offset: -1
2025-11-05T13:42:31.191860Z node 2 :PERSQUEUE INFO: new Cookie 874b32d3-68b8b63e-273ee896-96e21be1|e87f6bce-d33cbbae-b3a372f5-56f86cb_0 generated for partition {0, {2, 281474976715673}, 100000} topic 'test-topic' owner 874b32d3-68b8b63e-273ee896-96e21be1
2025-11-05T13:42:31.191863Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.191865Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.191869Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.191869Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.191873Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyOwnerOk. Partition: {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:31.191874Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.191878Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.191883Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Start of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=2&id=YWY0MGFmYjItZTg5ZmJjNi0yZGZkNDMwYS02NjliZmQxMg== TxId: 01k9a42dfgcvadrj144gs9211b
2025-11-05T13:42:31.191888Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Topic 'test-topic_2' partition {0, {2, 281474976715673}, 100000} part blob processing sourceId '' seqNo 1 partNo 0
2025-11-05T13:42:31.191926Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) End of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=2&id=YWY0MGFmYjItZTg5ZmJjNi0yZGZkNDMwYS02NjliZmQxMg== TxId: 01k9a42dfgcvadrj144gs9211b Status: SUCCESS
2025-11-05T13:42:31.191936Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:31.191938Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:31.191938Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Topic 'test-topic_2' partition {0, {2, 281474976715673}, 100000} part blob complete sourceId '' seqNo 1 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 167 count 1 nextOffset 1 batches 1
2025-11-05T13:42:31.191944Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.191947Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:42:31.191978Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:31.191979Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:31.191987Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Reserve bytes in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:42:31.191993Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 1
2025-11-05T13:42:31.191995Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Add new write blob: topic 'test-topic_2' partition {0, {2, 281474976715673}, 100000} compactOffset 0,1 HeadOffset 0 endOffset 0 curOffset 1 D0000100000_00000000000000000000_00000_0000000001_00000| size 155 WTime 1762350151191
2025-11-05T13:42:31.192001Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:31.192017Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:31.192021Z node 2 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:42:31.192023Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:42:31.192029Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 100000 offset 0 partNo 0 count 1 size 155
2025-11-05T13:42:31.192031Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Write in transaction. Partition: 0, WriteId: { NodeId: 2 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:42:31.192034Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message topic: test-topic partition: 0 SourceId: '' SeqNo: 1 partNo : 0 messageNo: 1 size 100 offset: -1
2025-11-05T13:42:31.192046Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.192049Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.192057Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Topic 'test-topic' partition {0, {2, 281474976715673}, 100000} part blob processing sourceId '' seqNo 1 partNo 0
2025-11-05T13:42:31.192066Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Topic 'test-topic' partition {0, {2, 281474976715673}, 100000} part blob complete sourceId '' seqNo 1 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 167 count 1 nextOffset 1 batches 1
2025-11-05T13:42:31.192070Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.192092Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Add new write blob: topic 'test-topic' partition {0, {2, 281474976715673}, 100000} compactOffset 0,1 HeadOffset 0 endOffset 0 curOffset 1 D0000100000_00000000000000000000_00000_0000000001_00000| size 155 WTime 1762350151191
2025-11-05T13:42:31.192104Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:31.192111Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 100000 offset 0 partNo 0 count 1 size 155
2025-11-05T13:42:31.192187Z node 2 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 100000 offset 0 count 1 size 155 actorID [2:7569236266423202696:2451]
2025-11-05T13:42:31.192205Z node 2 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 100000 offset 0 count 1 size 155 actorID [2:7569236266423202554:2425]
2025-11-05T13:42:31.192207Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 100000 offset 0 partno 0 count 1 parts 0 size 155
2025-11-05T13:42:31.192217Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037892' partition 100000 offset 0 partno 0 count 1 parts 0 size 155
2025-11-05T13:42:31.192228Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 100 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:31.192238Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:31.192245Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic_2', Partition: {0, {2, 281474976715673}, 100000}, SeqNo: 1, partNo: 0, Offset: 0 is stored on disk
2025-11-05T13:42:31.192255Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 100 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:42:31.192260Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.192262Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.192264Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:31.192268Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic_2' partition: 0 messageNo: 1  requestId: <none> cookie: 1
2025-11-05T13:42:31.192271Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '', Topic: 'test-topic', Partition: {0, {2, 281474976715673}, 100000}, SeqNo: 1, partNo: 0, Offset: 0 is stored on disk
2025-11-05T13:42:31.192274Z node 2 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 1  requestId: <none> cookie: 1
2025-11-05T13:42:31.192280Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:31.192294Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.192296Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.192306Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:42:31.192888Z :DEBUG: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:31.192997Z :DEBUG: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 1 written_in_tx { } } write_statistics { persisting_time { } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-11-05T13:42:31.193005Z :DEBUG: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] OnAck: seqNo=1, txId=01k9a42dfgcvadrj144gs9211b, WriteCount=1, AckCount=1
2025-11-05T13:42:31.193008Z :DEBUG: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 1
2025-11-05T13:42:31.193741Z :DEBUG: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:42:31.193798Z :DEBUG: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Write session got write response: acks { seq_no: 1 written_in_tx { } } write_statistics { persisting_time { } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-11-05T13:42:31.193810Z :DEBUG: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] OnAck: seqNo=1, txId=01k9a42dfgcvadrj144gs9211b, WriteCount=1, AckCount=1
2025-11-05T13:42:31.193814Z :DEBUG: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Write session: acknoledged message 1
2025-11-05T13:42:31.200582Z :INFO: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Write session: close. Timeout 0.000000s
2025-11-05T13:42:31.200597Z :INFO: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Write session will now close
2025-11-05T13:42:31.200604Z :DEBUG: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Write session: aborting
2025-11-05T13:42:31.200805Z :INFO: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Write session: gracefully shut down, all writes complete
2025-11-05T13:42:31.200812Z :DEBUG: [/Root]  TraceId []  SessionId [99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0]  PartitionId [0]  Generation [1] Write session: destroy
2025-11-05T13:42:31.200832Z :INFO: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Write session: close. Timeout 0.000000s
2025-11-05T13:42:31.200834Z :INFO: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Write session will now close
2025-11-05T13:42:31.200837Z :DEBUG: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Write session: aborting
2025-11-05T13:42:31.200855Z :INFO: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Write session: gracefully shut down, all writes complete
2025-11-05T13:42:31.200857Z :DEBUG: [/Root]  TraceId []  SessionId [1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0]  PartitionId [0]  Generation [1] Write session: destroy
2025-11-05T13:42:31.201536Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 6 sessionId: 99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0 grpc read done: success: 0 data: 
2025-11-05T13:42:31.201563Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 6 sessionId: 99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0 grpc read failed
2025-11-05T13:42:31.201570Z node 2 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: 1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0 grpc read done: success: 0 data: 
2025-11-05T13:42:31.201573Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 6 sessionId: 99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0 grpc closed
2025-11-05T13:42:31.201574Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: 1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0 grpc read failed
2025-11-05T13:42:31.201579Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 6 sessionId: 99ad130-2e958736-c8e61f35-4d85c738|29077335-915f8de9-be66d0a3-b75c0e77_0 is DEAD
2025-11-05T13:42:31.201583Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: 1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0 grpc closed
2025-11-05T13:42:31.201586Z node 2 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: 1e2cbd2e-bbb66fc2-f19e6a85-51d67e91|ffa978a0-169069e8-547660dc-966960e9_0 is DEAD
2025-11-05T13:42:31.201741Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:31.201751Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:31.201772Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:31.201779Z node 2 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:42:31.201833Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [2:7569236266423202813:2476] destroyed
2025-11-05T13:42:31.201840Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [2:7569236266423202821:2476] destroyed
2025-11-05T13:42:31.201852Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236266423202826:2480] destroyed
2025-11-05T13:42:31.201853Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:31.201858Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [2:7569236266423202833:2480] destroyed
2025-11-05T13:42:31.201860Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.201862Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.201866Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:31.201870Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.201872Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.201878Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:31.201880Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:42:31.201880Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.201882Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.201885Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.201887Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.202586Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 2 Status: STATUS_NOT_FOUND
2025-11-05T13:42:31.202588Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 2 Status: STATUS_NOT_FOUND
2025-11-05T13:42:31.202597Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {2, 281474976715673}, TxId (empty maybe), Status STATUS_SUBSCRIBED
2025-11-05T13:42:31.202601Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] TxWriteInfo: WriteId {2, 281474976715673}, TxId (empty maybe), Status STATUS_SUBSCRIBED
2025-11-05T13:42:31.202600Z node 2 :PQ_TX INFO: [PQ: 72075186224037894] delete partitions for WriteId {2, 281474976715673} (longTxService lost tx)
2025-11-05T13:42:31.202603Z node 2 :PQ_TX INFO: [PQ: 72075186224037892] delete partitions for WriteId {2, 281474976715673} (longTxService lost tx)
2025-11-05T13:42:31.202605Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvPQ::TEvDeletePartition to partition {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:31.202608Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] send TEvPQ::TEvDeletePartition to partition {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:31.202614Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Handle TEvPQ::TEvDeletePartition
2025-11-05T13:42:31.202617Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Handle TEvPQ::TEvDeletePartition
2025-11-05T13:42:31.202636Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:31.202637Z node 2 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:42:31.202642Z node 2 :PERSQUEUE DEBUG: CacheProxy. Delete blobs from D0000100000(+) to D0000100001(-)
2025-11-05T13:42:31.202642Z node 2 :PERSQUEUE DEBUG: CacheProxy. Delete blobs from D0000100000(+) to D0000100001(-)
2025-11-05T13:42:31.202990Z node 2 :PERSQUEUE DEBUG: Deleting head blob in L1. Partition 100000 offset 0 count 1 actorID [2:7569236266423202696:2451]
2025-11-05T13:42:31.202991Z node 2 :PERSQUEUE DEBUG: Deleting head blob in L1. Partition 100000 offset 0 count 1 actorID [2:7569236266423202554:2425]
2025-11-05T13:42:31.203027Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.203028Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.203035Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.203037Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: {0, {2, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.203123Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvDeletePartitionDone {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:31.203128Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] DeletePartition {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:31.203134Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvUnsubscribeLock for WriteId {2, 281474976715673}
2025-11-05T13:42:31.203138Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPQ::TEvDeletePartitionDone {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:31.203141Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] DeletePartition {0, {2, 281474976715673}, 100000}
2025-11-05T13:42:31.203145Z node 2 :PQ_TX DEBUG: [PQ: 72075186224037892] send TEvUnsubscribeLock for WriteId {2, 281474976715673}
2025-11-05T13:42:31.203149Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.203156Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:42:31.203296Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Removed. Tablet '72075186224037892' partition 100000 offset 0 partno 0 count 1 parts 0
2025-11-05T13:42:31.203309Z node 2 :PERSQUEUE DEBUG: PQ Cache (L2). Removed. Tablet '72075186224037894' partition 100000 offset 0 partno 0 count 1 parts 0
2025-11-05T13:42:31.203389Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.203411Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:42:31.245969Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.245982Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:42:31.282399Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:42:31.282417Z node 2 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
