[Home]

Summary:ASTERISK-26146: cdr_pgsql: Schema change happened
Reporter:Early Bird (earlybird)Labels:
Date Opened:2016-06-24 05:53:10Date Closed:
Priority:MinorRegression?Yes
Status:Open/NewComponents:CDR/cdr_pgsql
Versions:13.1.0 13.9.1 Frequency of
Occurrence		Constant
Related
Issues:
is related toASTERISK-26170 cdr_odbc: Insertion of record fails with Postgresql
Environment:Ubuntu 16.04 Xenial, Asterisk 13.1 (latest release available in the 16.04 repos), Postgres 9.5. {code} dpkg -l | grep asterisk: ii asterisk 1:13.1.0~dfsg-1.1ubuntu4 amd64 Open Source Private Branch Exchange (PBX) ii asterisk-config 1:13.1.0~dfsg-1.1ubuntu4 all Configuration files for Asterisk ii asterisk-core-sounds-en 1.4.22-1 all asterisk PBX sound files - US English ii asterisk-core-sounds-en-gsm 1.4.22-1 all asterisk PBX sound files - en-us/gsm ii asterisk-dahdi 1:13.1.0~dfsg-1.1ubuntu4 amd64 DAHDI devices support for the Asterisk PBX ii asterisk-modules 1:13.1.0~dfsg-1.1ubuntu4 amd64 loadable modules for the Asterisk PBX ii asterisk-moh-opsound-gsm 2.03-1 all asterisk extra sound files - English/gsm ii asterisk-mp3 1:13.1.0~dfsg-1.1ubuntu4 amd64 MP3 playback support for the Asterisk PBX ii asterisk-voicemail 1:13.1.0~dfsg-1.1ubuntu4 amd64 simple voicemail support for the Asterisk PBX dpkg -l | grep postgres: ii postgresql 9.5+173 all object-relational SQL database (supported version) ii postgresql-9.5 9.5.3-0ubuntu0.16.04 amd64 object-relational SQL database, version 9.5 server ii postgresql-client-9.5 9.5.3-0ubuntu0.16.04 amd64 front-end programs for PostgreSQL 9.5 ii postgresql-client-common 173 all manager for multiple PostgreSQL client versions ii postgresql-common 173 all PostgreSQL database-cluster manager ii postgresql-contrib-9.5 9.5.3-0ubuntu0.16.04 amd64 additional facilities for PostgreSQL {code}Attachments:
Description:While porting our configuration from 1.8 to 13.1, I noticed the following behaviour change in cdr_pgsql which I believe is a regression:

We were using the following CDR table format with 1.8. Whenever a call was entered with the 'NO ANSWER' disposition, the answer column got set to a timestamp equivalent to 0 epoch (1970-yadayada):

{code}
CREATE TABLE cdr (
       id serial NOT NULL,
       start timestamp with time zone NOT NULL ,
       answer timestamp with time zone NOT NULL ,
       "end" timestamp with time zone NOT NULL ,
       clid varchar (80) NOT NULL ,
       src varchar (80) NOT NULL ,
       dst varchar (80) NOT NULL ,
       dcontext varchar (80) NOT NULL ,
       channel varchar (80) NOT NULL ,
       dstchannel varchar (80) NOT NULL ,
       lastapp varchar (80) NOT NULL ,
       lastdata varchar (80) NOT NULL ,
       duration int NOT NULL ,
       billsec int NOT NULL ,
       disposition varchar (45) NOT NULL ,
       amaflags int NOT NULL ,
       accountcode varchar (20) NOT NULL ,
       uniqueid varchar (150) NOT NULL ,
       userfield varchar (255) NOT NULL ,
       peeraccount varchar(20) NOT NULL ,
       linkedid varchar(150) NOT NULL ,
       sequence int NOT NULL
);
{code}
When attempting to use the same data format on 13.1, inserting calls with the NO ANSWER dispostion fails hard to the effect that the CDR gets dropped, the reason being that instead of a valid timestamp, cdr_pgsql tries to pass an empty string:

{code}
[Jun 23 03:14:30] ERROR[27597] cdr_pgsql.c: Failed to insert call detail record into database!
985 [Jun 23 03:14:30] ERROR[27597] cdr_pgsql.c: Reason: ERROR:  invalid input syntax for type timestamp with time zone: ""
986 LINE 1: ...nkedid","sequence") VALUES ('2016-06-23 03:14:06','','2016-0...
{code}

Everything else continues to work properly. I have for now worked around this issue by dropping the answer column and deriving that timestamp using start + (duration-billsec) in our reporting queries.

I'm reporting this since the passing of the empty string is not compliant with postgres's strict type requirements.

I should also note that this occurred when using chan_sip.
Comments:By: Asterisk Team (asteriskteam) 2016-06-24 05:53:10.482-0500

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].
By: Joshua C. Colp (jcolp) 2016-06-24 06:09:24.665-0500

13.1 is an absurdly old version, does this problem present itself with 13.9?

For reference:
13.1 was released December 2014.
13.9 was released May 2016.

There have been substantial changes since then.
By: Early Bird (earlybird) 2016-06-28 03:20:06.826-0500

The same issue occurs with 13.9.1 (presently known as 13-current). Built on Ubuntu 16.04 with bundled pjlib. Uses chan_sip.
{code}
Asterisk 13.9.1 built by ubuntu @ ip-10-180-228-22 on a x86_64 running Linux on 2016-06-28 07:20:24 UTC
{code}

The error appears as follows:

{code}
[Jun 28 17:10:09] DEBUG[12936]: cdr_pgsql.c:391 pgsql_log: Inserting a CDR record: [INSERT INTO cdr ("start","end","answer","clid","src","dst","dcontext","channel","dstchannel","lastapp","lastdata","duration","billsec","disposition","amaflags","accountcode","unique$
d","peeraccount","linkedid","sequence") VALUES ('2016-06-28 17:09:45','2016-06-28 17:10:09','','"Test 3" <6293>','6293','6292','EXTENSIONS','SIP/6293-00000004','SIP/6292-00000005','Dial','SIP/6292,24,r',24,0,'NO ANSWER',3,'','1467101385.2022','','1467101385.20$
2',5)]
[Jun 28 17:10:09] ERROR[12936]: cdr_pgsql.c:422 pgsql_log: Failed to insert call detail record into database!
[Jun 28 17:10:09] ERROR[12936]: cdr_pgsql.c:423 pgsql_log: Reason: ERROR:  invalid input syntax for type timestamp with time zone: ""
LINE 1: ...LUES ('2016-06-28 17:09:45','2016-06-28 17:10:09','','"Test ...
                                                            ^
[Jun 28 17:10:09] ERROR[12936]: cdr_pgsql.c:424 pgsql_log: Connection may have been lost... attempting to reconnect.
[Jun 28 17:10:09] ERROR[12936]: cdr_pgsql.c:427 pgsql_log: Connection reestablished.
[Jun 28 17:10:09] ERROR[12936]: cdr_pgsql.c:435 pgsql_log: HARD ERROR!  Attempted reconnection failed.  DROPPING CALL RECORD!
[Jun 28 17:10:09] ERROR[12936]: cdr_pgsql.c:436 pgsql_log: Reason: ERROR:  invalid input syntax for type timestamp with time zone: ""
LINE 1: ...LUES ('2016-06-28 17:09:45','2016-06-28 17:10:09','','"Test ...
                                                            ^
{code}
By: Joshua C. Colp (jcolp) 2016-06-28 09:18:24.001-0500

The underlying cause of this is that during the migration to using alembic for schema management it actually changed:

   start TIMESTAMP WITHOUT TIME ZONE,
   answer TIMESTAMP WITHOUT TIME ZONE,
   "end" TIMESTAMP WITHOUT TIME ZONE,

I'm not quite sure what to do... whether to try to return it to previous or if it was done on purpose.
By: Early Bird (earlybird) 2016-06-28 23:11:11.065-0500

Ah yes, I overlooked that the TZ is always +00 now. Changing the schema solves the original problem.

I see where this might be coming from.

cdr_pgsql.conf permits a timezone=UTC parameter which alters the timezone (time per se) passed to the storage backend. This functionality is in line with the usegmttime=yes being supported by other storage backends such as CSV ([csv] in cdr.conf). Similar goes for the ODBC or MySQL CDR.

What is making this a mess is that dumb flat-file storage backends like CSV are thrown into the same basket as SQL backends with powerful timestamp types. Perhaps ODBC is a bit special because TIMESTAMP in the SQL standard means WITHOUT TIME ZONE and ODBC  might not be able to make assumptions about the active ODBC driver, however if you can pass a timestamp with timezone to a SQL database I'd strongly suggest to do so because you obtain a CDR table with full information. This makes for a more robust storage backend. If you use timestamp without timezone, you need to get the information what timezone a timestamp is in from a 2nd source -- as it is not guaranteed to be consistent, e.g. always UTC.
You'd also be able to drop the timezone= options from some SQL backends. I also see that cdr_tds does not have such an option in the first place...

(Sorry, one more edit.)
It should also be noted that timestamps without timezone in Postgres always mean UTC [1]. So whenever a non-UTC timestamp is passed to Postgres from Asterisk (entirely permissible with timezone=UTC not set), it's a semantic error. It also makes reporting queries less robust against timezone caveats.

--
[1] https://www.postgresql.org/docs/current/static/datatype-datetime.html#AEN5811, 8.5.1.3. Time Stamps.


By: Early Bird (earlybird) 2016-06-29 01:04:07.234-0500

I also suggest that the configuration for timezone=UTC backend parameters receive more commenting in the sample config files to indicate that any value different from UTC is not supported (set timezone=JST with localtime in JST and the timezone logged in CDR is in JST-JST=UTC).

The name of the key is misleading and suggests that the timezone is actually configurable; it should be a binary option instead. Naming it useutc=yes|no seems much more sensible.
By: cloos (cloos) 2016-06-29 17:26:02.842-0500

One note:

timestamp without timezone SHOULD NOT be used.

It is only there because the ansi std specifies it, but it is always the wrong thing to use.

timestamp with timezone (aka timestamptz) is the right thing to use for any time stamp column.

(Searching on the pgsql lists will show multiple threads pointing that out.)

By: Early Bird (earlybird) 2016-06-29 22:27:07.933-0500

Sharing the following configuration that effectively restores the 1.8 behaviour for us:

Set a schema using timestamps with timezone and Asterisk database timezone to the preferred TZ in pgsql:

{code}
CREATE TABLE cdr (
       id serial NOT NULL,
       start timestamp with time zone NOT NULL,
       answer timestamp with time zone,
       "end" timestamp with time zone NOT NULL,
       clid varchar (80) NOT NULL ,
       src varchar (80) NOT NULL ,
       dst varchar (80) NOT NULL ,
       dcontext varchar (80) NOT NULL ,
       channel varchar (80) NOT NULL ,
       dstchannel varchar (80) NOT NULL ,
       lastapp varchar (80) NOT NULL ,
       lastdata varchar (80) NOT NULL ,
       duration int NOT NULL ,
       billsec int NOT NULL ,
       disposition varchar (45) NOT NULL ,
       amaflags int NOT NULL ,
       accountcode varchar (20) NOT NULL ,
       uniqueid varchar (150) NOT NULL ,
       peeraccount varchar(20) NOT NULL ,
       linkedid varchar(150) NOT NULL ,
       sequence int NOT NULL
);
SET TIMEZONE TO '$YOURTIMEZONE';
{code}

cdr_pgsql.conf:

{code}
timezone=UTC
{code}