Time in Segstart filed is 3 hours ahead

[gvag]

I have a strange issue with CMS R14 and ECHI-Converter 0.4.0. All the
records that are stored in a MySQL db, have the segstart and segstop
fields with +3 hrs ahead.
I checked the unix time in the CMS box, i check the time of the
Communication Manager and i check also the time at the box running the
ECHI-Convert tool.

Here are some lines from the database.log:

Fri Oct 17 16:31:03 +0300 2008 (15844) EchiRecord Create
(0.003162) INSERT INTO `echi_records` (`segment`, `vdn9`, `events0`,
`asaiuui`, `cwcdigits`, `cwcs0`, `queuetime`, `events1`, `split1`,
`malicious`, `origholdtime`, `cwcs1`, `firstvdn`, `holdabn`,
`events2`, `split2`, `dispsklevel`, `cwcs2`, `lastobserver`,
`audiodifficulty`, `events3`, `split3`, `observingcall`, `cwcs3`,
`uuilen`, `events4`, `cwcs4`, `segstart`, `eqloc`, `events5`,
`conference`, `talktime`, `duration`, `disptime`, `onholdtime`,
`acdnum`, `agentreleased`, `events6`, `dispivector`, `collectdigits`,
`firstivector`, `origreason`, `calldisp`, `callingII`, `ansreason`,
`dispsplit`, `events7`, `obslocid`, `daqueued`, `events8`,
`consulttime`, `ucid`, `trunkgroup`, `dialednumber`, `dispvdn`,
`vdn2`, `vdn3`, `segstop`, `assist`, `origlocid`, `callid`, `vdn4`,
`transferred`, `tklocid`, `vdn5`, `ringtime`, `callingparty`,
`acwtime`, `answerlocid`, `vdn6`, `holds`, `disppriority`, `vdn7`,
`origlogid`, `anslogid`, `netintime`, `vdn8`) VALUES(1, '', 0, '', '',
'', 0, 0, 0, 'N', 0, '', '222', 'N', 0, -1, 0, '', '', 'N', 0, -1,
'N', '', 0, 0, '', '2008-10-17 19:25:10', '', 0, 'N', 0, 14, 2, 0, 1,
'N', 0, 13, '', 13, 0, 1, '', 0, 0, 0, 0, 'N', 0, 0,
'00001000151224249900', 0, '222', '222', '', '', '2008-10-17
19:25:24', 'N', 0, 3574, '', 'N', 0, '', 0, '107', 0, 0, '', 0, 4, '',
'', '', 0, '')
Fri Oct 17 16:31:03 +0300 2008 (15844) EchiRecord Create
(0.002429) INSERT INTO `echi_records` (`segment`, `vdn9`, `events0`,
`asaiuui`, `cwcdigits`, `cwcs0`, `queuetime`, `events1`, `split1`,
`malicious`, `origholdtime`, `cwcs1`, `firstvdn`, `holdabn`,
`events2`, `split2`, `dispsklevel`, `cwcs2`, `lastobserver`,
`audiodifficulty`, `events3`, `split3`, `observingcall`, `cwcs3`,
`uuilen`, `events4`, `cwcs4`, `segstart`, `eqloc`, `events5`,
`conference`, `talktime`, `duration`, `disptime`, `onholdtime`,
`acdnum`, `agentreleased`, `events6`, `dispivector`, `collectdigits`,
`firstivector`, `origreason`, `calldisp`, `callingII`, `ansreason`,
`dispsplit`, `events7`, `obslocid`, `daqueued`, `events8`,
`consulttime`, `ucid`, `trunkgroup`, `dialednumber`, `dispvdn`,
`vdn2`, `vdn3`, `segstop`, `assist`, `origlocid`, `callid`, `vdn4`,
`transferred`, `tklocid`, `vdn5`, `ringtime`, `callingparty`,
`acwtime`, `answerlocid`, `vdn6`, `holds`, `disppriority`, `vdn7`,
`origlogid`, `anslogid`, `netintime`, `vdn8`) VALUES(1, '', 0, '', '',
'', 0, 0, -1, 'N', 0, '', '628', 'N', 0, -1, 0, '', '', 'N', 0, -1,
'N', '', 0, 0, '', '2008-10-17 19:24:58', '', 0, 'N', 0, 90, 7, 0, 1,
'N', 0, 28, '', 28, 0, 1, '', 0, -1, 0, 0, 'N', 0, 0,
'00001000141224249897', 0, '628', '628', '', '', '2008-10-17
19:26:28', 'N', 0, 3575, '', 'N', 0, '', 0, '606', 0, 0, '', 0, 0, '',
'', '', 0, '')
Fri Oct 17 16:31:03 +0300 2008 (15844) SQL (0.005556) COMMIT
Fri Oct 17 16:31:03 +0300 2008 (15844) SQL (0.003537) BEGIN
Fri Oct 17 16:31:03 +0300 2008 (15844) EchiLog Create (0.002307)
INSERT INTO `echi_logs` (`filenumber`, `processedat`, `version`,
`records`, `filename`) VALUES(308, '2008-10-17 16:31:03', 12, 31,
'chr0203')
Fri Oct 17 16:31:03 +0300 2008 (15844) SQL (0.003690) COMMIT

You will notice that even the record is processed on 16:31 the
segstart field has 19:24:58.

Any idea on how to fix this?

Regards
George

[JasonGoecke]

This is strange. ECHI does nothing to process the time, simply takes
what is in the file and inserts it into the database. If you could
post one of your files that is '3 hours' ahead with the time that it
should have been, we may see if the source is in the file itself or
somewhere else along the way.

Have not seen this one before.

[gvag]

Jason,

Please find the last file i got today with '3 hours' ahead. Its the
binary i received from CMS.

http://www.2shared.com/file/4146401/b41ea9c7/chr0524.html

Thanks

[gvag]

I have uploaded the file (chr0524) also here.

On Oct 18, 5:18 pm, JasonGoecke <jsgoe...@gmail.com> wrote:

[JasonGoecke]

Alright, I extracted the methods into a little script that allows you
to simply look at the contents of the files without doing any process.
The utility 'echi-file-eval' may be found here:

http://github.com/jsgoecke/echi-file-eval/tree/master

I parsed your file that you provided and got this:

http://gist.github.com/20591

You may see the first segstart/stop here:

segstart { type => datetime & length => 4 } value => Thu Oct 23
07:30:44 -0700 2008
segstop { type => datetime & length => 4 } value => Thu Oct 23
07:31:25 -0700 2008

And the last one here:

segstart { type => datetime & length => 4 } value => Thu Oct 23
07:54:27 -0700 2008
segstop { type => datetime & length => 4 } value => Thu Oct 23
07:59:51 -0700 2008

As you may see from the script there is nothing being done to the data
except a simple binary conversion, and in this case the way the
segstart/stop are converted is:

http://gist.github.com/20593

So, the date is just being created from the Ruby Time class using the
binary unpacked. If these times are three hours off, I would look to
the CMS as the culprit. I can not tell, as you did not mention the
time you were expecting.

Let us know.

[gvag]

Thanks Jason.

I will check the files using your script and i will let you know....

Regards

[gvag]

Jason,

Checking the file i can see that the timestamp is 3 hours ahead, that
means the problem is on the CMS. But since solaris date/time is
correct where could be the problem, any idea?

[JasonGoecke]

When it comes to the Avaya specific issues on the CMS, unfortunately
you would need to get in touch with Avaya or your support vendor.
Someone else here might know, but I do not.

Thanks for coming back to us and good luck!