test_client.cpp: SetPath # /home/runner/.ya/build/build_root/4xc1/003f8c/r3tmp/tmp6CX3tx/pdisk_1.dat
2025-11-05T13:43:35.958297Z node 9 :PQ_READ_PROXY DEBUG: Direct read cache: : Created
2025-11-05T13:43:35.997511Z node 9 :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:43:36.006822Z node 9 :IMPORT WARN: Table profiles were not loaded
2025-11-05T13:43:36.010101Z node 9 :CONFIGS_DISPATCHER ERROR: Notification cookie mismatch for subscription [9:7569236540751559142:2081] 1762350215924506 != 1762350215924509
TServer::EnableGrpc on GrpcPort 24963, node 9
2025-11-05T13:43:36.047875Z node 9 :NET_CLASSIFIER WARN: distributable config is empty, broken or outdated, will use file: /home/runner/.ya/build/build_root/4xc1/003f8c/r3tmp/yandexVoZpWF.tmp
2025-11-05T13:43:36.047892Z node 9 :NET_CLASSIFIER WARN: will try to initialize from file: /home/runner/.ya/build/build_root/4xc1/003f8c/r3tmp/yandexVoZpWF.tmp
2025-11-05T13:43:36.047968Z node 9 :NET_CLASSIFIER WARN: successfully initialized from file: /home/runner/.ya/build/build_root/4xc1/003f8c/r3tmp/yandexVoZpWF.tmp
2025-11-05T13:43:36.047996Z node 9 :NET_CLASSIFIER ERROR: got bad distributable configuration
2025-11-05T13:43:36.049178Z INFO: TTestServer started on Port 22998 GrpcPort 24963
2025-11-05T13:43:36.049718Z node 9 :HIVE WARN: HIVE#72057594037968897 Node(9, (0,0,0,0)) VolatileState: Unknown -> Disconnected
2025-11-05T13:43:36.049747Z node 9 :HIVE WARN: HIVE#72057594037968897 Node(9, (0,0,0,0)) VolatileState: Disconnected -> Connecting
2025-11-05T13:43:36.061647Z node 9 :HIVE WARN: HIVE#72057594037968897 Node(9, (0,0,0,0)) VolatileState: Connecting -> Connected
TClient is connected to server localhost:22998
PQClient connected to localhost:24963
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:43:36.130299Z node 9 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpAlterSubDomain, opId: 281474976715657:0, at schemeshard:  72057594046644480
waiting...
2025-11-05T13:43:36.132749Z node 9 :FLAT_TX_SCHEMESHARD WARN: NotifyTxCompletion, unknown transaction, txId: 281474976715657, at schemeshard: 72057594046644480
waiting...
waiting...
2025-11-05T13:43:36.145517Z node 9 :FLAT_TX_SCHEMESHARD WARN: Operation part proposed ok, but propose itself is undo unsafe, suboperation type: ESchemeOpCreateTable, opId: 281474976715659:0, at schemeshard:  72057594046644480
waiting...
2025-11-05T13:43:36.182599Z node 9 :FLAT_TX_SCHEMESHARD WARN: NotifyTxCompletion, unknown transaction, txId: 281474976715660, at schemeshard: 72057594046644480
waiting...
2025-11-05T13:43:36.200260Z node 9 :FLAT_TX_SCHEMESHARD WARN: NotifyTxCompletion, unknown transaction, txId: 281474976715661, at schemeshard: 72057594046644480
2025-11-05T13:43:36.504170Z node 9 :KQP_COMPILE_ACTOR ERROR: Compilation failed, self: [9:7569236545046527208: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:43:36.504741Z node 9 :KQP_SESSION WARN: SessionId: ydb://session/3?node_id=9&id=NGVmY2ViOWItM2I4NzEyMC1kNTY4ZGZlYy0yZmVjNDYxZg==, ActorId: [9:7569236545046527205:2314], ActorState: ExecuteState, TraceId: 01k9a44d9kdfk15m1z06wyyqcs, ReplyQueryCompileError, status SCHEME_ERROR remove tx with tx_id: 
2025-11-05T13:43:36.504880Z node 9 :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:43:36.512518Z node 9 :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:43:36.581311Z node 9 :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:43:36.613102Z node 9 :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 [9:7569236545046527485:2566] 
2025-11-05T13:43:36.947605Z node 9 :TX_CONVEYOR ERROR: fline=service.h:53;problem=unexpected event for task executor;ev_type=NActors::TEvents::TEvWakeup;
=== CheckClustersList. Ok
2025-11-05T13:43:41.717813Z :WriteToTopic_Demo_22_RestartBeforeCommit INFO: TTopicSdkTestSetup started
2025-11-05T13:43:41.720533Z node 9 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:43:41.723964Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037893][] pipe [9:7569236566521364274:2736] connected; active server actors: 1
2025-11-05T13:43:41.723982Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:43:41.724086Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:43:41.724089Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] updating configuration. Deleted partitions []. Added partitions [0]
2025-11-05T13:43:41.724153Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:43:41.724154Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:43:41.724175Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] BALANCER INIT DONE for test-topic: (0, 72075186224037892) 
2025-11-05T13:43:41.724198Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] doesn't have tx info
2025-11-05T13:43:41.724202Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-11-05T13:43:41.724204Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] no config, start with empty partitions and default config
2025-11-05T13:43:41.724208Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:43:41.724215Z node 9 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:43:41.724224Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037892] doesn't have tx writes info
2025-11-05T13:43:41.724285Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [9:7569236566521364271:2734], now have 1 active actors on pipe
2025-11-05T13:43:41.724290Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [9:7569236566521364300:2422], now have 1 active actors on pipe
2025-11-05T13:43:41.724297Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72075186224037892, NodeId 9, Generation 1
2025-11-05T13:43:41.724304Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] TEvClientConnected TabletId 72057594046644480, NodeId 9, Generation 2
2025-11-05T13:43:41.724448Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236540751559480 RawX2: 38654707810 } 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:43:41.724475Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] Propose TxId 281474976715671, WriteId (empty maybe)
2025-11-05T13:43:41.724483Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state UNKNOWN
2025-11-05T13:43:41.724485Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State UNKNOWN
2025-11-05T13:43:41.724489Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] schedule TEvProposeTransactionResult(PREPARED)
2025-11-05T13:43:41.724493Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from UNKNOWN to PREPARING
2025-11-05T13:43:41.724499Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:43:41.724558Z node 9 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PREPARED MinStep: 1762350221765 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: 7569236540751559480 RawX2: 38654707810 } Partitions { }
2025-11-05T13:43:41.724580Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:41.724919Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:41.724934Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARING
2025-11-05T13:43:41.724936Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARING
2025-11-05T13:43:41.724938Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARING to PREPARED
2025-11-05T13:43:41.725123Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037892 TxId: 281474976715671
2025-11-05T13:43:41.725350Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [9:7569236566521364313:2759], now have 1 active actors on pipe
2025-11-05T13:43:41.725403Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976715671 AckTo { RawX1: 0 RawX2: 0 } } Step: 1762350221772 MediatorID: 72057594046382081 TabletID: 72075186224037892
2025-11-05T13:43:41.725412Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PREPARED
2025-11-05T13:43:41.725413Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PREPARED
2025-11-05T13:43:41.725416Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PREPARED to PLANNING
2025-11-05T13:43:41.725420Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] PlanStep 1762350221772, PlanTxId 281474976715671
2025-11-05T13:43:41.725437Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:43:41.725502Z node 9 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: PLANNED MinStep: 1762350221765 MaxStep: 18446744073709551615 Step: 1762350221772 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: 7569236540751559480 RawX2: 38654707810 } Partitions { }
2025-11-05T13:43:41.725522Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:41.725668Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:41.725678Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state PLANNING
2025-11-05T13:43:41.725679Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State PLANNING
2025-11-05T13:43:41.725682Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNING to PLANNED
2025-11-05T13:43:41.725684Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxQueue.size 1
2025-11-05T13:43:41.725687Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] New ExecStep 1762350221772, ExecTxId 281474976715671
2025-11-05T13:43:41.725821Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from PLANNED to CALCULATING
2025-11-05T13:43:41.725823Z node 9 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:43:41.725835Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-11-05T13:43:41.725866Z node 9 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:43:41.725909Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] bootstrapping 0 [9:7569236566521364319:2426]
2025-11-05T13:43:41.726073Z node 9 :PERSQUEUE DEBUG: [test-topic:0:Initializer] Initializing completed.
2025-11-05T13:43:41.726079Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037892, Partition: 0, State: StateInit] init complete for topic 'test-topic' partition 0 generation 1 [9:7569236566521364319:2426]
2025-11-05T13:43:41.726083Z node 9 :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:43:41.726136Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-11-05T13:43:41.726143Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.726156Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.726160Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:43:41.726161Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.726162Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.726163Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Handle TEvPQ::TEvProposePartitionConfigResult Step 1762350221772, TxId 281474976715671, Partition 0
2025-11-05T13:43:41.726163Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:43:41.726165Z node 9 :PQ_TX DEBUG: [TxId: 281474976715671] Handle TEvProposePartitionConfigResult
2025-11-05T13:43:41.726168Z node 9 :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:43:41.726168Z node 9 :PQ_TX DEBUG: [TxId: 281474976715671] Partition responses 1/1
2025-11-05T13:43:41.726170Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATING
2025-11-05T13:43:41.726172Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATING
2025-11-05T13:43:41.726175Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATING FrontTxId 281474976715671
2025-11-05T13:43:41.726178Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:43:41.726183Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATING to CALCULATED
2025-11-05T13:43:41.726187Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:43:41.726254Z node 9 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: CALCULATED MinStep: 1762350221765 MaxStep: 18446744073709551615 Step: 1762350221772 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: 7569236540751559480 RawX2: 38654707810 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:43:41.726275Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:41.726435Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:41.726440Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state CALCULATED
2025-11-05T13:43:41.726441Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State CALCULATED
2025-11-05T13:43:41.726443Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State CALCULATED FrontTxId 281474976715671
2025-11-05T13:43:41.726444Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from CALCULATED to WAIT_RS
2025-11-05T13:43:41.726452Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-11-05T13:43:41.726454Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveParticipantsDecision 1
2025-11-05T13:43:41.726460Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS to EXECUTING
2025-11-05T13:43:41.726461Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 0, Expected 1
2025-11-05T13:43:41.726473Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1762350221772, TxId 281474976715671
2025-11-05T13:43:41.726481Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.726483Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.726505Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.726537Z node 9 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:43:41.726860Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] Handle TEvPQ::TEvTxCommitDone Step 1762350221772, TxId 281474976715671, Partition 0
2025-11-05T13:43:41.726865Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:43:41.726869Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTING
2025-11-05T13:43:41.726870Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTING
2025-11-05T13:43:41.726870Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.726872Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTING FrontTxId 281474976715671
2025-11-05T13:43:41.726872Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.726874Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Received 1, Expected 1
2025-11-05T13:43:41.726878Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId: 281474976715671 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-11-05T13:43:41.726885Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] complete TxId 281474976715671
2025-11-05T13:43:41.726928Z node 9 :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:43:41.726944Z node 9 :PERSQUEUE NOTICE: [PQ: 72075186224037892] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:43:41.726951Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] delete partitions for TxId 281474976715671
2025-11-05T13:43:41.726953Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTING to EXECUTED
2025-11-05T13:43:41.726956Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] write key for TxId 281474976715671
2025-11-05T13:43:41.726999Z node 9 :PQ_TX DEBUG: [TxId: 281474976715671] save tx TxId: 281474976715671 State: EXECUTED MinStep: 1762350221765 MaxStep: 18446744073709551615 Step: 1762350221772 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: 7569236540751559480 RawX2: 38654707810 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:43:41.727023Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:41.727453Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:43:41.727527Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:43:41.727617Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:41.727626Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state EXECUTED
2025-11-05T13:43:41.727628Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State EXECUTED
2025-11-05T13:43:41.727631Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671 State EXECUTED FrontTxId 281474976715671
2025-11-05T13:43:41.727635Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TPersQueue::SendEvReadSetAckToSenders
2025-11-05T13:43:41.727638Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from EXECUTED to WAIT_RS_ACKS
2025-11-05T13:43:41.727641Z node 9 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:43:41.727643Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-11-05T13:43:41.727644Z node 9 :PQ_TX DEBUG: [TxId: 281474976715671] PredicateAcks: 0/0
2025-11-05T13:43:41.727647Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] add an TxId 281474976715671 to the list for deletion
2025-11-05T13:43:41.727649Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] TxId 281474976715671 moved from WAIT_RS_ACKS to DELETING
2025-11-05T13:43:41.727653Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] delete key for TxId 281474976715671
2025-11-05T13:43:41.727662Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:41.727797Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:41.727805Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Try execute txs with state DELETING
2025-11-05T13:43:41.727806Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] TxId 281474976715671, State DELETING
2025-11-05T13:43:41.727809Z node 9 :PQ_TX INFO: [PQ: 72075186224037892] delete TxId 281474976715671
2025-11-05T13:43:41.728180Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:43:41.728412Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:43:41.728417Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:24963
2025-11-05T13:43:41.729466Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "test-topic" message_group_id: "src" }
2025-11-05T13:43:41.729580Z node 9 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:43:41.729590Z node 9 :PQ_WRITE_PROXY DEBUG: new session created cookie 1
2025-11-05T13:43:41.729682Z node 9 :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:43:41.729704Z node 9 :PQ_WRITE_PROXY INFO: session request cookie: 1 topic: "test-topic" message_group_id: "src" from ipv6:[::1]:50662
2025-11-05T13:43:41.729711Z node 9 :PQ_WRITE_PROXY INFO: write session:  cookie=1 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:50662 proto=v1  topic=test-topic durationSec=0
2025-11-05T13:43:41.729714Z node 9 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:43:41.730304Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId:  describe result for acl check
2025-11-05T13:43:41.730347Z node 9 :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:43:41.730352Z node 9 :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:43:41.730353Z node 9 :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:43:41.730365Z node 9 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [9:7569236566521364363:2434] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:43:41.730370Z node 9 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 1 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:43:41.730476Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037892, NodeId 9, Generation: 1
2025-11-05T13:43:41.730489Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server connected, pipe [9:7569236566521364366:2434], now have 1 active actors on pipe
2025-11-05T13:43:41.730499Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:43:41.730504Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:43:41.730536Z node 9 :PERSQUEUE INFO: new Cookie src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0 generated for partition 0 topic 'test-topic' owner src
2025-11-05T13:43:41.730548Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.730552Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.730566Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.730581Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:43:41.730604Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.730637Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'test-topic' requestId: <none>
2025-11-05T13:43:41.730654Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] got client message batch for topic 'test-topic' partition 0
2025-11-05T13:43:41.730675Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'test-topic' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.730693Z node 9 :PQ_WRITE_PROXY INFO: session inited cookie: 1 partition: 0 MaxSeqNo: 0 sessionId: src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0
2025-11-05T13:43:41.731108Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350221731 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:43:41.731131Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0" topic: "test-topic"
2025-11-05T13:43:41.737484Z :INFO: [/Root] MessageGroupId [src] SessionId [src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0] Write session: close. Timeout = 0 ms
2025-11-05T13:43:41.737504Z :INFO: [/Root] MessageGroupId [src] SessionId [src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0] Write session will now close
2025-11-05T13:43:41.737512Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0] Write session: aborting
2025-11-05T13:43:41.737724Z :INFO: [/Root] MessageGroupId [src] SessionId [src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:43:41.737730Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0] Write session: destroy
2025-11-05T13:43:41.738183Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 1 sessionId: src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0 grpc read done: success: 0 data: 
2025-11-05T13:43:41.738196Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0 grpc read failed
2025-11-05T13:43:41.738206Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0 grpc closed
2025-11-05T13:43:41.738209Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 1 sessionId: src|f9096f3e-d43c2523-92b8a40d-a0914d2d_0 is DEAD
2025-11-05T13:43:41.738418Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037892 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:43:41.738479Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892] server disconnected, pipe [9:7569236566521364366:2434] destroyed
2025-11-05T13:43:41.738492Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:43:41.738500Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.738503Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.741961Z :WriteToTopic_Demo_22_RestartBeforeCommit INFO: Topic created
2025-11-05T13:43:41.754833Z node 9 :PQ_READ_PROXY DEBUG: new create topic request
2025-11-05T13:43:41.756008Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:43:41.756027Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:43:41.758022Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][] pipe [9:7569236566521364404:2798] connected; active server actors: 1
2025-11-05T13:43:41.758029Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:43:41.758107Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Registered with mediator time cast
2025-11-05T13:43:41.758125Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] updating configuration. Deleted partitions []. Added partitions [0]
2025-11-05T13:43:41.758169Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:43:41.758200Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] doesn't have tx info
2025-11-05T13:43:41.758208Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] PlanStep 0, PlanTxId 0, ExecStep 0, ExecTxId 0
2025-11-05T13:43:41.758210Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] no config, start with empty partitions and default config
2025-11-05T13:43:41.758214Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:43:41.758218Z node 9 :PERSQUEUE NOTICE: [PQ: 72075186224037894] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:43:41.758223Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037894] doesn't have tx writes info
2025-11-05T13:43:41.758260Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037895
2025-11-05T13:43:41.758261Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236566521364403:2797], now have 1 active actors on pipe
2025-11-05T13:43:41.758278Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] BALANCER INIT DONE for topic_A: (0, 72075186224037894) 
2025-11-05T13:43:41.758312Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] TEvClientConnected TabletId 72075186224037894, NodeId 9, Generation 1
2025-11-05T13:43:41.758318Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] TEvClientConnected TabletId 72057594046644480, NodeId 9, Generation 2
2025-11-05T13:43:41.758351Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236540751559480 RawX2: 38654707810 } 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: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" 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:43:41.758378Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] Propose TxId 281474976715672, WriteId (empty maybe)
2025-11-05T13:43:41.758385Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state UNKNOWN
2025-11-05T13:43:41.758387Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State UNKNOWN
2025-11-05T13:43:41.758391Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] schedule TEvProposeTransactionResult(PREPARED)
2025-11-05T13:43:41.758394Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from UNKNOWN to PREPARING
2025-11-05T13:43:41.758399Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:43:41.758452Z node 9 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: PREPARED MinStep: 1762350221779 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: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" 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: 7569236540751559480 RawX2: 38654707810 } Partitions { }
2025-11-05T13:43:41.758474Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:41.758479Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236566521364442:2448], now have 1 active actors on pipe
2025-11-05T13:43:41.758669Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:41.758681Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PREPARING
2025-11-05T13:43:41.758683Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PREPARING
2025-11-05T13:43:41.758686Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PREPARING to PREPARED
2025-11-05T13:43:41.758866Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransactionAttach TabletId: 72075186224037894 TxId: 281474976715672
2025-11-05T13:43:41.758980Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236566521364454:2827], now have 1 active actors on pipe
2025-11-05T13:43:41.758998Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvTxProcessing::TEvPlanStep Transactions { TxId: 281474976715672 AckTo { RawX1: 0 RawX2: 0 } } Step: 1762350221807 MediatorID: 72057594046382081 TabletID: 72075186224037894
2025-11-05T13:43:41.759005Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PREPARED
2025-11-05T13:43:41.759007Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PREPARED
2025-11-05T13:43:41.759009Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PREPARED to PLANNING
2025-11-05T13:43:41.759013Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] PlanStep 1762350221807, PlanTxId 281474976715672
2025-11-05T13:43:41.759016Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:43:41.759076Z node 9 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: PLANNED MinStep: 1762350221779 MaxStep: 18446744073709551615 Step: 1762350221807 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: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" 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: 7569236540751559480 RawX2: 38654707810 } Partitions { }
2025-11-05T13:43:41.759095Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:41.759239Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:41.759250Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state PLANNING
2025-11-05T13:43:41.759252Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State PLANNING
2025-11-05T13:43:41.759267Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PLANNING to PLANNED
2025-11-05T13:43:41.759274Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxQueue.size 1
2025-11-05T13:43:41.759277Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] New ExecStep 1762350221807, ExecTxId 281474976715672
2025-11-05T13:43:41.759395Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:43:41.759399Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from PLANNED to CALCULATING
2025-11-05T13:43:41.759410Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateInit] HandleOnInit TEvPQ::TEvProposePartitionConfig
2025-11-05T13:43:41.759440Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:43:41.759499Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] bootstrapping 0 [9:7569236566521364460:2452]
2025-11-05T13:43:41.759701Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Initializing completed.
2025-11-05T13:43:41.759710Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] init complete for topic 'topic_A' partition 0 generation 1 [9:7569236566521364460:2452]
2025-11-05T13:43:41.759715Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateInit] SYNC INIT topic topic_A partitition 0 so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:43:41.759796Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Process pending events. Count 1
2025-11-05T13:43:41.759804Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.759820Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.759826Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:43:41.759826Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvProposePartitionConfigResult Step 1762350221807, TxId 281474976715672, Partition 0
2025-11-05T13:43:41.759828Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.759829Z node 9 :PQ_TX DEBUG: [TxId: 281474976715672] Handle TEvProposePartitionConfigResult
2025-11-05T13:43:41.759830Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.759831Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still pending for come commits
2025-11-05T13:43:41.759831Z node 9 :PQ_TX DEBUG: [TxId: 281474976715672] Partition responses 1/1
2025-11-05T13:43:41.759833Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state CALCULATING
2025-11-05T13:43:41.759835Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State CALCULATING
2025-11-05T13:43:41.759837Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 user test-consumer readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:43:41.759837Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State CALCULATING FrontTxId 281474976715672
2025-11-05T13:43:41.759840Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 1, Expected 1
2025-11-05T13:43:41.759843Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from CALCULATING to CALCULATED
2025-11-05T13:43:41.759846Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:43:41.759902Z node 9 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: CALCULATED MinStep: 1762350221779 MaxStep: 18446744073709551615 Step: 1762350221807 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: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" 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: 7569236540751559480 RawX2: 38654707810 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:43:41.759921Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:41.760173Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:41.760182Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state CALCULATED
2025-11-05T13:43:41.760184Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State CALCULATED
2025-11-05T13:43:41.760186Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State CALCULATED FrontTxId 281474976715672
2025-11-05T13:43:41.760189Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from CALCULATED to WAIT_RS
2025-11-05T13:43:41.760199Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] Send TEvTxProcessing::TEvReadSet to 0 receivers. Wait TEvTxProcessing::TEvReadSet from 0 senders.
2025-11-05T13:43:41.760202Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] HaveParticipantsDecision 1
2025-11-05T13:43:41.760210Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from WAIT_RS to EXECUTING
2025-11-05T13:43:41.760214Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Handle TEvPQ::TEvTxCommit Step 1762350221807, TxId 281474976715672
2025-11-05T13:43:41.760216Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 0, Expected 1
2025-11-05T13:43:41.760217Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.760219Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.760241Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.760280Z node 9 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:43:41.760660Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] Handle TEvPQ::TEvTxCommitDone Step 1762350221807, TxId 281474976715672, Partition 0
2025-11-05T13:43:41.760660Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:43:41.760665Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.760667Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state EXECUTING
2025-11-05T13:43:41.760667Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.760668Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State EXECUTING
2025-11-05T13:43:41.760670Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State EXECUTING FrontTxId 281474976715672
2025-11-05T13:43:41.760672Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Received 1, Expected 1
2025-11-05T13:43:41.760676Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId: 281474976715672 send TEvPersQueue::TEvProposeTransactionResult(COMPLETE)
2025-11-05T13:43:41.760682Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] complete TxId 281474976715672
2025-11-05T13:43:41.760721Z node 9 :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: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" 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:43:41.760737Z node 9 :PERSQUEUE NOTICE: [PQ: 72075186224037894] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:43:41.760747Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] delete partitions for TxId 281474976715672
2025-11-05T13:43:41.760749Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from EXECUTING to EXECUTED
2025-11-05T13:43:41.760752Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] write key for TxId 281474976715672
2025-11-05T13:43:41.760789Z node 9 :PQ_TX DEBUG: [TxId: 281474976715672] save tx TxId: 281474976715672 State: EXECUTED MinStep: 1762350221779 MaxStep: 18446744073709551615 Step: 1762350221807 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: "topic_A" Version: 0 RequireAuthWrite: true RequireAuthRead: true FormatVersion: 0 Codecs { } TopicPath: "/Root/topic_A" 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: 7569236540751559480 RawX2: 38654707810 } Partitions { Partition { PartitionId: 0 } }
2025-11-05T13:43:41.760813Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:41.761075Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:41.761084Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state EXECUTED
2025-11-05T13:43:41.761086Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State EXECUTED
2025-11-05T13:43:41.761087Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672 State EXECUTED FrontTxId 281474976715672
2025-11-05T13:43:41.761089Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TPersQueue::SendEvReadSetAckToSenders
2025-11-05T13:43:41.761091Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from EXECUTED to WAIT_RS_ACKS
2025-11-05T13:43:41.761093Z node 9 :PQ_TX DEBUG: [TxId: 281474976715672] PredicateAcks: 0/0
2025-11-05T13:43:41.761095Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] HaveAllRecipientsReceive 1, AllSupportivePartitionsHaveBeenDeleted 1
2025-11-05T13:43:41.761096Z node 9 :PQ_TX DEBUG: [TxId: 281474976715672] PredicateAcks: 0/0
2025-11-05T13:43:41.761098Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] add an TxId 281474976715672 to the list for deletion
2025-11-05T13:43:41.761100Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715672 moved from WAIT_RS_ACKS to DELETING
2025-11-05T13:43:41.761102Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] delete key for TxId 281474976715672
2025-11-05T13:43:41.761107Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:41.761111Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037893][test-topic] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037893
2025-11-05T13:43:41.761121Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] Discovered subdomain [OwnerId: 72057594046644480, LocalPathId: 1] state, outOfSpace = 0 at RB 72075186224037895
2025-11-05T13:43:41.761127Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Registered with mediator time cast
2025-11-05T13:43:41.761145Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037892] Registered with mediator time cast
2025-11-05T13:43:41.761204Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:41.761211Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Try execute txs with state DELETING
2025-11-05T13:43:41.761212Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxId 281474976715672, State DELETING
2025-11-05T13:43:41.761214Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] delete TxId 281474976715672
2025-11-05T13:43:41.761615Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: try to update token
2025-11-05T13:43:41.761871Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session: Do CDS request
2025-11-05T13:43:41.761877Z :INFO: [/Root] MessageGroupId [src] SessionId [] Start write session. Will connect to endpoint: localhost:24963
2025-11-05T13:43:41.767040Z node 9 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:43:41.767054Z node 9 :PQ_WRITE_PROXY DEBUG: new session created cookie 2
2025-11-05T13:43:41.769545Z :DEBUG: [/Root] MessageGroupId [src] SessionId [] Write session: send init request: init_request { topic: "topic_A" message_group_id: "src" }
2025-11-05T13:43:41.769805Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId:  grpc read done: success: 1 data: init_request { topic: "topic_A" message_group_id: "src" }
2025-11-05T13:43:41.769838Z node 9 :PQ_WRITE_PROXY INFO: session request cookie: 2 topic: "topic_A" message_group_id: "src" from ipv6:[::1]:50662
2025-11-05T13:43:41.769854Z node 9 :PQ_WRITE_PROXY INFO: write session:  cookie=2 sessionId= userAgent="pqv1 server" ip=ipv6:[::1]:50662 proto=v1  topic=topic_A durationSec=0
2025-11-05T13:43:41.769863Z node 9 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:43:41.770323Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId:  describe result for acl check
2025-11-05T13:43:41.770360Z node 9 :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:43:41.770365Z node 9 :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:43:41.770367Z node 9 :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:43:41.770378Z node 9 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [9:7569236566521364495:2460] (SourceId=src, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:43:41.770382Z node 9 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 2 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:43:41.770566Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236566521364498:2460], now have 1 active actors on pipe
2025-11-05T13:43:41.770570Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 9, Generation: 1
2025-11-05T13:43:41.770578Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.770584Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.770610Z node 9 :PERSQUEUE INFO: new Cookie src|da152e0a-cca58a48-f04ed5ee-308256ab_0 generated for partition 0 topic 'topic_A' owner src
2025-11-05T13:43:41.770628Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.770632Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.770642Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.770659Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:43:41.770689Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.770721Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.770731Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.770753Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.770777Z node 9 :PQ_WRITE_PROXY INFO: session inited cookie: 2 partition: 0 MaxSeqNo: 0 sessionId: src|da152e0a-cca58a48-f04ed5ee-308256ab_0
2025-11-05T13:43:41.771021Z :INFO: [/Root] MessageGroupId [src] SessionId [] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350221771 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:43:41.771053Z :INFO: [/Root] MessageGroupId [src] SessionId [] Write session established. Init response: session_id: "src|da152e0a-cca58a48-f04ed5ee-308256ab_0" topic: "topic_A"
2025-11-05T13:43:41.771134Z :INFO: [/Root] MessageGroupId [src] SessionId [src|da152e0a-cca58a48-f04ed5ee-308256ab_0] Write session: close. Timeout = 0 ms
2025-11-05T13:43:41.771143Z :INFO: [/Root] MessageGroupId [src] SessionId [src|da152e0a-cca58a48-f04ed5ee-308256ab_0] Write session will now close
2025-11-05T13:43:41.771150Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|da152e0a-cca58a48-f04ed5ee-308256ab_0] Write session: aborting
2025-11-05T13:43:41.771280Z :INFO: [/Root] MessageGroupId [src] SessionId [src|da152e0a-cca58a48-f04ed5ee-308256ab_0] Write session: gracefully shut down, all writes complete
2025-11-05T13:43:41.771285Z :DEBUG: [/Root] MessageGroupId [src] SessionId [src|da152e0a-cca58a48-f04ed5ee-308256ab_0] Write session: destroy
2025-11-05T13:43:41.771468Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 2 sessionId: src|da152e0a-cca58a48-f04ed5ee-308256ab_0 grpc read done: success: 0 data: 
2025-11-05T13:43:41.771474Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|da152e0a-cca58a48-f04ed5ee-308256ab_0 grpc read failed
2025-11-05T13:43:41.771480Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|da152e0a-cca58a48-f04ed5ee-308256ab_0 grpc closed
2025-11-05T13:43:41.771482Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 2 sessionId: src|da152e0a-cca58a48-f04ed5ee-308256ab_0 is DEAD
2025-11-05T13:43:41.771611Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:43:41.771809Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [9:7569236566521364498:2460] destroyed
2025-11-05T13:43:41.771820Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:43:41.771825Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.771826Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.775437Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: try to update token
2025-11-05T13:43:41.775577Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Start write session. Will connect to nodeId: 0
2025-11-05T13:43:41.775761Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: write to message_group: test-message_group_id
2025-11-05T13:43:41.775831Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: send init request: init_request { path: "topic_A" producer_id: "test-message_group_id" message_group_id: "test-message_group_id" }
2025-11-05T13:43:41.775834Z :TRACE: [/Root] TRACE_EVENT InitRequest 
2025-11-05T13:43:41.775885Z node 9 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:43:41.775897Z node 9 :PQ_WRITE_PROXY DEBUG: new session created cookie 3
2025-11-05T13:43:41.775941Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:43:41.776007Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId:  grpc read done: success: 1 data: init_request { path: "topic_A" producer_id: "test-message_group_id" message_group_id: "test-message_group_id" }
2025-11-05T13:43:41.776031Z node 9 :PQ_WRITE_PROXY INFO: session request cookie: 3 path: "topic_A" producer_id: "test-message_group_id" message_group_id: "test-message_group_id" from ipv6:[::1]:50662
2025-11-05T13:43:41.776038Z node 9 :PQ_WRITE_PROXY INFO: write session:  cookie=3 sessionId= userAgent="topic server" ip=ipv6:[::1]:50662 proto=topic  topic=topic_A durationSec=0
2025-11-05T13:43:41.776041Z node 9 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:43:41.776249Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId:  describe result for acl check
2025-11-05T13:43:41.776290Z node 9 :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:43:41.776295Z node 9 :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:43:41.776297Z node 9 :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:43:41.776309Z node 9 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [9:7569236566521364509:2467] (SourceId=test-message_group_id, PreferedPartition=(NULL)) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:43:41.776313Z node 9 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 3 sessionId:  partition: 0 expectedGeneration: (NULL)
2025-11-05T13:43:41.776419Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 9, Generation: 1
2025-11-05T13:43:41.776426Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236566521364512:2467], now have 1 active actors on pipe
2025-11-05T13:43:41.776433Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.776439Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.776459Z node 9 :PERSQUEUE INFO: new Cookie test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0 generated for partition 0 topic 'topic_A' owner test-message_group_id
2025-11-05T13:43:41.776466Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.776474Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.776482Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.776496Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:43:41.776521Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.776549Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.776557Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.776575Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.776594Z node 9 :PQ_WRITE_PROXY INFO: session inited cookie: 3 partition: 0 MaxSeqNo: 0 sessionId: test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0
2025-11-05T13:43:41.776758Z :DEBUG: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:43:41.776770Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1762350221776 BytesWritten: 0 MessagesWritten: 0 BytesWrittenCompressed: 0 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:43:41.776795Z :INFO: [/Root]  TraceId []  SessionId []  MessageGroupId [test-message_group_id] Write session established. Init response: session_id: "test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0"
2025-11-05T13:43:41.776799Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0
2025-11-05T13:43:41.776802Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  MessageGroupId [test-message_group_id] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:43:41.776869Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.000000s
2025-11-05T13:43:41.776875Z :TRACE: [/Root] TRACE_EVENT DescribePartitionRequest  path=/Root/topic_A partition_id=0
2025-11-05T13:43:41.776901Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-11-05T13:43:41.777348Z node 9 :PQ_READ_PROXY DEBUG: new Describe partition request
2025-11-05T13:43:41.778233Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 9
    generation: 1
  }
}
2025-11-05T13:43:41.778243Z :TRACE: [/Root] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=9 pl_generation=1
2025-11-05T13:43:41.778248Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 9 exists in the endpoint pool.
2025-11-05T13:43:41.778253Z :TRACE: [/Root] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=9 Generation=1
2025-11-05T13:43:41.778256Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  PartitionId [0]  Generation [1] Start write session. Will connect to nodeId: 9
2025-11-05T13:43:41.778463Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 1, Msg: CANCELLED, Details: , InternalError: 0
2025-11-05T13:43:41.778555Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  PartitionId [0]  Generation [1] Write session: direct write to partition: 0, generation 1
2025-11-05T13:43:41.778591Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  PartitionId [0]  Generation [1] Write session: send init request: init_request { path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 1 } }
2025-11-05T13:43:41.778595Z :TRACE: [/Root] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=1
2025-11-05T13:43:41.778680Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  PartitionId [0]  Generation [1] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:43:41.777406Z node 9 :PQ_READ_PROXY DEBUG: TDescribePartitionActor for request path: "/Root/topic_A"
include_location: true
2025-11-05T13:43:41.777419Z node 9 :PQ_READ_PROXY DEBUG: TDescribePartitionActor[9:7569236566521364515:2469]: Bootstrap
2025-11-05T13:43:41.777788Z node 9 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [9:7569236566521364515:2469]: Request location
2025-11-05T13:43:41.777934Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [9:7569236566521364524:2470] connected; active server actors: 1
2025-11-05T13:43:41.777993Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] addPartitionToResponse tabletId 72075186224037894, partitionId 0, NodeId 9, Generation 1
2025-11-05T13:43:41.777998Z node 9 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [9:7569236566521364515:2469]: Got location
2025-11-05T13:43:41.778186Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [9:7569236566521364524:2470] disconnected; active server actors: 1
2025-11-05T13:43:41.778188Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [9:7569236566521364524:2470] disconnected no session
2025-11-05T13:43:41.781596Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 3 sessionId: test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0 grpc read done: success: 0 data: 
2025-11-05T13:43:41.781599Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0 grpc read failed
2025-11-05T13:43:41.781608Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0 grpc closed
2025-11-05T13:43:41.781611Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 3 sessionId: test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0 is DEAD
2025-11-05T13:43:41.781761Z node 9 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:43:41.781770Z node 9 :PQ_WRITE_PROXY DEBUG: new session created cookie 4
2025-11-05T13:43:41.781802Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:43:41.781966Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId:  grpc read done: success: 1 data: init_request { path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 1 } }
2025-11-05T13:43:41.781991Z node 9 :PQ_WRITE_PROXY INFO: session request cookie: 4 path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 1 } from ipv6:[::1]:50662
2025-11-05T13:43:41.781999Z node 9 :PQ_WRITE_PROXY INFO: write session:  cookie=4 sessionId= userAgent="topic server" ip=ipv6:[::1]:50662 proto=topic  topic=topic_A durationSec=0
2025-11-05T13:43:41.782002Z node 9 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:43:41.782007Z node 9 :PQ_WRITE_PROXY INFO: session to partition: 0, generation: 1
2025-11-05T13:43:41.782022Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [9:7569236566521364512:2467] destroyed
2025-11-05T13:43:41.782047Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:43:41.782054Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.782056Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.782276Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId:  describe result for acl check
2025-11-05T13:43:41.782313Z node 9 :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:43:41.782318Z node 9 :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:43:41.782320Z node 9 :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:43:41.782326Z node 9 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [9:7569236566521364529:2472] (SourceId=test-message_group_id, PreferedPartition=0) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:43:41.782330Z node 9 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 4 sessionId:  partition: 0 expectedGeneration: 1
2025-11-05T13:43:41.782417Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 9, Generation: 1
2025-11-05T13:43:41.782430Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236566521364532:2472], now have 1 active actors on pipe
2025-11-05T13:43:41.782435Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.782441Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.782460Z node 9 :PERSQUEUE INFO: new Cookie test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0 generated for partition 0 topic 'topic_A' owner test-message_group_id
2025-11-05T13:43:41.782465Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.782468Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.782477Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.782489Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:43:41.782508Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.782540Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.782546Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.782555Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.782571Z node 9 :PQ_WRITE_PROXY INFO: session inited cookie: 4 partition: 0 MaxSeqNo: 0 sessionId: test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0
2025-11-05T13:43:41.782785Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:43:41.782806Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|a5586176-c84bdcfd-d02a03ac-3e3994db_0]  PartitionId [0]  Generation [1] Write session established. Init response: session_id: "test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0"
2025-11-05T13:43:41.782811Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0
2025-11-05T13:43:41.782816Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:43:41.782871Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=1, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=1, AckCount=0
2025-11-05T13:43:41.782907Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 1 to 1
2025-11-05T13:43:41.782976Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:41.782981Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 1
2025-11-05T13:43:41.783159Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=2, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=2, AckCount=0
2025-11-05T13:43:41.783179Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 2 to 2
2025-11-05T13:43:41.783195Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:41.783197Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 2
2025-11-05T13:43:41.783207Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=3, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=3, AckCount=0
2025-11-05T13:43:41.783230Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 3 to 3
2025-11-05T13:43:41.783239Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:41.783241Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 3
2025-11-05T13:43:41.783246Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=4, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=4, AckCount=0
2025-11-05T13:43:41.783263Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 4 to 4
2025-11-05T13:43:41.783281Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:41.783283Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 4
2025-11-05T13:43:41.783291Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=5, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=5, AckCount=0
2025-11-05T13:43:41.783314Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 5 to 5
2025-11-05T13:43:41.783336Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:41.783340Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 5
2025-11-05T13:43:41.783321Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:43:41.783347Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=6, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=6, AckCount=0
2025-11-05T13:43:41.783373Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 6 to 6
2025-11-05T13:43:41.783398Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:41.783400Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 6
2025-11-05T13:43:41.783407Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=7, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=7, AckCount=0
2025-11-05T13:43:41.783399Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP for a WriteId. SessionId: ydb://session/3?node_id=9&id=NWNkYWJlZTUtMWVjY2JjNWQtYTdiOTliNTItZmM5NzEyZjQ= TxId: 01k9a44jefawdk0j0f56e90ysd
2025-11-05T13:43:41.783425Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 7 to 7
2025-11-05T13:43:41.783451Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:41.783453Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 7
2025-11-05T13:43:41.783460Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=8, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=8, AckCount=0
2025-11-05T13:43:41.783528Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 8 to 8
2025-11-05T13:43:41.783555Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:41.783557Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 8
2025-11-05T13:43:41.783575Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=9, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=9, AckCount=0
2025-11-05T13:43:41.783597Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 9 to 9
2025-11-05T13:43:41.783622Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:41.783624Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 9
2025-11-05T13:43:41.783632Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] OnWrite: seqNo=10, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=10, AckCount=0
2025-11-05T13:43:41.783652Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write 1 messages with Id from 10 to 10
2025-11-05T13:43:41.783709Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: try to update token
2025-11-05T13:43:41.783711Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Send 1 message(s) (0 left), first sequence number is 10
2025-11-05T13:43:41.784362Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:43:41.784608Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of the request to KQP for the WriteId. SessionId: ydb://session/3?node_id=9&id=NWNkYWJlZTUtMWVjY2JjNWQtYTdiOTliNTItZmM5NzEyZjQ= TxId: 01k9a44jefawdk0j0f56e90ysd Status: SUCCESS
2025-11-05T13:43:41.784614Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) SessionId: ydb://session/3?node_id=9&id=NWNkYWJlZTUtMWVjY2JjNWQtYTdiOTliNTItZmM5NzEyZjQ= TxId: 01k9a44jefawdk0j0f56e90ysd WriteId: {9, 281474976715673}
2025-11-05T13:43:41.784623Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 9, Generation: 1
2025-11-05T13:43:41.784635Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236566521364535:2472], now have 1 active actors on pipe
2025-11-05T13:43:41.784729Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.784736Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.784744Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] partition {0, {9, 281474976715673}, 100000} for WriteId {9, 281474976715673}
2025-11-05T13:43:41.784777Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvSubscribeLock for WriteId {9, 281474976715673}
2025-11-05T13:43:41.784793Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:41.784958Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 9 Status: STATUS_SUBSCRIBED
2025-11-05T13:43:41.784963Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {9, 281474976715673}, TxId (empty maybe), Status STATUS_UNSPECIFIED
2025-11-05T13:43:41.784965Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] subscribed WriteId {9, 281474976715673}
2025-11-05T13:43:41.785085Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:43:41.785175Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:41.785202Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:43:41.785329Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:43:41.785336Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:43:41.785452Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:43:41.785508Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateInit] bootstrapping {0, {9, 281474976715673}, 100000} [9:7569236566521364541:2474]
2025-11-05T13:43:41.785703Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitDiskStatusStep
2025-11-05T13:43:41.785932Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 4 sessionId: test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:43:41.785974Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitMetaStep
2025-11-05T13:43:41.786014Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitInfoRangeStep
2025-11-05T13:43:41.786081Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236566521364548:2858], now have 1 active actors on pipe
2025-11-05T13:43:41.786088Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataRangeStep
2025-11-05T13:43:41.786127Z node 9 :PERSQUEUE ERROR: Answer error topic: 'topic_A' partition: 0 messageNo: 0 requestId: <none> error: tablet will be restarted right now
2025-11-05T13:43:41.786715Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvTabletPipe::TEvClientDestroyed
2025-11-05T13:43:41.786717Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) received TEvClientDestroyed
2025-11-05T13:43:41.786726Z node 9 :PQ_WRITE_PROXY INFO: session v1 error cookie: 4 reason: status is not ok: tablet will be restarted right now sessionId: test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0
2025-11-05T13:43:41.786728Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] TEvClientDestroyed 72075186224037894
2025-11-05T13:43:41.786818Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 4 sessionId: test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0 is DEAD
2025-11-05T13:43:41.787476Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:43:41.787494Z :TRACE: [/Root] TRACE_EVENT Error  status=UNAVAILABLE
2025-11-05T13:43:41.787520Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Got error. Status: UNAVAILABLE, Description: <main>: Error: status is not ok: tablet will be restarted right now, code: 500001 
2025-11-05T13:43:41.787524Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [1] Write session will restart in 0.006314s
2025-11-05T13:43:41.787536Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [0] Get partition location async, partition 0, delay 0.006314s
2025-11-05T13:43:41.787544Z :TRACE: [/Root] TRACE_EVENT DescribePartitionRequest  path=/Root/topic_A partition_id=0
2025-11-05T13:43:41.788423Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvInterconnect::TEvNodeInfo
2025-11-05T13:43:41.788525Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Transactions request. From tx_00000000000000000000, To tx_18446744073709551615
2025-11-05T13:43:41.788547Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] has a tx info
2025-11-05T13:43:41.788557Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] PlanStep 1762350221807, PlanTxId 281474976715672, ExecStep 1762350221807, ExecTxId 281474976715672
2025-11-05T13:43:41.788587Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Txs.size=0, PlannedTxs.size=0
2025-11-05T13:43:41.788958Z node 9 :PERSQUEUE NOTICE: [PQ: 72075186224037894] disable metering: reason# billing is not enabled in BillingMeteringConfig
2025-11-05T13:43:41.788963Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037894] has a tx writes info
2025-11-05T13:43:41.789040Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvSubscribeLock for WriteId {9, 281474976715673}
2025-11-05T13:43:41.789050Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Registered with mediator time cast
2025-11-05T13:43:41.789085Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 9 Status: STATUS_SUBSCRIBED
2025-11-05T13:43:41.789091Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {9, 281474976715673}, TxId (empty maybe), Status STATUS_UNSPECIFIED
2025-11-05T13:43:41.789092Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] subscribed WriteId {9, 281474976715673}
2025-11-05T13:43:41.789099Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:43:41.789188Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:43:41.789238Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] bootstrapping 0 [9:7569236566521364575:2479]
2025-11-05T13:43:41.793743Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitConfigStep
2025-11-05T13:43:41.793927Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitInternalFieldsStep
2025-11-05T13:43:41.794075Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateInit] bootstrapping {0, {9, 281474976715673}, 100000} [9:7569236566521364576:2480]
2025-11-05T13:43:41.794394Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitDiskStatusStep
2025-11-05T13:43:41.794537Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitMetaStep
2025-11-05T13:43:41.794563Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitInfoRangeStep
2025-11-05T13:43:41.794598Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataRangeStep
2025-11-05T13:43:41.794613Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitDataStep
2025-11-05T13:43:41.794618Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Start initializing step TInitEndWriteTimestampStep
2025-11-05T13:43:41.794621Z node 9 :PERSQUEUE INFO: [topic_A:{0, {9, 281474976715673}, 100000}:TInitEndWriteTimestampStep] Initializing EndWriteTimestamp skipped because already initialized.
2025-11-05T13:43:41.794636Z node 9 :PERSQUEUE DEBUG: [topic_A:{0, {9, 281474976715673}, 100000}:Initializer] Initializing completed.
2025-11-05T13:43:41.794641Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateInit] init complete for topic 'topic_A' partition {0, {9, 281474976715673}, 100000} generation 2 [9:7569236566521364576:2480]
2025-11-05T13:43:41.794648Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateInit] SYNC INIT topic topic_A partitition {0, {9, 281474976715673}, 100000} so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:43:41.794652Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Process pending events. Count 0
2025-11-05T13:43:41.794655Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.794658Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.795259Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitDiskStatusStep
2025-11-05T13:43:41.795409Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitMetaStep
2025-11-05T13:43:41.795462Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitInfoRangeStep
2025-11-05T13:43:41.795708Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitDataRangeStep
2025-11-05T13:43:41.795728Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitDataStep
2025-11-05T13:43:41.795730Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Start initializing step TInitEndWriteTimestampStep
2025-11-05T13:43:41.795736Z node 9 :PERSQUEUE INFO: [topic_A:0:TInitEndWriteTimestampStep] Initializing EndWriteTimestamp skipped because already initialized.
2025-11-05T13:43:41.795739Z node 9 :PERSQUEUE DEBUG: [topic_A:0:Initializer] Initializing completed.
2025-11-05T13:43:41.795744Z node 9 :PERSQUEUE INFO: [PQ: 72075186224037894, Partition: 0, State: StateInit] init complete for topic 'topic_A' partition 0 generation 2 [9:7569236566521364575:2479]
2025-11-05T13:43:41.795749Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateInit] SYNC INIT topic topic_A partitition 0 so 0 endOffset 0 Head Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:43:41.795754Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Process pending events. Count 0
2025-11-05T13:43:41.795756Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.795758Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.795772Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 user test-consumer readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:43:41.797373Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [0]  Getting partition location, partition 0
2025-11-05T13:43:41.797864Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] TEvClientConnected TabletId 72075186224037894, NodeId 9, Generation 2
2025-11-05T13:43:41.797879Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236566521364551:2448], now have 1 active actors on pipe
2025-11-05T13:43:41.798184Z node 9 :PQ_READ_PROXY DEBUG: new Describe partition request
2025-11-05T13:43:41.798236Z node 9 :PQ_READ_PROXY DEBUG: TDescribePartitionActor for request path: "/Root/topic_A"
include_location: true
2025-11-05T13:43:41.798244Z node 9 :PQ_READ_PROXY DEBUG: TDescribePartitionActor[9:7569236566521364593:2483]: Bootstrap
2025-11-05T13:43:41.798514Z node 9 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [9:7569236566521364593:2483]: Request location
2025-11-05T13:43:41.798690Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [9:7569236566521364595:2484] connected; active server actors: 1
2025-11-05T13:43:41.798763Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] addPartitionToResponse tabletId 72075186224037894, partitionId 0, NodeId 9, Generation 2
2025-11-05T13:43:41.798768Z node 9 :PQ_READ_PROXY DEBUG: DescribeTopicImpl [9:7569236566521364593:2483]: Got location
2025-11-05T13:43:41.799131Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [0] Got PartitionLocation response. Status SUCCESS, proto:
partition {
  active: true
  partition_location {
    node_id: 9
    generation: 2
  }
}
2025-11-05T13:43:41.799109Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [9:7569236566521364595:2484] disconnected; active server actors: 1
2025-11-05T13:43:41.799114Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [9:7569236566521364595:2484] disconnected no session
2025-11-05T13:43:41.799165Z :TRACE: [/Root] TRACE_EVENT DescribePartitionResponse  partition_id=0 active=1 pl_node_id=9 pl_generation=2
2025-11-05T13:43:41.799174Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [0] GetPreferredEndpoint: partitionId 0, partitionNodeId 9 exists in the endpoint pool.
2025-11-05T13:43:41.799180Z :TRACE: [/Root] TRACE_EVENT PreferredPartitionLocation  Endpoint= NodeId=9 Generation=2
2025-11-05T13:43:41.799183Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [2] Start write session. Will connect to nodeId: 9
2025-11-05T13:43:41.799596Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [2] Write session: direct write to partition: 0, generation 2
2025-11-05T13:43:41.799624Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [2] Write session: send init request: init_request { path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 2 } }
2025-11-05T13:43:41.799628Z :TRACE: [/Root] TRACE_EVENT InitRequest  pwg_partition_id=0 pwg_generation=2
2025-11-05T13:43:41.799702Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [2] Write session: OnWriteDone gRpcStatusCode: 0
2025-11-05T13:43:41.799723Z node 9 :PQ_WRITE_PROXY DEBUG: new grpc connection
2025-11-05T13:43:41.799733Z node 9 :PQ_WRITE_PROXY DEBUG: new session created cookie 5
2025-11-05T13:43:41.799854Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId:  grpc read done: success: 1 data: init_request { path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 2 } }
2025-11-05T13:43:41.799880Z node 9 :PQ_WRITE_PROXY INFO: session request cookie: 5 path: "topic_A" producer_id: "test-message_group_id" partition_with_generation { generation: 2 } from ipv6:[::1]:50662
2025-11-05T13:43:41.799883Z node 9 :PQ_WRITE_PROXY INFO: write session:  cookie=5 sessionId= userAgent="topic server" ip=ipv6:[::1]:50662 proto=topic  topic=topic_A durationSec=0
2025-11-05T13:43:41.799887Z node 9 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:43:41.799907Z node 9 :PQ_WRITE_PROXY INFO: session to partition: 0, generation: 2
2025-11-05T13:43:41.800226Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId:  describe result for acl check
2025-11-05T13:43:41.800283Z node 9 :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:43:41.800284Z node 9 :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:43:41.800293Z node 9 :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:43:41.800301Z node 9 :PQ_PARTITION_CHOOSER DEBUG: TPartitionChooser [9:7569236566521364600:2486] (SourceId=test-message_group_id, PreferedPartition=0) ReplyResult: Partition=0, SeqNo=0
2025-11-05T13:43:41.800305Z node 9 :PQ_WRITE_PROXY DEBUG: ProceedPartition. session cookie: 5 sessionId:  partition: 0 expectedGeneration: 2
2025-11-05T13:43:41.800568Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 9, Generation: 2
2025-11-05T13:43:41.800578Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236566521364603:2486], now have 1 active actors on pipe
2025-11-05T13:43:41.800642Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.800648Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.800671Z node 9 :PERSQUEUE INFO: new Cookie test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0 generated for partition 0 topic 'topic_A' owner test-message_group_id
2025-11-05T13:43:41.800679Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.800683Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.800694Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.800704Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::ReplyOwnerOk. Partition: 0
2025-11-05T13:43:41.800719Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.800817Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.800821Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.800836Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.800850Z node 9 :PQ_WRITE_PROXY INFO: session inited cookie: 5 partition: 0 MaxSeqNo: 0 sessionId: test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0
2025-11-05T13:43:41.801020Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [2] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:43:41.801051Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|27a68ad0-e82592ee-23eab253-d8dba0dd_0]  PartitionId [0]  Generation [2] Write session established. Init response: session_id: "test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0"
2025-11-05T13:43:41.801056Z :TRACE: [/Root] TRACE_EVENT InitResponse  partition_id=0 session_id=test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0
2025-11-05T13:43:41.801060Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: set DirectWriteToPartitionId 0
2025-11-05T13:43:41.802896Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: try to update token
2025-11-05T13:43:41.802906Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Send 10 message(s) (0 left), first sequence number is 1
2025-11-05T13:43:41.807380Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0 grpc read done: success: 1 data:  write_request[data omitted]
2025-11-05T13:43:41.807926Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP for a WriteId. SessionId: ydb://session/3?node_id=9&id=NWNkYWJlZTUtMWVjY2JjNWQtYTdiOTliNTItZmM5NzEyZjQ= TxId: 01k9a44jefawdk0j0f56e90ysd
2025-11-05T13:43:41.808135Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of the request to KQP for the WriteId. SessionId: ydb://session/3?node_id=9&id=NWNkYWJlZTUtMWVjY2JjNWQtYTdiOTliNTItZmM5NzEyZjQ= TxId: 01k9a44jefawdk0j0f56e90ysd Status: SUCCESS
2025-11-05T13:43:41.808139Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) SessionId: ydb://session/3?node_id=9&id=NWNkYWJlZTUtMWVjY2JjNWQtYTdiOTliNTItZmM5NzEyZjQ= TxId: 01k9a44jefawdk0j0f56e90ysd WriteId: {9, 281474976715673}
2025-11-05T13:43:41.808293Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) TEvClientConnected Status OK, TabletId: 72075186224037894, NodeId 9, Generation: 2
2025-11-05T13:43:41.808313Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236566521364606:2486], now have 1 active actors on pipe
2025-11-05T13:43:41.808321Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.808327Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.808363Z node 9 :PERSQUEUE INFO: new Cookie test-message_group_id|3e7097bc-4e16d3b9-8a5fb079-f060af65_0 generated for partition {0, {9, 281474976715673}, 100000} topic 'topic_A' owner test-message_group_id
2025-11-05T13:43:41.808374Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.808378Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.808391Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.808400Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyOwnerOk. Partition: {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:41.808421Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.808435Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Start of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=9&id=NWNkYWJlZTUtMWVjY2JjNWQtYTdiOTliNTItZmM5NzEyZjQ= TxId: 01k9a44jefawdk0j0f56e90ysd
2025-11-05T13:43:41.808488Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) End of a request to KQP to save PartitionId. SessionId: ydb://session/3?node_id=9&id=NWNkYWJlZTUtMWVjY2JjNWQtYTdiOTliNTItZmM5NzEyZjQ= TxId: 01k9a44jefawdk0j0f56e90ysd Status: SUCCESS
2025-11-05T13:43:41.808560Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.808564Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.808582Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:41.808673Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.808678Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.808735Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Reserve bytes in transaction. Partition: 0, WriteId: { NodeId: 9 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:43:41.808751Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 1
2025-11-05T13:43:41.808766Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:43:41.808874Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:41.808877Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:41.808887Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Write in transaction. Partition: 0, WriteId: { NodeId: 9 KeyId: 281474976715673 KafkaTransaction: false }, NeedSupportivePartition: 0
2025-11-05T13:43:41.808898Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 1 partNo : 0 messageNo: 1 size 100073 offset: -1
2025-11-05T13:43:41.808903Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 2 partNo : 0 messageNo: 1 size 100073 offset: -1
2025-11-05T13:43:41.808908Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 3 partNo : 0 messageNo: 1 size 100073 offset: -1
2025-11-05T13:43:41.808911Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 4 partNo : 0 messageNo: 1 size 100073 offset: -1
2025-11-05T13:43:41.808914Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 5 partNo : 0 messageNo: 1 size 100073 offset: -1
2025-11-05T13:43:41.808917Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 6 partNo : 0 messageNo: 1 size 100073 offset: -1
2025-11-05T13:43:41.808919Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 7 partNo : 0 messageNo: 1 size 100073 offset: -1
2025-11-05T13:43:41.808922Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 8 partNo : 0 messageNo: 1 size 100073 offset: -1
2025-11-05T13:43:41.808926Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 9 partNo : 0 messageNo: 1 size 100073 offset: -1
2025-11-05T13:43:41.808929Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message topic: topic_A partition: 0 SourceId: '\0test-message_group_id' SeqNo: 10 partNo : 0 messageNo: 1 size 100073 offset: -1
2025-11-05T13:43:41.808965Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.808972Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.808994Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 1 partNo 0
2025-11-05T13:43:41.809028Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 1 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 100162 count 1 nextOffset 1 batches 1
2025-11-05T13:43:41.809035Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 0
2025-11-05T13:43:41.809040Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 2 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 200292 count 2 nextOffset 2 batches 1
2025-11-05T13:43:41.809044Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 3 partNo 0
2025-11-05T13:43:41.809051Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 3 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 300422 count 3 nextOffset 3 batches 1
2025-11-05T13:43:41.809055Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 4 partNo 0
2025-11-05T13:43:41.809059Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 4 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 400552 count 4 nextOffset 4 batches 1
2025-11-05T13:43:41.809062Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 5 partNo 0
2025-11-05T13:43:41.809070Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 5 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 500682 count 5 nextOffset 5 batches 1
2025-11-05T13:43:41.809076Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 6 partNo 0
2025-11-05T13:43:41.809753Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 6 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 600613 count 6 nextOffset 6 batches 1
2025-11-05T13:43:41.809770Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 7 partNo 0
2025-11-05T13:43:41.809781Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 7 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 700775 count 7 nextOffset 7 batches 2
2025-11-05T13:43:41.809786Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 8 partNo 0
2025-11-05T13:43:41.809791Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 8 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 800905 count 8 nextOffset 8 batches 2
2025-11-05T13:43:41.809795Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 9 partNo 0
2025-11-05T13:43:41.809808Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 9 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 901035 count 9 nextOffset 9 batches 2
2025-11-05T13:43:41.809812Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob processing sourceId '\0test-message_group_id' seqNo 10 partNo 0
2025-11-05T13:43:41.809816Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Topic 'topic_A' partition {0, {9, 281474976715673}, 100000} part blob complete sourceId '\0test-message_group_id' seqNo 10 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 1001165 count 10 nextOffset 10 batches 2
2025-11-05T13:43:41.809819Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.810021Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Add new write blob: topic 'topic_A' partition {0, {9, 281474976715673}, 100000} compactOffset 0,10 HeadOffset 0 endOffset 0 curOffset 10 D0000100000_00000000000000000000_00000_0000000010_00000| size 1001058 WTime 1762350221809
2025-11-05T13:43:41.810157Z node 9 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:43:41.810167Z node 9 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 100000 offset 0 partNo 0 count 10 size 1001058
2025-11-05T13:43:41.810680Z node 9 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 100000 offset 0 count 10 size 1001058 actorID [9:7569236566521364571:2478]
2025-11-05T13:43:41.810734Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 1000950 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:43:41.810752Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:41.810761Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {9, 281474976715673}, 100000}, SeqNo: 1, partNo: 0, Offset: 0 is stored on disk
2025-11-05T13:43:41.810766Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:41.810773Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {9, 281474976715673}, 100000}, SeqNo: 2, partNo: 0, Offset: 1 is stored on disk
2025-11-05T13:43:41.810776Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:41.810784Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {9, 281474976715673}, 100000}, SeqNo: 3, partNo: 0, Offset: 2 is stored on disk
2025-11-05T13:43:41.810787Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:41.810791Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {9, 281474976715673}, 100000}, SeqNo: 4, partNo: 0, Offset: 3 is stored on disk
2025-11-05T13:43:41.810794Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:41.810801Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {9, 281474976715673}, 100000}, SeqNo: 5, partNo: 0, Offset: 4 is stored on disk
2025-11-05T13:43:41.810804Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:41.810813Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {9, 281474976715673}, 100000}, SeqNo: 6, partNo: 0, Offset: 5 is stored on disk
2025-11-05T13:43:41.810816Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:41.810820Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {9, 281474976715673}, 100000}, SeqNo: 7, partNo: 0, Offset: 6 is stored on disk
2025-11-05T13:43:41.810823Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:41.810834Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {9, 281474976715673}, 100000}, SeqNo: 8, partNo: 0, Offset: 7 is stored on disk
2025-11-05T13:43:41.810836Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:41.810843Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {9, 281474976715673}, 100000}, SeqNo: 9, partNo: 0, Offset: 8 is stored on disk
2025-11-05T13:43:41.810849Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] TPartition::ReplyWrite. Partition: {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:41.810853Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Answering for message sourceid: '\0test-message_group_id', Topic: 'topic_A', Partition: {0, {9, 281474976715673}, 100000}, SeqNo: 10, partNo: 0, Offset: 9 is stored on disk
2025-11-05T13:43:41.811226Z node 9 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 100000 offset 0 partno 0 count 10 parts 0 size 1001058
2025-11-05T13:43:41.811309Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 1  requestId: <none> cookie: 1
2025-11-05T13:43:41.811335Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NKikimr::TEvPersQueue::TEvResponse
2025-11-05T13:43:41.811974Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: OnReadDone gRpcStatusCode: 0
2025-11-05T13:43:41.812073Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session got write response: acks { seq_no: 1 written_in_tx { } } acks { seq_no: 2 written_in_tx { } } acks { seq_no: 3 written_in_tx { } } acks { seq_no: 4 written_in_tx { } } acks { seq_no: 5 written_in_tx { } } acks { seq_no: 6 written_in_tx { } } acks { seq_no: 7 written_in_tx { } } acks { seq_no: 8 written_in_tx { } } acks { seq_no: 9 written_in_tx { } } acks { seq_no: 10 written_in_tx { } } write_statistics { persisting_time { nanos: 1000000 } min_queue_wait_time { } max_queue_wait_time { } partition_quota_wait_time { } topic_quota_wait_time { } }
2025-11-05T13:43:41.812094Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] OnAck: seqNo=1, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=10, AckCount=1
2025-11-05T13:43:41.812099Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: acknoledged message 1
2025-11-05T13:43:41.812119Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] OnAck: seqNo=2, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=10, AckCount=2
2025-11-05T13:43:41.812121Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: acknoledged message 2
2025-11-05T13:43:41.812126Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] OnAck: seqNo=3, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=10, AckCount=3
2025-11-05T13:43:41.812129Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: acknoledged message 3
2025-11-05T13:43:41.812134Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] OnAck: seqNo=4, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=10, AckCount=4
2025-11-05T13:43:41.812136Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: acknoledged message 4
2025-11-05T13:43:41.812140Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] OnAck: seqNo=5, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=10, AckCount=5
2025-11-05T13:43:41.812144Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: acknoledged message 5
2025-11-05T13:43:41.812170Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] OnAck: seqNo=6, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=10, AckCount=6
2025-11-05T13:43:41.812172Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: acknoledged message 6
2025-11-05T13:43:41.812178Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] OnAck: seqNo=7, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=10, AckCount=7
2025-11-05T13:43:41.812180Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: acknoledged message 7
2025-11-05T13:43:41.812185Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] OnAck: seqNo=8, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=10, AckCount=8
2025-11-05T13:43:41.812187Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: acknoledged message 8
2025-11-05T13:43:41.812194Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] OnAck: seqNo=9, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=10, AckCount=9
2025-11-05T13:43:41.812196Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: acknoledged message 9
2025-11-05T13:43:41.812200Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] OnAck: seqNo=10, txId=01k9a44jefawdk0j0f56e90ysd, WriteCount=10, AckCount=10
2025-11-05T13:43:41.812202Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: acknoledged message 10
2025-11-05T13:43:41.812569Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.812580Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.826233Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.826251Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.895808Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.895830Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.895858Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.895861Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.926553Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.926568Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.996167Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.996189Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:41.996227Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:41.996233Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.026913Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.026933Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.096523Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.096523Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.096531Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.096536Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.127218Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.127240Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.196869Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.196869Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.196879Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.196882Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.227596Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.227608Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.297225Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.297229Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.297236Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.297241Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.327948Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.327964Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.397599Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.397599Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.397606Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.397612Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.428307Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.428321Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.497911Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.497911Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.497922Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.497924Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.528651Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.528664Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.598273Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.598273Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.598280Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.598294Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.628995Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.629012Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.698592Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.698592Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.698599Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.698605Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.729334Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.729351Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.798979Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.798993Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.798999Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.799003Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.800999Z node 9 :PQ_WRITE_PROXY INFO: init check schema
2025-11-05T13:43:42.801346Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0 describe result for acl check
2025-11-05T13:43:42.829733Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.829750Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.899348Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.899348Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.899356Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.899363Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.930073Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.930087Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.999737Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.999755Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:42.999789Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:42.999792Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.030403Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.030420Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.100049Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.100068Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.100105Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.100112Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.130861Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.130877Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.201545Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.201558Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.201584Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.201587Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.233642Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.233659Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.304318Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.304332Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.304362Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.304365Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.334041Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.334062Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.404674Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.404690Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.404720Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.404723Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.437561Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.437580Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.505008Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.505021Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.505022Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.505029Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.537779Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.537794Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.605375Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.605378Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.605384Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.605395Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.638125Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.638139Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.705664Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.705679Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.705677Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.705683Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.738524Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.738540Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.787158Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236575111299314:2940], now have 1 active actors on pipe
2025-11-05T13:43:43.787362Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPersQueue::TEvProposeTransaction SourceActor { RawX1: 7569236575111299311 RawX2: 4503638282078624 } TxId: 281474976715676 Data { Operations { PartitionId: 0 Path: "/Root/topic_A" SupportivePartition: 100000 } Op: Commit SendingShards: 72075186224037894 ReceivingShards: 72075186224037894 Immediate: true WriteId { NodeId: 9 KeyId: 281474976715673 } }
2025-11-05T13:43:43.787377Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] PartitionId {0, {9, 281474976715673}, 100000} for WriteId {9, 281474976715673}
2025-11-05T13:43:43.787389Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] TxId 281474976715676 has WriteId {9, 281474976715673}
2025-11-05T13:43:43.787393Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] immediate transaction
2025-11-05T13:43:43.787414Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Send TEvGetWriteInfoRequest for TxId (empty maybe)
2025-11-05T13:43:43.787422Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.787426Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] The Tx (empty maybe) is waiting for TEvGetWriteInfoResponse
2025-11-05T13:43:43.787433Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Still preprocessing - waiting for something
2025-11-05T13:43:43.787447Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Handle TEvPQ::TEvGetWriteInfoRequest
2025-11-05T13:43:43.787986Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Send TEvPQ::TEvGetWriteInfoResponse
2025-11-05T13:43:43.788013Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Handle TEvPQ::TEvGetWriteInfoResponse
2025-11-05T13:43:43.788020Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Received TEvGetWriteInfoResponse for TxId (empty maybe)
2025-11-05T13:43:43.788023Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.788036Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.788045Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::CommitWriteOperations TxId: (empty maybe)
2025-11-05T13:43:43.788053Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] t.WriteInfo->BodyKeys.size=0, t.WriteInfo->BlobsFromHead.size=10
2025-11-05T13:43:43.788061Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Head=Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0, NewHead=Offset 0 PartNo 0 PackedSize 0 count 0 nextOffset 0 batches 0
2025-11-05T13:43:43.788081Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 1 partNo 0
2025-11-05T13:43:43.788110Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 1 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 100162 count 1 nextOffset 1 batches 1
2025-11-05T13:43:43.788120Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 2 partNo 0
2025-11-05T13:43:43.788123Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 2 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 200292 count 2 nextOffset 2 batches 1
2025-11-05T13:43:43.788126Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 3 partNo 0
2025-11-05T13:43:43.788129Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 3 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 300422 count 3 nextOffset 3 batches 1
2025-11-05T13:43:43.788131Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 4 partNo 0
2025-11-05T13:43:43.788134Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 4 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 400552 count 4 nextOffset 4 batches 1
2025-11-05T13:43:43.788137Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 5 partNo 0
2025-11-05T13:43:43.788140Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 5 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 500682 count 5 nextOffset 5 batches 1
2025-11-05T13:43:43.788143Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 6 partNo 0
2025-11-05T13:43:43.788688Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 6 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 600613 count 6 nextOffset 6 batches 1
2025-11-05T13:43:43.788712Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 7 partNo 0
2025-11-05T13:43:43.788723Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 7 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 700775 count 7 nextOffset 7 batches 2
2025-11-05T13:43:43.788726Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 8 partNo 0
2025-11-05T13:43:43.788729Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 8 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 800905 count 8 nextOffset 8 batches 2
2025-11-05T13:43:43.788732Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 9 partNo 0
2025-11-05T13:43:43.788735Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 9 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 901035 count 9 nextOffset 9 batches 2
2025-11-05T13:43:43.788738Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob processing sourceId '\0test-message_group_id' seqNo 10 partNo 0
2025-11-05T13:43:43.788741Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 part blob complete sourceId '\0test-message_group_id' seqNo 10 partNo 0 FormedBlobsCount 0 NewHead: Offset 0 PartNo 0 PackedSize 1001165 count 10 nextOffset 10 batches 2
2025-11-05T13:43:43.788753Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] schedule TEvPersQueue::TEvProposeTransactionResult(COMPLETE), reason=
2025-11-05T13:43:43.788764Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.788918Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Add new write blob: topic 'topic_A' partition 0 compactOffset 0,10 HeadOffset 0 endOffset 0 curOffset 10 d0000000000_00000000000000000000_00000_0000000010_00000| size 1001058 WTime 1762350223788
2025-11-05T13:43:43.789383Z node 9 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:43:43.789447Z node 9 :PERSQUEUE DEBUG: CacheProxy. Passthrough blob. Partition 0 offset 0 partNo 0 count 10 size 1001058
2025-11-05T13:43:43.789748Z node 9 :PERSQUEUE DEBUG: Caching head blob in L1. Partition 0 offset 0 count 10 size 1001058 actorID [9:7569236566521364571:2478]
2025-11-05T13:43:43.789784Z node 9 :PERSQUEUE DEBUG: PQ Cache (L2). Adding blob. Tablet '72075186224037894' partition 0 offset 0 partno 0 count 10 parts 0 size 1001058
2025-11-05T13:43:43.789834Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 1000950
2025-11-05T13:43:43.790114Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 user test-consumer readTimeStamp for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:43:43.790115Z node 9 :PQ_TX INFO: [PQ: 72075186224037894] Handle TEvPQ::TEvTransactionCompleted WriteId {9, 281474976715673}
2025-11-05T13:43:43.790120Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvPQ::TEvDeletePartition to partition {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:43.790123Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 user test-consumer send read request for offset 0 initiated  queuesize 0 startOffset 0 ReadingTimestamp 1 rrg 0
2025-11-05T13:43:43.790129Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.790132Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.790148Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Handle TEvPQ::TEvDeletePartition
2025-11-05T13:43:43.790169Z node 9 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:43:43.790178Z node 9 :PERSQUEUE DEBUG: CacheProxy. Delete blobs from D0000100000(+) to D0000100001(-)
2025-11-05T13:43:43.790183Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] read cookie 0 Topic 'topic_A' partition 0 user test-consumer offset 0 count 1 size 1024000 endOffset 10 max time lag 0ms effective offset 0
2025-11-05T13:43:43.790190Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] read cookie 0 added 0 blobs, size 0 count 0 last offset 0, current partition end offset: 10
2025-11-05T13:43:43.790211Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvLongTxService::TEvLockStatus LockId: 281474976715673 LockNode: 9 Status: STATUS_NOT_FOUND
2025-11-05T13:43:43.790229Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] TxWriteInfo: WriteId {9, 281474976715673}, TxId 281474976715676, Status STATUS_SUBSCRIBED
2025-11-05T13:43:43.790232Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] there is already a transaction TxId 281474976715676 for WriteId {9, 281474976715673}
2025-11-05T13:43:43.790324Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Reading cookie 0. All data is from uncompacted head.
2025-11-05T13:43:43.790334Z node 9 :PERSQUEUE DEBUG: FormAnswer for 0 blobs
2025-11-05T13:43:43.790357Z node 9 :PERSQUEUE DEBUG: Topic 'topic_A' partition 0 user test-consumer readTimeStamp done, result 1762350221808 queuesize 0 startOffset 0
2025-11-05T13:43:43.790388Z :INFO: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] Starting read session
2025-11-05T13:43:43.790399Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] Starting single session
2025-11-05T13:43:43.790432Z node 9 :PERSQUEUE DEBUG: Deleting head blob in L1. Partition 100000 offset 0 count 10 actorID [9:7569236566521364571:2478]
2025-11-05T13:43:43.790468Z node 9 :PERSQUEUE DEBUG: PQ Cache (L2). Removed. Tablet '72075186224037894' partition 100000 offset 0 partno 0 count 10 parts 0
2025-11-05T13:43:43.790489Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.790492Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] Handle TEvPQ::TEvDeletePartitionDone {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:43.790495Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: {0, {9, 281474976715673}, 100000}, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.790496Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] DeletePartition {0, {9, 281474976715673}, 100000}
2025-11-05T13:43:43.790556Z node 9 :PQ_TX DEBUG: [PQ: 72075186224037894] send TEvUnsubscribeLock for WriteId {9, 281474976715673}
2025-11-05T13:43:43.790565Z node 9 :PQ_TX WARN: [PQ: 72075186224037894] Unknown transaction 281474976715676
2025-11-05T13:43:43.790580Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Send TEvKeyValue::TEvRequest (WRITE_TX_COOKIE)
2025-11-05T13:43:43.790670Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] In Reconnect, ReadSizeBudget = 52428800, ReadSizeServerDelta = 0
2025-11-05T13:43:43.790686Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] New values: ReadSizeBudget = 52428800, ReadSizeServerDelta = 0
2025-11-05T13:43:43.790690Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] Reconnecting session to cluster  in 0.000000s
2025-11-05T13:43:43.790751Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Handle TEvKeyValue::TEvResponse (WRITE_TX_COOKIE)
2025-11-05T13:43:43.790933Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] Successfully connected. Initializing session
2025-11-05T13:43:43.791166Z node 9 :PQ_READ_PROXY DEBUG: new grpc connection
2025-11-05T13:43:43.791171Z node 9 :PQ_READ_PROXY DEBUG: new session created cookie 1
2025-11-05T13:43:43.791288Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer  session  grpc read done: success# 1, data# { init_request { topics_read_settings { path: "topic_A" } consumer: "test-consumer" } }
2025-11-05T13:43:43.791332Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 read init: from# ipv6:[::1]:50662, request# { init_request { topics_read_settings { path: "topic_A" } consumer: "test-consumer" } }
2025-11-05T13:43:43.791353Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 auth for : test-consumer
2025-11-05T13:43:43.791502Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 Handle describe topics response
2025-11-05T13:43:43.791531Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 auth is DEAD
2025-11-05T13:43:43.791537Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 auth ok: topics# 1, initDone# 0
2025-11-05T13:43:43.791756Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 register session: topic# /Root/topic_A
2025-11-05T13:43:43.791835Z :INFO: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] Server session id: test-consumer_9_1_13171674980121704570_v1
2025-11-05T13:43:43.791845Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] In ContinueReadingDataImpl, ReadSizeBudget = 52428800, ReadSizeServerDelta = 0
2025-11-05T13:43:43.791820Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [9:7569236575111299328:2516] connected; active server actors: 1
2025-11-05T13:43:43.791928Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 52428800
2025-11-05T13:43:43.791831Z node 9 :PERSQUEUE_READ_BALANCER NOTICE: [72075186224037895][topic_A] consumer "test-consumer" register session for pipe [9:7569236575111299328:2516] session test-consumer_9_1_13171674980121704570_v1
2025-11-05T13:43:43.791837Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] consumer test-consumer register readable partition 0
2025-11-05T13:43:43.791844Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] consumer test-consumer family created family=1 (Status=Free, Partitions=[0])
2025-11-05T13:43:43.791848Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] consumer test-consumer register reading session ReadingSession "test-consumer_9_1_13171674980121704570_v1" (Sender=[9:7569236575111299325:2516], Pipe=[9:7569236575111299328:2516], Partitions=[], ActiveFamilyCount=0)
2025-11-05T13:43:43.791851Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] consumer test-consumer rebalancing was scheduled
2025-11-05T13:43:43.791859Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] consumer test-consumer balancing. Sessions=1, Families=1, UnradableFamilies=1 [1 (0), ], RequireBalancing=0 []
2025-11-05T13:43:43.791864Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] consumer test-consumer balancing family=1 (Status=Free, Partitions=[0]) for ReadingSession "test-consumer_9_1_13171674980121704570_v1" (Sender=[9:7569236575111299325:2516], Pipe=[9:7569236575111299328:2516], Partitions=[], ActiveFamilyCount=0)
2025-11-05T13:43:43.791873Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] consumer test-consumer family 1 status Active partitions [0] session "test-consumer_9_1_13171674980121704570_v1" sender [9:7569236575111299325:2516] lock partition 0 for ReadingSession "test-consumer_9_1_13171674980121704570_v1" (Sender=[9:7569236575111299325:2516], Pipe=[9:7569236575111299328:2516], Partitions=[], ActiveFamilyCount=1) generation 1 step 1
2025-11-05T13:43:43.791885Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] consumer test-consumer start rebalancing. familyCount=1, sessionCount=1, desiredFamilyCount=1, allowPlusOne=0
2025-11-05T13:43:43.791888Z node 9 :PERSQUEUE_READ_BALANCER DEBUG: [72075186224037895][topic_A] consumer test-consumer balancing duration: 0.000027s
2025-11-05T13:43:43.792026Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 assign: record# { Partition: 0 TabletId: 72075186224037894 Topic: "topic_A" Generation: 1 Step: 1 Session: "test-consumer_9_1_13171674980121704570_v1" ClientId: "test-consumer" PipeClient { RawX1: 7569236575111299328 RawX2: 4503638282078676 } Path: "/Root/topic_A" }
2025-11-05T13:43:43.792046Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 grpc read done: success# 1, data# { read_request { bytes_size: 52428800 } }
2025-11-05T13:43:43.792051Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 INITING TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1)
2025-11-05T13:43:43.792100Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1) pipe restart attempt 0 pipe creation result: OK TabletId: 72075186224037894 Generation: 2, pipe: [9:7569236575111299331:2519]
2025-11-05T13:43:43.792110Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server connected, pipe [9:7569236575111299331:2519], now have 1 active actors on pipe
2025-11-05T13:43:43.792115Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 got read request: guid# a8860609-8cb7de97-3863991-afd90545
2025-11-05T13:43:43.792118Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:43.792123Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:43.792132Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Created session test-consumer_9_1_13171674980121704570_v1 on pipe: [9:7569236575111299331:2519]
2025-11-05T13:43:43.792262Z node 9 :PQ_READ_PROXY DEBUG: Direct read cache: registered server session: test-consumer_9_1_13171674980121704570_v1:1 with generation 2
2025-11-05T13:43:43.792272Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.792277Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.792291Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 user test-consumer session is set to 0 (startOffset 0) session test-consumer_9_1_13171674980121704570_v1
2025-11-05T13:43:43.792299Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.792327Z node 9 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:43:43.792763Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:43:43.792766Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 18446744073709551615
2025-11-05T13:43:43.792772Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.792774Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.792831Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1) initDone 0 event { CmdGetClientOffsetResult { Offset: 0 EndOffset: 10 WriteTimestampMS: 1762350221808 CreateTimestampMS: 1762350221782 SizeLag: 1001058 WriteTimestampEstimateMS: 1762350221809 ClientHasAnyCommits: false } Cookie: 18446744073709551615 }
2025-11-05T13:43:43.792844Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 INIT DONE TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1) EndOffset 10 readOffset 0 committedOffset 0
2025-11-05T13:43:43.792864Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 sending to client partition status
2025-11-05T13:43:43.793114Z :INFO: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] Confirm partition stream create. Partition stream id: 1. Cluster: "-". Topic: "topic_A". Partition: 0. Read offset: (NULL)
2025-11-05T13:43:43.793245Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 grpc read done: success# 1, data# { start_partition_session_response { partition_session_id: 1 } }
2025-11-05T13:43:43.793285Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 got StartRead from client: partition# TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1), readOffset# 0, commitOffset# (empty maybe)
2025-11-05T13:43:43.793300Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 Start reading TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1) EndOffset 10 readOffset 0 committedOffset 0 clientCommitOffset (empty maybe) clientReadOffset 0
2025-11-05T13:43:43.793307Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1) ready for read with readOffset 0 endOffset 10
2025-11-05T13:43:43.793319Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 partition ready for read: partition# TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1), readOffset# 0, endOffset# 10, WTime# 1762350221808, sizeLag# 1001058
2025-11-05T13:43:43.793325Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1TEvPartitionReady. Aval parts: 1
2025-11-05T13:43:43.793332Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 performing read request: guid# d7dfff2e-fd4a2e3b-bfe94b8-79106380, from# TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1), count# 12, size# 1201269, partitionsAsked# 1, maxTimeLag# 0ms
2025-11-05T13:43:43.793355Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 READ FROM TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1)maxCount 12 maxSize 1201269 maxTimeLagMs 0 readTimestampMs 0 readOffset 0 EndOffset 10 ClientCommitOffset 0 committedOffset 0 Guid d7dfff2e-fd4a2e3b-bfe94b8-79106380
2025-11-05T13:43:43.793383Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:43.793401Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:43.793444Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] read cookie 1 Topic 'topic_A' partition 0 user test-consumer offset 0 count 12 size 1201269 endOffset 10 max time lag 0ms effective offset 0
2025-11-05T13:43:43.793453Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] read cookie 1 added 0 blobs, size 0 count 0 last offset 0, current partition end offset: 10
2025-11-05T13:43:43.793868Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Reading cookie 1. All data is from uncompacted head.
2025-11-05T13:43:43.793878Z node 9 :PERSQUEUE DEBUG: FormAnswer for 0 blobs
2025-11-05T13:43:43.793926Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 0
2025-11-05T13:43:43.794039Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1) initDone 1 event { CmdReadResult { MaxOffset: 10 Result { Offset: 0 Data: "... 100073 bytes ..." SourceId: "\000test-message_group_id" SeqNo: 1 WriteTimestampMS: 1762350221808 CreateTimestampMS: 1762350221782 UncompressedSize: 100000 PartitionKey: "" ExplicitHash: "" } Result { Offset: 1 Data: "... 100073 bytes ..." SourceId: "\000test-message_group_id" SeqNo: 2 WriteTimestampMS: 1762350221808 CreateTimestampMS: 1762350221783 UncompressedSize: 100000 PartitionKey: "" ExplicitHash: "" } Result { Offset: 2 Data: "... 100073 bytes ..." SourceId: "\000test-message_group_id" SeqNo: 3 WriteTimestampMS: 1762350221808 CreateTimestampMS: 1762350221783 UncompressedSize: 100000 PartitionKey: "" ExplicitHash: "" } Result { Offset: 3 Data: "... 100073 bytes ..." SourceId: "\000test-message_group_id" SeqNo: 4 WriteTimestampMS: 1762350221808 CreateTimestampMS: 1762350221783 UncompressedSize: 100000 PartitionKey: "" ExplicitHash: "" } Result { Offset: 4 Data: "... 100073 bytes ..." SourceId: "\000test-message_group_id" SeqNo: 5 WriteTimestampMS: 1762350221808 CreateTimestampMS: 1762350221783 UncompressedSize: 100000 PartitionKey: "" ExplicitHash: "" } Result { Offset: 5 Data: "... 100073 bytes ..." SourceId: "\000test-message_group_id" SeqNo: 6 WriteTimestampMS: 1762350221808 CreateTimestampMS: 1762350221783 UncompressedSize: 100000 PartitionKey: "" ExplicitHash: "" } Result { Offset: 6 Data: "... 100073 bytes ..." SourceId: "\000test-message_group_id" SeqNo: 7 WriteTimestampMS: 1762350221809 CreateTimestampMS: 1762350221783 UncompressedSize: 100000 PartitionKey: "" ExplicitHash: "" } Result { Offset: 7 Data: "... 100073 bytes ..." SourceId: "\000test-message_group_id" SeqNo: 8 WriteTimestampMS: 1762350221809 CreateTimestampMS: 1762350221783 UncompressedSize: 100000 PartitionKey: "" ExplicitHash: "" } Result { Offset: 8 Data: "... 100073 bytes ..." SourceId: "\000test-message_group_id" SeqNo: 9 WriteTimestampMS: 1762350221809 CreateTimestampMS: 1762350221783 UncompressedSize: 100000 PartitionKey: "" ExplicitHash: "" } Result { Offset: 9 Data: "... 100073 bytes ..." SourceId: "\000test-message_group_id" SeqNo: 10 WriteTimestampMS: 1762350221809 CreateTimestampMS: 1762350221783 UncompressedSize: 100000 PartitionKey: "" ExplicitHash: "" } BlobsFromDisk: 0 BlobsFromCache: 0 SizeLag: 18446744073709551374 RealReadOffset: 9 WaitQuotaTimeMs: 0 EndOffset: 10 StartOffset: 0 } Cookie: 0 }
2025-11-05T13:43:43.794320Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1) wait data in partition inited, cookie 1 from offset10
2025-11-05T13:43:43.794335Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 after read state TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1) EndOffset 10 ReadOffset 10 ReadGuid d7dfff2e-fd4a2e3b-bfe94b8-79106380 has messages 1
2025-11-05T13:43:43.794368Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 read done: guid# d7dfff2e-fd4a2e3b-bfe94b8-79106380, partition# TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1), size# 1000810
2025-11-05T13:43:43.794383Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 response to read: guid# d7dfff2e-fd4a2e3b-bfe94b8-79106380
2025-11-05T13:43:43.794945Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 Process answer. Aval parts: 0
2025-11-05T13:43:43.795853Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] Got ReadResponse, serverBytesSize = 1000810, now ReadSizeBudget = 0, ReadSizeServerDelta = 51427990
2025-11-05T13:43:43.795887Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] In ContinueReadingDataImpl, ReadSizeBudget = 0, ReadSizeServerDelta = 51427990
2025-11-05T13:43:43.795943Z :DEBUG: [/Root] Decompression task done. Partition/PartitionSessionId: 1 (6-9)
2025-11-05T13:43:43.795953Z :DEBUG: [/Root] Decompression task done. Partition/PartitionSessionId: 1 (0-5)
2025-11-05T13:43:43.795955Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] Returning serverBytesSize = 1000810 to budget
2025-11-05T13:43:43.795970Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] In ContinueReadingDataImpl, ReadSizeBudget = 1000810, ReadSizeServerDelta = 51427990
2025-11-05T13:43:43.796061Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] After sending read request: ReadSizeBudget = 0, ReadSizeServerDelta = 52428800
2025-11-05T13:43:43.796069Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] Returning serverBytesSize = 0 to budget
2025-11-05T13:43:43.796132Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 grpc read done: success# 1, data# { read_request { bytes_size: 1000810 } }
2025-11-05T13:43:43.796170Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 got read request: guid# 8190304b-63cd3e97-12555edd-5f4c90a8
2025-11-05T13:43:43.796301Z :DEBUG: [/Root] Take Data. Partition 0. Read: {0, 0} (0-0)
2025-11-05T13:43:43.796390Z :DEBUG: [/Root] Take Data. Partition 0. Read: {0, 1} (1-1)
2025-11-05T13:43:43.796485Z :DEBUG: [/Root] Take Data. Partition 0. Read: {0, 2} (2-2)
2025-11-05T13:43:43.796494Z :DEBUG: [/Root] Take Data. Partition 0. Read: {0, 3} (3-3)
2025-11-05T13:43:43.796536Z :DEBUG: [/Root] Take Data. Partition 0. Read: {0, 4} (4-4)
2025-11-05T13:43:43.796547Z :DEBUG: [/Root] Take Data. Partition 0. Read: {0, 5} (5-5)
2025-11-05T13:43:43.796561Z :DEBUG: [/Root] Take Data. Partition 0. Read: {1, 0} (6-6)
2025-11-05T13:43:43.796570Z :DEBUG: [/Root] Take Data. Partition 0. Read: {1, 1} (7-7)
2025-11-05T13:43:43.797465Z :DEBUG: [/Root] Take Data. Partition 0. Read: {1, 2} (8-8)
2025-11-05T13:43:43.797490Z :DEBUG: [/Root] Take Data. Partition 0. Read: {1, 3} (9-9)
2025-11-05T13:43:43.797504Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] The application data is transferred to the client. Number of messages 10, size 1000000 bytes
2025-11-05T13:43:43.797514Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] Returning serverBytesSize = 0 to budget
0 10
2025-11-05T13:43:43.797650Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] Commit offsets [0, 10). Partition stream id: 1
2025-11-05T13:43:43.797832Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 grpc read done: success# 1, data# { commit_offset_request { commit_offsets { partition_session_id: 1 offsets { end: 10 } } } }
2025-11-05T13:43:43.797894Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1) committing to position 10 prev 0 end 10 by cookie 2
2025-11-05T13:43:43.797931Z node 9 :PERSQUEUE DEBUG: Handle TEvRequest topic: 'topic_A' requestId: <none>
2025-11-05T13:43:43.797939Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] got client message batch for topic 'topic_A' partition 0
2025-11-05T13:43:43.797958Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.797966Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.797980Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 user test-consumer offset is set to 10 (startOffset 0) session test-consumer_9_1_13171674980121704570_v1
2025-11-05T13:43:43.797987Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.798020Z node 9 :PERSQUEUE DEBUG: CacheProxy. Passthrough write request to KV
2025-11-05T13:43:43.798360Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Topic 'topic_A' partition 0 user test-consumer readTimeStamp for offset 10 initiated  queuesize 0 startOffset 0 ReadingTimestamp 0 rrg 0
2025-11-05T13:43:43.798379Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::HandleWriteResponse writeNewSize# 0 WriteNewSizeFromSupportivePartitions# 0
2025-11-05T13:43:43.798388Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.798390Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.798402Z node 9 :PERSQUEUE DEBUG: Answer ok topic: 'topic_A' partition: 0 messageNo: 0  requestId: <none> cookie: 2
2025-11-05T13:43:43.798425Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1) initDone 1 event { Cookie: 2 }
2025-11-05T13:43:43.798439Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 TopicId: Topic /Root/topic_A in database: Root, partition 0(assignId:1) commit done to position 10 endOffset 10 with cookie 2
2025-11-05T13:43:43.798445Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 replying for commits: assignId# 1, from# 2, to# 2, offset# 10
2025-11-05T13:43:43.798584Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] Committed response: { partitions_committed_offsets { partition_session_id: 1 committed_offset: 10 } }
2025-11-05T13:43:43.806087Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.806104Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.838866Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.838880Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.906448Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.906462Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:43.939218Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:43.939233Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.006781Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.006797Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.039535Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.039555Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.107162Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.107180Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.139921Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.139939Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.208490Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.208505Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.240257Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.240275Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.309564Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.309584Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.340629Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.340646Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.409756Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.409772Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.440955Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.440971Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.510092Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.510111Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.541315Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.541330Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.610453Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.610469Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.641680Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.641695Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.710788Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.710804Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.742051Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.742068Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.790585Z :INFO: [/Root] Read/commit by partition streams (cluster:topic:partition:stream-id:read-offset:committed-offset): -:topic_A:0:1:9:10
2025-11-05T13:43:44.790617Z :INFO: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] Counters: { Errors: 0 CurrentSessionLifetimeMs: 1000 BytesRead: 1000000 MessagesRead: 10 BytesReadCompressed: 1000000 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:43:44.792197Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 checking auth because of timeout
2025-11-05T13:43:44.792223Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 auth for : test-consumer
2025-11-05T13:43:44.792393Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 Handle describe topics response
2025-11-05T13:43:44.792421Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 auth is DEAD
2025-11-05T13:43:44.792439Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 auth ok: topics# 1, initDone# 1
2025-11-05T13:43:44.811140Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.811153Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.842368Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.842382Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.911500Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.911517Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:44.942729Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:44.942744Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.011846Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.011863Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.043130Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.043144Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.112169Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.112183Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.143536Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.143556Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.212538Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.212555Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.243784Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.243800Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.312915Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.312930Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.344392Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.344408Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.413671Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.413688Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.444529Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.444559Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.514141Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.514155Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.544839Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.544855Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.614444Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.614459Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.645200Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.645217Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.714822Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.714839Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.745537Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.745556Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.790999Z :INFO: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] Closing read session. Close timeout: 0.000000s
2025-11-05T13:43:45.791018Z :INFO: [/Root] Read/commit by partition streams (cluster:topic:partition:stream-id:read-offset:committed-offset): -:topic_A:0:1:9:10
2025-11-05T13:43:45.791027Z :INFO: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] Counters: { Errors: 0 CurrentSessionLifetimeMs: 2000 BytesRead: 1000000 MessagesRead: 10 BytesReadCompressed: 1000000 BytesInflightUncompressed: 0 BytesInflightCompressed: 0 BytesInflightTotal: 0 MessagesInflight: 0 }
2025-11-05T13:43:45.791046Z :NOTICE: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Close with zero timeout " }
2025-11-05T13:43:45.791055Z :DEBUG: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] [] Abort session to cluster
2025-11-05T13:43:45.791094Z :NOTICE: [/Root] [/Root] [7824f0-f7ac4f25-e18b2d2c-e2c49c4e] Aborting read session. Description: SessionClosed { Status: ABORTED Issues: "<main>: Error: Aborted " }
2025-11-05T13:43:45.791758Z node 9 :PQ_READ_PROXY DEBUG: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 grpc read done: success# 0, data# {  }
2025-11-05T13:43:45.791771Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 grpc read failed
2025-11-05T13:43:45.791778Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 grpc closed
2025-11-05T13:43:45.791786Z node 9 :PQ_READ_PROXY INFO: session cookie 1 consumer test-consumer session test-consumer_9_1_13171674980121704570_v1 is DEAD
2025-11-05T13:43:45.792027Z node 9 :PERSQUEUE_READ_BALANCER INFO: [72075186224037895][topic_A] pipe [9:7569236575111299328:2516] disconnected; active server actors: 1
2025-11-05T13:43:45.792034Z node 9 :PERSQUEUE_READ_BALANCER NOTICE: [72075186224037895][topic_A] pipe [9:7569236575111299328:2516] client test-consumer disconnected session test-consumer_9_1_13171674980121704570_v1
2025-11-05T13:43:45.792063Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] Destroy direct read session test-consumer_9_1_13171674980121704570_v1
2025-11-05T13:43:45.792072Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [9:7569236575111299331:2519] destroyed
2025-11-05T13:43:45.792088Z node 9 :PQ_READ_PROXY DEBUG: Direct read cache: server session deregistered: test-consumer_9_1_13171674980121704570_v1
2025-11-05T13:43:45.793565Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: close. Timeout 0.000000s
2025-11-05T13:43:45.793575Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session will now close
2025-11-05T13:43:45.793583Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: aborting
2025-11-05T13:43:45.793693Z :INFO: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: gracefully shut down, all writes complete
2025-11-05T13:43:45.793699Z :DEBUG: [/Root]  TraceId []  SessionId [test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0]  PartitionId [0]  Generation [2] Write session: destroy
2025-11-05T13:43:45.793837Z node 9 :PQ_WRITE_PROXY DEBUG: session v1 cookie: 5 sessionId: test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0 grpc read done: success: 0 data: 
2025-11-05T13:43:45.793850Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0 grpc read failed
2025-11-05T13:43:45.793860Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0 grpc closed
2025-11-05T13:43:45.793863Z node 9 :PQ_WRITE_PROXY INFO: session v1 cookie: 5 sessionId: test-message_group_id|ca2240d4-ab2b6854-fcaa64d3-ab5b354b_0 is DEAD
2025-11-05T13:43:45.794158Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:43:45.794187Z node 9 :PQ_WRITE_PROXY DEBUG: TPartitionWriter 72075186224037894 (partition=0) Received event: NActors::TEvents::TEvPoison
2025-11-05T13:43:45.794242Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [9:7569236566521364603:2486] destroyed
2025-11-05T13:43:45.794253Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894] server disconnected, pipe [9:7569236566521364606:2486] destroyed
2025-11-05T13:43:45.794276Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] TPartition::DropOwner.
2025-11-05T13:43:45.794283Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.794285Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.815147Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.815163Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.846100Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.846136Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.915525Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.915546Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037894, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
2025-11-05T13:43:45.947714Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state before ContinueProcessTxsAndUserActs: 0
2025-11-05T13:43:45.947741Z node 9 :PERSQUEUE DEBUG: [PQ: 72075186224037892, Partition: 0, State: StateIdle] Batching state after ContinueProcessTxsAndUserActs: 1
