一次倍受折磨的“invalid byte sequence for encoding "UTF8": 0x00”事件的经验教训
一、概述
invalid byte sequence for encoding "UTF8": 0x00(注意:若不是0x00则很可能是字符集设置有误),是PostgreSQL独有的错误信息,直接原因是varchar型的字段或变量不接受含有'\0'(也即数值0x00、UTF编码'\u0000')的字符串 。官方给出的解决方法:事先去掉字符串中的'\0',例如在Java代码中使用str.replaceAll('\u0000', ''),貌似这是目前唯一可行的方法。
几天前,项目的一个程序就出现这种错误,该程序是将一批特殊格式的文件导入到数据库的若干张表中。虽然已知道用replaceAll('\u0000', '')可解决问题,但由于要插入多张表、每个表含多个varchar字段、插入操作由JPA实现、插入操作要批量进行等因素,程序日志内容太笼统,为判断是哪个(或哪些)表、字段造成的、以及是代码原因还是数据原因提供的帮助很少,因而过程中麻烦多多困难重重,现在将其中的经验与教训总结出来,希望对同行们有所帮助。
二、经验1:从PostgreSQl的运行日志中定位表
一开始用普通方法,即通过在应用程序代码里加断点来跟踪执行情况,但在本例中,一旦跟踪到JPA持久化时就无法继续下去。而由于数据内容很多,用人工一一去检查费时费力,因而走了很多弯路。
后来,通过修改PostgreSQL配置文件,在运行日志(不是WAL和提交日志)中输出SQL语句执行情况,可以准确定位到哪个表会引发错误。具体方法是:
- 修改配置文件postgresql.conf,通常在$pgdata目录下,本例中是在D:\PostgreSQL\data\pg94目录;
- 找到“where to log”块,将logging_collector设置为on,这意味着开启运行日志,所在目录由log_directory参数指定;
- 找到“when to log”块,将log_statement设置为mod或all,这意味着sql语句被记录到运行日志;
- 仍在“when to log”块,确保log_min_error_statement为error或更低级别,以记录错误信息;因缺省值已是error,一般无须修改;
- 仍在“when to log”块,确保log_min_message为info或更低级别,这样成功执行的sql语句所绑定的变量也能查到(可选);
- 重启PostgreSQL,执行那个导入程序,此时运行日志已记录下执行的sql语句情况,根据报错信息即可具体定位是哪个表引起。
三、经验2:在程序代码中输出字符串内容
本来到这阶段已经相当接近成功了,但还是在此犯了错误:过于依赖页面所显示的内容,实在是不应该。因为浏览器、某些图形化工具在处理含有'\0'的字符串时会自动截断'\0'后面的内容,依旧无法确定是表里的哪个字段。
后来,干脆使用古老而经典的方法:在程序日志中按字节内容输出字符串变量(最好加上其长度),很快就准确找到了引发错误的字段。
同时,代码原因还是数据原因也随之确定。在本例中,特殊格式的数据文件是由一个早期版本的C程序生成的,很可能由于字符串初始化不彻底,生成的部分字段内容在正确内容后附加了一个'\0'和少许乱码,从而引发这次事件。
四、事件解决
如果按照官方的推荐做法而直接对嫌疑字符串使用str.replaceAll('\u0000', ''),虽然避免了错误发生,之后的乱码却会存入数据库并最终显示在页面。经与客户沟通,确认'\0'之后均为乱码,于是在程序代码中将所有的嫌疑字段的'\0'及乱码一起截断:
str.trim().split('\u0000')[0];
至此,这次折磨人多日的事件终于得到解决。
PS:该程序以前在Oracle环境没出现问题,因为Oracle可接受中间带'\0'的字符串进行存储,并在各种界面显示内容时会自动截断后面的内容,因而查不出原因,只有通过length()函数查询字符串长度才能发现不一致之处。