前回（No.10の記事）は、SpringのMySQL向け入門コンテンツを流用して、PostgreSQLへテーブルアクセスする、簡単なプログラムを組みました。
当然、動作確認までしなければ意味がないわけですが、ちゃんと動くまでには多少、いろいろあったので、今回はそのあたりをまとめておこうと思います。
※というか、以外とこっちのほうが（動かない＞直す＞動いた！という経験が）が大事
最初はエラーばっかり
まあ最初なので、一発で動くなんてことはありえないわけで、少々はまりました。
DB接続エラー
最初の「application.properties」の記載は以下のとおり。
spring.jpa.database=POSTGRESQL
spring.datasource.url=jdbc:postgresql://localhost:5432/ttsdb
spring.datasource.username=ttsuesr
spring.datasource.password=ttsuesr
spring.jpa.hibernate.ddl-auto=validate
spring.jpa.properties.hibernate.format_sql=true
logging.level.org.hibernate.SQL=DEBUG
logging.level.org.hibernate.type.descriptor.sql.BasicBinder=TRACEPostgreSQLに接続成功している方々の定義をお借りしてきたりしているので、基本的に間違っていないはずなのだけれど、接続エラーが発生。
org.postgresql.util.PSQLException: FATAL: ユーザ"ttsuser"のパスワード認証に失敗しました(pgjdbc: server-encoding として windows-31j を自動検出しました、メッセージが読めない場合はデータベースログおよび host, port, dbname, user, password, pg_dba.conf を確認してください)
なにがいけないのだろう？
前途多難を予感しながら素直な心で全てを疑ってみる。
認証失敗って言ってるんだから、認証までは行いにいってるよね？
ということは、「ttsuser」？、あ、「ttsusr」だ！
spring.datasource.username=ttsuser
＜＜ttusrに直す
spring.datasource.password=ttsuser ＜＜ttusrに直す
単純に思い込みで間違っていた、というパターンですね。
こういうのって、以外と良くあるよね？（いや、自分だけかも？）、そしてエラーはまだ続く。
findByメソッドが作れない？
当初、カテゴリ・テーブルのカラム名は、以下のように定義していました。
「ca_id」「ca_name」等、 ”_”（アンダースコア）で、単語・用語を繋げていくパターン。
「スネークケース」と言われているやつ。
最初の部分は「category」は長いので（正しくはcategoriesかもだけど）シンプルに「ca」で。
なので当初の「Category.java」は、以下のとおり。
package com.chankazu.tts.accessingdatapostgresql;
import javax.persistence.Entity;
import javax.persistence.Id;
@Entity // This tells Hibernate to make a table out of this class
public class Category {
@Id
private Long ca_id;
private String ca_name;
protected Category() {}
public Category(Long id, String name) {
this.ca_id = id;
this.ca_name = name;
}
@Override
public String toString() {
return String.format(
"Category[id=%d, name='%s']",ca_id, ca_name);
}
public Long getCa_id() {
return ca_id;
}
public void setCa_id(Long id) {
this.ca_id = id;
}
public String getCa_name() {
return ca_name;
}
public void setCa_name(String name) {
this.ca_name = name;
}
}
「ca_id」、「ca_name」という、Java側とテーブル側の定義が同じ状態。
この状態なので、「CategoryRepository」に定義するfindメソッドは以下にしました。
package com.chankazu.tts.accessingdatapostgresql;
import java.util.List;
import org.springframework.data.repository.CrudRepository;
public interface CategoryRepository extends CrudRepository<Category, Integer> {
List<Category> findAll();
Category findByCa_id(Long id);
}
けどこの状態だと、実行すると以下のエラーが発生。
Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2020-12-28 09:29:19.512 ERROR 29860 --- [ main] o.s.boot.SpringApplication : Application run failed
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'categoryRepository' defined in com.chankazu.tts.accessingdatapostgresql.CategoryRepository defined in @EnableJpaRepositories declared on JpaRepositoriesRegistrar.EnableJpaRepositoriesConfiguration: Cannot resolve reference to bean 'jpaMappingContext' while setting bean property 'mappingContext'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'jpaMappingContext': Invocation of init method failed; nested exception is javax.persistence.PersistenceException: [PersistenceUnit: default] Unable to build Hibernate SessionFactory; nested exception is org.hibernate.tool.schema.spi.SchemaManagementException: Schema-validation: missing column [ca_id] in table [category]
「ca_id」がダメ？、う～ん、よくわからんが、カラム名をうまく認識してくれないようなので、Java側もテーブル側も、名称はシンプルに「id」と「name」にしてみると、、、
通った！、これはつまり、 ”_”（アンダースコア）がだめなのか？
Spring Data JPAリポジトリメソッドは、アンダースコアを持つプロパティ名を認識しません
Spring Bootで変数名にスネークケースを使ってはまったこと
どうもそのようです。
試しに、テーブル側の定義を「ca_id」「ca_name」に戻して、Java側を「caId」「caName」にしてみたら、
package com.chankazu.tts.accessingdatapostgresql;
import javax.persistence.Entity;
import javax.persistence.Id;
@Entity // This tells Hibernate to make a table out of this class
public class Category {
@Id
private Long caId;
private String caName;
protected Category() {}
public Category(Long id, String name) {
this.caId = id;
this.caName = name;
}
@Override
public String toString() {
return String.format(
"Category[id=%d, name='%s']",caId, caName);
}
public Long getCaId() {
return caId;
}
public void setCaId(Long id) {
this.caId = id;
}
public String getCaName() {
return caName;
}
public void setName(String name) {
this.caName = name;
}
}通った、、、
つまり、Javaでの「caId」「caName」（キャメルケース）を、テーブル上の「ca_id」「ca_name」（スネークケース）に合わせようとするわけね、Spring JPAくんは。
う~ん、これは、便利なのだろうか？
余計なお世話のような気もするが。
こうした理由が知りたい。また、回避する方法もありそうだけれど、まずは勝手に変換されてしまうのを避けるため、テーブルのカラム名は、「id」「name」とシンプルにして、Java側もそれに倣うように、揃えるようにしました。
BootRunで実行
Gradleタスク・ビューをみてみると、
「このプロジェクトを Spring Boot アプリケーションとして実行します。」というのがあるので、当初これで実行。
> Task :bootRun
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.3.2.RELEASE)
・・・
・・・
（途中省略）
・・・
・・・
2020-12-28 11:05:35.504 DEBUG 24016 --- [ main] org.hibernate.SQL :
select
category0_.ca_id as ca_id1_0_,
category0_.ca_name as ca_name2_0_
from
category category0_
2020-12-28 11:05:35.519 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=2, name='Brake']
2020-12-28 11:05:35.519 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=1, name='Engine
']
2020-12-28 11:05:35.519 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=3, name='Muffler']
2020-12-28 11:05:35.519 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=102, name='AAA102']
2020-12-28 11:05:35.519 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=103, name='AAA103']
2020-12-28 11:05:35.519 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=104, name='AAA104']
2020-12-28 11:05:35.519 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=105, name='AAA105']
2020-12-28 11:05:35.519 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication :
2020-12-28 11:05:35.536 DEBUG 24016 --- [ main] org.hibernate.SQL :
select
category0_.ca_id as ca_id1_0_,
category0_.ca_name as ca_name2_0_
from
category category0_
where
category0_.ca_id=?
2020-12-28 11:05:35.537 TRACE 24016 --- [ main] o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [BIGINT] - [1]
2020-12-28 11:05:35.539 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category found with findById(1L):
2020-12-28 11:05:35.539 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication : --------------------------------
2020-12-28 11:05:35.539 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=1, name='Engine
']
2020-12-28 11:05:35.539 INFO 24016 --- [ main] c.t.a.AccessingDataPostgresqlApplication :
エラーで中断することがなくなって、ちゃんと動きます。カテゴリ・テーブルから Select してきているようだし、大丈夫そう。
そしてもう少しログをみてみると、起動時にSQLを生成するようです。
これって、毎回生成？、いっぱいあったら大変では？、という疑問がわいたが、とりあえず、放置しておきます。
そして、なんか、プログラムが終わらないっぽい。
自分で停止する必要がありそう。
ログの最初のほうをみてみると「Tomcat」が動いている。たぶんこれのせいですね。
2020-12-28 12:50:10.964 INFO 23176 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Starting AccessingDataPostgresqlApplication on MyComputer with PID 23176 (C:\workspace\tts\build\classes\java\main started by xxxxx in C:\workspace\tts)
2020-12-28 12:50:10.965 INFO 23176 --- [ main] c.t.a.AccessingDataPostgresqlApplication : No active profile set, falling back to default profiles: default
2020-12-28 12:50:11.350 INFO 23176 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFERRED mode.
2020-12-28 12:50:11.386 INFO 23176 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 31ms. Found 2 JPA repository interfaces.
2020-12-28 12:50:11.839 INFO 23176 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2020-12-28 12:50:11.846 INFO 23176 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2020-12-28 12:50:11.846 INFO 23176 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.37]
2020-12-28 12:50:11.918 INFO 23176 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2020-12-28 12:50:11.918 INFO 23176 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 926 ms
さらに、@SpringBootApplicationとか、@SpringBootTestとか、@Testとか、気になる指定（アノテーション）がいくつかあるけれど、それらは一旦おいておいて先に進みます。
JUnitで実行
そもそも、テストクラス「AccessingDataPostgresqlApplicationTests」は、JUnitっぽいのだから
package com.chankazu.tts.accessingdatapostgresql;
import org.junit.jupiter.api.Test;
import org.springframework.boot.test.context.SpringBootTest;
@SpringBootTest
class AccessingDataPostgresqlApplicationTests {
@Test
void contextLoads() {
}
}
「JUnitで実行」してみた。
うまくいったようです、ちゃんと終わります。
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.3.2.RELEASE)
2020-12-28 11:10:17.246 INFO 28756 --- [ main] .AccessingDataPostgresqlApplicationTests : Starting AccessingDataPostgresqlApplicationTests on MyComputer with PID 28756 (started by xxxxx in C:\pleiades\workspace\tts_old)
2020-12-28 11:10:17.247 INFO 28756 --- [ main] .AccessingDataPostgresqlApplicationTests : No active profile set, falling back to default profiles: default
2020-12-28 11:10:17.613 INFO 28756 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFERRED mode.
2020-12-28 11:10:17.659 INFO 28756 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 38ms. Found 1 JPA repository interfaces.
2020-12-28 11:10:18.060 INFO 28756 --- [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor'
2020-12-28 11:10:18.111 INFO 28756 --- [ task-1] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [name: default]
2020-12-28 11:10:18.156 INFO 28756 --- [ task-1] org.hibernate.Version : HHH000412: Hibernate ORM core version 5.4.18.Final
2020-12-28 11:10:18.159 INFO 28756 --- [ task-1] org.hibernate.cfg.Environment : HHH000205: Loaded properties from resource hibernate.properties: {hibernate.bytecode.use_reflection_optimizer=false, hibernate.jdbc.lob.non_contextual_creation=true}
2020-12-28 11:10:18.300 INFO 28756 --- [ task-1] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.1.0.Final}
2020-12-28 11:10:18.335 WARN 28756 --- [ main] JpaBaseConfiguration$JpaWebConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning
2020-12-28 11:10:18.599 INFO 28756 --- [ task-1] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2020-12-28 11:10:18.710 INFO 28756 --- [ task-1] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
2020-12-28 11:10:18.731 INFO 28756 --- [ task-1] org.hibernate.dialect.Dialect : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL95Dialect
2020-12-28 11:10:18.843 INFO 28756 --- [ main] DeferredRepositoryInitializationListener : Triggering deferred initialization of Spring Data repositories…
2020-12-28 11:10:19.267 INFO 28756 --- [ task-1] o.h.e.t.j.p.i.JtaPlatformInitiator : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2020-12-28 11:10:19.276 INFO 28756 --- [ task-1] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2020-12-28 11:10:19.483 INFO 28756 --- [ main] DeferredRepositoryInitializationListener : Spring Data repositories initialized!
2020-12-28 11:10:19.489 INFO 28756 --- [ main] .AccessingDataPostgresqlApplicationTests : Started AccessingDataPostgresqlApplicationTests in 2.447 seconds (JVM running for 3.236)
2020-12-28 11:10:19.490 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Categories found with findAll():
2020-12-28 11:10:19.490 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : -------------------------------
2020-12-28 11:10:19.598 DEBUG 28756 --- [ main] org.hibernate.SQL :
select
category0_.ca_id as ca_id1_0_,
category0_.ca_name as ca_name2_0_
from
category category0_
2020-12-28 11:10:19.619 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=2, name='Brake']
2020-12-28 11:10:19.619 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=1, name='Engine
']
2020-12-28 11:10:19.619 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=3, name='Muffler']
2020-12-28 11:10:19.619 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=102, name='AAA102']
2020-12-28 11:10:19.619 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=103, name='AAA103']
2020-12-28 11:10:19.619 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=104, name='AAA104']
2020-12-28 11:10:19.619 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=105, name='AAA105']
2020-12-28 11:10:19.619 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication :
2020-12-28 11:10:19.648 DEBUG 28756 --- [ main] org.hibernate.SQL :
select
category0_.ca_id as ca_id1_0_,
category0_.ca_name as ca_name2_0_
from
category category0_
where
category0_.ca_id=?
2020-12-28 11:10:19.650 TRACE 28756 --- [ main] o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [BIGINT] - [1]
2020-12-28 11:10:19.652 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category found with findById(1L):
2020-12-28 11:10:19.652 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : --------------------------------
2020-12-28 11:10:19.652 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication : Category[id=1, name='Engine
']
2020-12-28 11:10:19.652 INFO 28756 --- [ main] c.t.a.AccessingDataPostgresqlApplication :
2020-12-28 11:10:19.747 INFO 28756 --- [extShutdownHook] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'default'
2020-12-28 11:10:19.748 INFO 28756 --- [extShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor : Shutting down ExecutorService 'applicationTaskExecutor'
2020-12-28 11:10:19.749 INFO 28756 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown initiated...
2020-12-28 11:10:19.751 INFO 28756 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown completed.
完了しました。とりあえず、よしとします。
次回はコントローラーを作成
今回は、PostgreSQLのテーブル検索処理が出来ることを主眼にしたので、単なるアプリからの検索処理実行でした。
なので次回は、「コントローラー」から検索処理を呼び出す形にして、実際のアプリに近いスタイル（Web＜＞コントローラー＜＞エンティティ）にしてみます。
コメント
[…] 前回（No.11の記事）は、PostgreSQLのテーブルへアクセスする、簡単なプログラムを作成しました。 […]