why send twice query?

[basquiat78]

this is my test code log

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v3.1.0)

2023-06-29T11:32:12.066+09:00  INFO 6181 --- [           main] i.b.m.d.m.s.ReadMusicianServiceTest      : Starting ReadMusicianServiceTest using Java 17.0.5 with PID 6181 (started by basquiat in /Users/basquiat/IdeaProjects/musicshop)
2023-06-29T11:32:12.067+09:00  INFO 6181 --- [           main] i.b.m.d.m.s.ReadMusicianServiceTest      : The following 1 profile is active: "local"
2023-06-29T11:32:12.446+09:00  INFO 6181 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data R2DBC repositories in DEFAULT mode.
2023-06-29T11:32:12.532+09:00  INFO 6181 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 83 ms. Found 2 R2DBC repository interfaces.
2023-06-29T11:32:12.756+09:00  INFO 6181 --- [           main] c.g.j.r.m.MysqlConnectionFactoryProvider : set jasync.mysql.CLIENT_FOUND_ROWS=true
2023-06-29T11:32:12.795+09:00  INFO 6181 --- [           main] c.github.jasync.sql.db.util.NettyUtils   : jasync selected transport - nio
2023-06-29T11:32:13.252+09:00  INFO 6181 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 1 endpoint(s) beneath base path '/actuator'
2023-06-29T11:32:13.416+09:00  INFO 6181 --- [           main] i.b.m.d.m.s.ReadMusicianServiceTest      : Started ReadMusicianServiceTest in 1.481 seconds (process running for 1.926)
OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
2023-06-29T11:32:13.953+09:00  INFO 6181 --- [-netty-thread-2] i.b.m.c.listener.QueryLoggingListener    : Result Row : Optional[1]
2023-06-29T11:32:13.954+09:00  INFO 6181 --- [-netty-thread-2] i.b.m.c.listener.QueryLoggingListener    : ConnectionId: 10 
Query:["SELECT 1"] 
Bindings:[] 
Result Count : 1
2023-06-29T11:32:13.976+09:00  INFO 6181 --- [-netty-thread-2] i.b.m.c.listener.QueryLoggingListener    : Result Row : null
2023-06-29T11:32:13.977+09:00  INFO 6181 --- [-netty-thread-2] i.b.m.c.listener.QueryLoggingListener    : ConnectionId: 10 
Query:["SELECT musician.id, musician.name, musician.genre, musician.created_at, musician.updated_at FROM musician WHERE musician.id = ?"] 
Bindings:[(1)] 
Result Count : 1
2023-06-29T11:32:13.977+09:00  INFO 6181 --- [-netty-thread-2] i.b.m.c.listener.QueryLoggingListener    : ConnectionId: 10 
Query:["SELECT musician.id, musician.name, musician.genre, musician.created_at, musician.updated_at FROM musician WHERE musician.id = ?"] 
Bindings:[(1)] 
Result Count : 1

java.lang.AssertionError: expectation "assertNext" failed (expected: onNext(); actual: onError(org.springframework.data.mapping.MappingException: Could not read property @org.springframework.data.annotation.Id()private java.lang.Long io.basquiat.musicshop.domain.musician.model.entity.Musician.id from column Id))

    at reactor.test.MessageFormatter.assertionError(MessageFormatter.java:115)

.
.
.

Process finished with exit code 255

however The naming strategy is currently set, but regardless, it seems that two queries are being executed based on the logs. What could be wrong?

Did I miss something else?

[basquiat78]

but save case. only one create row.

Is it simply appearing in the logs as if the query is executed twice?

[basquiat78]

my self answer

i don't know why occured error then send like twice query.

but success test code, It displays normal logs.