Empty response received for query from Spring Boot Application even though data is present

[ssharan27]

Summary

Empty response received in Spring Boot application while querying data from table even though data is present in table.

Detailed description

I have a table that has a few columns having types BIGINT(20), VARCHAR(255), DATETIME. When I execute the query directly on the mysql shell, I am able to fetch records

SELECT * FROM TEST.ARTICLES WHERE ID IN (1234) AND URL  != 'NA';

But when I am trying to do the same thing from my Spring Boot application using the R2dbcEntityTemplate, I am getting empty response. Upon enabling the debug logs using logging.level.org.springframework.r2dbc=DEBUG, I am seeing the following log being printed:

2023-06-23 16:47:28 INFO  - Executing query with criteria: ID  IN (1234) AND URL  != 'NA'
2023-06-23 16:48:35 INFO  - Response: Eof41Message{warnings=1, serverStatuses=2}, reports 1 warning(s)

I was able to isolate the field that is causing this issue. When the fields having type BIGINT(20) in table are defined as java.lang.Long in the corresponding java entity class, I get an empty response.

However changing the same fields to java type java.math.BigInteger fixes the issue as the Eof41Message log is removed and I get the expected data in response. According to the doc here, BIGINT should be compatible with the java 'Long' type.Since this is an existing table and part of an existing application that is being migrated to Spring Boot 3, changing the field type is not an option for me. Can you please help me solve this?

Relevant context

Platform: Ubuntu 22 Spring Boot Version: 3.1.0 Java: openjdk-20 r2dbc-mysql driver: 1.0.2

application properties:

logging.level.org.springframework.r2dbc=DEBUG
spring.r2dbc.url=r2dbc:mysql://localhost:3306/test
spring.r2dbc.username=root
spring.r2dbc.password=password

Here's the code I am using to execute the query:

var result = template.select( Query.query( Criteria.where("id").in(idList).and("url").notIn(invalidValues) ) , Articles.class)

[jchrys]

Thanks for your report! Could you let us know your mysql server version?

[ssharan27]

Hi @jchrys, thanks for replying! We are using mysql server version 5.7

[jchrys]

Hi, @ssharan27 could you share us patch part as well? like 5.7.x? it seems version related, since it was not possible to reproduce in my environment with 5.7.42(latest).

[ssharan27]

Apologies @jchrys, I replied based on memory earlier. I checked just now, we are using 5.6.34

[jchrys]

No problem. Thanks a lot!

[jchrys]

@ssharan27 hello, could you share your SHOW CREATE TABLE {table} ; query result? and other details?

i'd tried to reproduce the issue in my environment with below ddl but I failed to reproduce it. (mysql 5.6.34, r2dbc-mysql 1.0.2, jdk=temurin20, springboot 3.1)

drop table if exists test;
create table test(id int AUTO_INCREMENT PRIMARY KEY , name varchar(255), age bigint(20));
insert into test.test (name, age) values('abc', 21);
insert into test.test (name, age) values('abd', 25);
insert into test.test (name, age) values('aba', 24);
insert into test.test (name, age) values('abe', 23);

@Table("test")
@Data
public class Test {
    @Id
    private Integer id;
    @Column
    private String name;
    @Column
    private Long age;
}

@Service
@Slf4j
public class TestService {
    @Autowired
    private TestRepository testRepository;
    @Autowired
    private R2dbcEntityTemplate template;
    public Mono<List<Test>> getAllTestData() {
        return template.select(Query.query(Criteria.where("id").in(List.of(1, 2, 3)).and("name").not("AN") ) , Test.class)
           .collectList()
           .doOnNext(tests -> log.info("Found data: {}", tests))
           .doOnError(throwable -> {
               log.error("Error", throwable);
           });
    }

[jchrys]

Please reopen this issue if you have more info to provide us or reproducer. Thanks!

[ssharan27]

Hi @jchrys, apologies for the delayed response, I found what was causing this issue. Nevertheless, thanks a lot for taking the time to check this! I had been trying to find the root cause of this issue for a while and was unable to reproduce it on any other setup. I needed some pointers about what could possibly be causing this (hence the question label). After some digging I found that it was breaking due to a custom converter we had added (and forgotten about) to convert epoch milliseconds (Long) to LocalDateTime. I removed the converter and the query started working as expected. But now I will have to check if there are any flows dependent on this particular converter :(

This is what the converter looks like:

    public static class LongToLocalDateTimeConverter implements Converter<Long, LocalDateTime> {
        @Override
        public LocalDateTime convert(Long source) {
            return new Date(source).toInstant().atZone(ZoneId.systemDefault()).toLocalDateTime();
        }

    }

This makes me wonder whether this is the correct way to use converters with Long and other wrapper types in java? Also, can you tell what could have caused this issue to appear only after Spring Boot 3 upgrade?

EDIT: @jchrys unable to reopen this issue. Can you please take a look at my questions above?

[jchrys]

Hello, thank you for reaching out again. I appreciate your continued engagement.

I understand that you're facing an issue, and I'd be happy to help you investigate it further. In order for me to provide more accurate assistance, I kindly request that you provide additional information.

To begin with, could you please configure your logging level to either TRACE or DEBUG? if you could provide the entire log file along with a clear explanation of the issue you're experiencing, it would be immensely helpful.

logging.level.org.springframework=DEBUG
logging.level.io.asyncer=TRACE

+)Since the Converter class is part of the Spring Framework, it might be beneficial to post your issue on the Spring Framework Core and Spring Data R2DBC forums as well. By doing so, you can engage with the broader Spring community, which includes experts in those specific areas. They may be able to provide you with a quicker response.

[jchrys]

@ssharan27 I removed the reply, since it might contain secrets. please share your logs after below message.

2023-07-21T15:01:08.404+05:30  INFO 38791 --- [           main] com.example.Main                         : Started Main in 1.934 seconds (process running for 2.156)

[jchrys]

The issued query and the normal one are different. If they were identical, the response packet (okpacket) would also be the same. However, you received a warning in the issue log, and the RowMessage log is absent, which typically represents rows, as you might have guessed. If you want to check the details of the warning, you can query SHOW WARNINGS\G.

[ssharan27]

@ssharan27 I removed the reply, since it might contain secrets. please share your logs after below message.

Thanks for pointing that out, updated the gists:

• debug logs for correct response when converter removed
• debug logs for empty response when converter not removed

Here's the relevant piece of code I am using to get the data for this example:

@NoArgsConstructor
@AllArgsConstructor
@Data
@Table("articles")
public class Articles {
    @JsonProperty("id")
    @Id
    @Column("id")
    private Long id;
    @JsonProperty("created")
    @Column("created")
    private ZonedDateTime created;
    @JsonProperty("updated")
    @Column("updated")
    private ZonedDateTime updated;
    @JsonProperty("userId")
    @Column("user_id")
    private Long userId;
    @JsonProperty("views")
    @Column("views")
    private Long views;
    @JsonProperty("title")
    @Column("title")
    private String title;
    @JsonProperty("url")
    @Column("url")
    private String url;
}

    return template.select(
        Query.query(Criteria.where("views").greaterThan(1)),
        Articles.class
    ).collectList();

This would mean that the converter in question is interfering at query preparation stage only. @jchrys Can you also tell me how do I check the 'issued query' to confirm this?

[jchrys]

Hello, @ssharan27. To retrieve the actual query and query parameters, you can set a breakpoint on the Constructor of io.asyncer.r2dbc.mysql.message.client.PreparedTextQueryMessage, which looks like this: public PreparedTextQueryMessage(Query query, MySqlParameter[] values).

Once the breakpoint is set, you can inspect the query.formattedSql() to see the statement and examine the values array to obtain the parameters(value field contains the param value). These two pieces of information are used to send a query to the MySQL server.

[jchrys]

By the way, we are planning to implement a way to log a parameter easily. :D sorry for inconvenience.

[ssharan27]

Found it @jchrys! Thanks a ton :heart_eyes:! So basically the converter was causing every Long type field to become LocalDateTime. This caused the binding value for views to change from 1 to 1970-01-01T00:00:00.001 (epoch timestamp 1) which is obviously incorrect :cry:

We had added this converter to handle the conversion of timestamps received in request to LocalDateTime without having to provide separate mappers for each entity class. This used to work fine earlier but somehow this behaviour has changed in Spring Boot 3 leading to this issue. Do you have any suggestions on how to overcome this?

[jchrys]

Hello, @ssharan27 ! I'm so glad you found the cause you were looking for!😸

We had added this converter to handle the conversion of timestamps received in request to LocalDateTime without having to provide separate mappers for each entity class. This used to work fine earlier but somehow this behaviour has changed in Spring Boot 3 leading to this issue. Do you have any suggestions on how to overcome this?

I must admit I don't have a perfect solution in mind, unfortunately. However, I believe the Spring framework team would be your best bet to get the necessary assistance. They are experts in the field and can offer valuable answer. I suggest you reach out to them by writing a detailed issue or question on the Spring Framework issue board.

Best of luck with resolving the issue, and I hope the Spring team can provide the help you need! If you have any other questions or need further assistance, feel free to ask. 😊

[ssharan27]

I will see if I can find a solution for this one on my own first, then I will raise it with the Spring Framework team I :+1: I am currently in the process of upgrading my service so you might be seeing me again :stuck_out_tongue_closed_eyes: Thanks a lot for helping me debug this one! Closing this issue now, cheers!