code: 101, message: Unexpected packet Query received from client when updating many-to-many association

[edhemphill]

Not sure this is a bug or my own misunderstanding of gorm:

These models:

type HModel struct {
	ID        string `gorm:"primarykey"`
	CreatedAt time.Time
	UpdatedAt time.Time
	// DeletedAt DeletedAt `gorm:"index"`
}

type Visitor struct {
	HModel
	Email string `gorm:"unique" json:"email"`
	FirstName    string           `json:"first_name"`
	LastName     string           `json:"last_name"`
	Aliases []*Alias `gorm:"many2many:visitor_to_alias" json:"aliases"` // many:many
}

type Alias struct {
	Email     string `gorm:"primaryKey" json:"email"`
	FirstName string `json:"first_name"`
	LastName  string `json:"last_name"`
}

an implementation of adding an alias for a visitor like this:

func UpsertAliasForVisitor(db *gorm.DB, visitor *Visitor, alias *Alias) (err error) {
	err = db.Model(alias).Create(alias).Error
	if err != nil {
		return err
	}
	return db.Model(visitor).Association("Aliases").Append(alias)
}

Fails like such:

[6.709ms] [rows:0] INSERT INTO `aliases` (`email`,`first_name`,`last_name`) VALUES (?,?,?)
clickhouse-go: [send query] compression="lz4" ALTER TABLE `visitors` UPDATE `updated_at`=toDateTime('1705510846') WHERE `id` = '018d185e-3e35-7491-86d6-abbb58e64515'
clickhouse-go: [send data] compression="lz4"
clickhouse-go: [end of stream]
clickhouse-go: [send query] compression="lz4" INSERT INTO `aliases` (`email`,`first_name`,`last_name`) VALUES
clickhouse-go: [send data] compression="lz4"
clickhouse-go: [table columns]
clickhouse-go: [read data] compression="lz4". block: columns=3, rows=0

2024/01/17 11:00:46 /Users/thomashemphill/ubuntu-work/hulation/model/visitor.go:194
[1.576ms] [rows:0] INSERT INTO `aliases` (`email`,`first_name`,`last_name`) VALUES (?,?,?) ON CONFLICT DO NOTHING
clickhouse-go: [send query] compression="lz4" INSERT INTO `visitor_to_alias` (`visitor_id`,`alias_email`) VALUES
clickhouse-go: [send data] compression="lz4"
clickhouse-go: [exception] code: 101, message: Unexpected packet Query received from client
[clickhouse-std][conn=0][localhost:9000] PrepareContext error: code: 101, message: Unexpected packet Query received from client

2024/01/17 11:00:46 /Users/thomashemphill/ubuntu-work/hulation/model/visitor.go:194 code: 101, message: Unexpected packet Query received from client
[3.583ms] [rows:0] INSERT INTO `visitor_to_alias` (`visitor_id`,`alias_email`) VALUES (?,?) ON CONFLICT DO NOTHING

However, an implementation calling my own SQL works fine:

func UpsertAliasForVisitor(db *gorm.DB, visitor *Visitor, alias *Alias) (err error) {
	err = db.Model(alias).Create(alias).Error
	if err != nil {
		return err
	}

	return db.Transaction(func(tx *gorm.DB) (err error) {

		if err = tx.Exec("INSERT INTO `visitor_to_alias` (`visitor_id`,`alias_email`) VALUES (?,?)", visitor.ID, alias.Email).Error; err != nil {
			fmt.Printf("Error inserting into visitor_to_alias: %s", err.Error())
			log.Errorf("Error inserting into visitor_to_alias: %s", err.Error())

		}
		return
	})
}

Results:

2024/01/17 11:08:10 /Users/thomashemphill/ubuntu-work/hulation/model/model_test.go:109
[15.935ms] [rows:0] INSERT INTO `visitors` (`id`,`created_at`,`updated_at`,`email`,`ss_cookie`,`first_name`,`last_name`) VALUES (?,?,?,?,?,?,?)
    model_test.go:115: Insert ok. ID of new visitor is:  018d1865-074f-7b3a-ae0a-37efdb45b365
clickhouse-go: [send query] compression="lz4" INSERT INTO `aliases` (`email`,`first_name`,`last_name`) VALUES
clickhouse-go: [send data] compression="lz4"
clickhouse-go: [table columns]
clickhouse-go: [read data] compression="lz4". block: columns=3, rows=0
clickhouse-go: [send data] compression="lz4"
clickhouse-go: [send data] compression="lz4"
clickhouse-go: [read data] compression="lz4". block: columns=6, rows=18
clickhouse-go: [profile events] rows=18
clickhouse-go: [read data] compression="lz4". block: columns=6, rows=32
clickhouse-go: [profile events] rows=32
clickhouse-go: [end of stream]

2024/01/17 11:08:10 /Users/thomashemphill/ubuntu-work/hulation/model/visitor.go:191
[8.719ms] [rows:0] INSERT INTO `aliases` (`email`,`first_name`,`last_name`) VALUES (?,?,?)
clickhouse-go: [send query] compression="lz4" INSERT INTO `visitor_to_alias` (`visitor_id`,`alias_email`) VALUES ('018d1865-074f-7b3a-ae0a-37efdb45b365','[email protected]')
clickhouse-go: [send data] compression="lz4"
clickhouse-go: [progress] rows=1, bytes=70, total rows=0, wrote rows=1 wrote bytes=70 elapsed=5.984083ms
clickhouse-go: [progress] rows=1, bytes=70, total rows=0, wrote rows=1 wrote bytes=70 elapsed=5.984083ms
clickhouse-go: [read data] compression="lz4". block: columns=6, rows=40
clickhouse-go: [profile events] rows=40
clickhouse-go: [end of stream]

2024/01/17 11:08:10 /Users/thomashemphill/ubuntu-work/hulation/model/visitor.go:202
[6.620ms] [rows:0] INSERT INTO `visitor_to_alias` (`visitor_id`,`alias_email`) VALUES (?,?)

Verified everything using the clickhouse client.

ClickHouse client version 23.12.2.59 (official build).
Connecting to localhost:9000 as user default.
Connected to ClickHouse server version 23.12.2.

---

My understanding is that the error: code: 101, message: Unexpected packet Query received from client

Is likely when the same client is asked to start a new transaction while waiting on another to complete. My cursory glance at the source confirms this.

Notice that the clickhouse-go end of stream event never occurs in the first implementation. Is the gorm clickhouse driver not waiting for the first action to complete, or am i doing something wrong here?

related: https://github.com/ClickHouse/clickhouse-go/issues/322 https://github.com/ClickHouse/clickhouse-go/issues/485