Feature-Request: Timestamp or some other correlationID required

  • Used Zammad version: 3.0.0-1560433985.617324d6.bionic
  • Used Zammad installation source: (source, package, …) ubuntu-package
  • Operating system: ubuntu 18.04 x64
  • Browser + version: not relevant

Expected behavior:

  • migrator reports some correlation data to identify issues

Actual behavior:

  • migrator fails with timeouts, but hard to find what is the cause for it

  • output grep cat console.log|grep -E "thread#5:|^[[:blank:]]+from"

thread#5: update Ticket.find_by(id: 35325) thread#5: update Ticket::Article.find_by(id: 3892741) thread#5: loading 20 Ticket starting at 56240... thread#5: POST: https://otrs.example.com/otrs/public.pl?Action=ZammadMigrator thread#5: PARAMS: {:Subaction=>"Export", :Object=>"Ticket", :Limit=>20, :Offset=>56240, :Diff=>0, :Action=>"ZammadMigrator", :Key=>"123456789wert6zuio"} from lib/import/otrs/requester.rb:130:inpost’
from lib/import/otrs/requester.rb:90:in request_json' from lib/import/otrs/requester.rb:77:inrequest_result’
from lib/import/otrs/requester.rb:32:in load' from lib/import/otrs.rb:141:inimport_action’
from lib/import/otrs.rb:135:in imported?' from lib/import/otrs.rb:99:inblock (3 levels) in threaded_import’
from lib/import/otrs.rb:93:in loop' from lib/import/otrs.rb:93:inblock (2 levels) in threaded_import’
thread#5: ERROR: #<Net::ReadTimeout: Net::ReadTimeout>
thread#5: POST: https://otrs.example.com/otrs/public.pl?Action=ZammadMigrator
thread#5: PARAMS: {:Subaction=>“Export”, :Object=>“Ticket”, :Limit=>20, :Offset=>56240, :Diff=>0, :Action=>“ZammadMigrator”, :Key=>“123456789wert6zuio”}
thread#5: ERROR: #<Net::ReadTimeout: Net::ReadTimeout>
thread#5: POST: https://otrs.example.com/otrs/public.pl?Action=ZammadMigrator
thread#5: PARAMS: {:Subaction=>“Export”, :Object=>“Ticket”, :Limit=>20, :Offset=>56240, :Diff=>0, :Action=>“ZammadMigrator”, :Key=>“123456789wert6zuio”}
thread#5: ERROR: #<Net::ReadTimeout: Net::ReadTimeout>
from /opt/zammad/lib/import/otrs/requester.rb:90:in request_json' from /opt/zammad/lib/import/otrs/requester.rb:77:inrequest_result’
from /opt/zammad/lib/import/otrs/requester.rb:32:in load' from /opt/zammad/lib/import/otrs.rb:141:inimport_action’
from /opt/zammad/lib/import/otrs.rb:135:in imported?' from /opt/zammad/lib/import/otrs.rb:99:inblock (3 levels) in threaded_import’
from /opt/zammad/lib/import/otrs.rb:93:in loop' from /opt/zammad/lib/import/otrs.rb:93:inblock (2 levels) in threaded_import’
from /opt/zammad/vendor/bundle/ruby/2.4.0/gems/logging-2.2.2/lib/logging/d`

Steps to reproduce the behavior:

  • run migration from very old OTRS (install 2005; currently running 5.0.x )

Any ideas how to track down the issue? I am missing any correlation to OTRS to get the corresponding error or message from log from OTRS

Did you install the migration plugin beforehand?
https://docs.zammad.org/en/latest/migration-otrs.html

hey come on :wink:
So basic steps are surely done… You see it from the first log message also, that the migration was already running.
So yes, plugin is installed.

Have I not seen some correlationID in the OTRS logs? If so, what is the ID?

Sorry for asking :wink:
@thorsteneckel might be a better partner here :wink:

I am failing with the migration and since of really to few details and also what time the thread was started it seems not to be solvable.

@thorsteneckel any updates on the correlationID (e.g. a timestamp on requests or even better a uuid on OTRS log and zammad-migrator log) to track down my issues?
Maybe also something of these related issues? Are multiple runs of OTRS migrator possible - maybe with yearly migrate runs?

e.g. I am often failing on:

thread#1: loading 20 Ticket starting at 56480...
thread#1: POST: https://otrs.example.com/otrs/public.pl?Action=ZammadMigrator
thread#1: PARAMS: {:Subaction=>"Export", :Object=>"Ticket", :Limit=>20, :Offset=>56480, :Diff=>0, :Action=>"ZammadMigrator", :Key=>"1234567890ßqwertzuiop"}
thread#1: ERROR: #<Net::ReadTimeout: Net::ReadTimeout>
thread#1: POST: https://otrs.example.com/otrs/public.pl?Action=ZammadMigrator
thread#1: PARAMS: {:Subaction=>"Export", :Object=>"Ticket", :Limit=>20, :Offset=>56480, :Diff=>0, :Action=>"ZammadMigrator", :Key=>"1234567890ßqwertzuiop"}
thread#1: ERROR: #<Net::ReadTimeout: Net::ReadTimeout>
thread#1: POST: https://otrs.example.com/otrs/public.pl?Action=ZammadMigrator
thread#1: PARAMS: {:Subaction=>"Export", :Object=>"Ticket", :Limit=>20, :Offset=>56480, :Diff=>0, :Action=>"ZammadMigrator", :Key=>"1234567890ßqwertzuiop"}
thread#1: ERROR: #<Net::ReadTimeout: Net::ReadTimeout>
        from /opt/zammad/lib/import/otrs/requester.rb:90:in "request_json"
        from /opt/zammad/lib/import/otrs/requester.rb:77:in "request_result"
        from /opt/zammad/lib/import/otrs/requester.rb:32:in "load"
        from /opt/zammad/lib/import/otrs.rb:141:in "import_action"
        from /opt/zammad/lib/import/otrs.rb:135:in "imported?"
        from /opt/zammad/lib/import/otrs.rb:99:in "block (3 levels) in threaded_import"
        from /opt/zammad/lib/import/otrs.rb:93:in "loop"
        from /opt/zammad/lib/import/otrs.rb:93:in "block (2 levels) in threaded_import"
        from /opt/zammad/vendor/bundle/ruby/2.4.0/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in "block in create_with_logging_context"

since I cannot correlate the error with OTRS log I am failing to track down the issue

Thorsten currently is quite busy, please give him sime time. :slight_smile:

If you need help NOW and thus need commercial services, please feel free to contact us at sales [at] zammad [dot] com

Hi @xeno,

I can’t see any remarks about the correlationID in the logs. Can you tell me where it comes from?

What I see in the logs is that your OTRS takes to long to answer that HTTP POST request:

thread#5: PARAMS: {:Subaction=>“Export”, :Object=>“Ticket”, :Limit=>20, :Offset=>56240, :Diff=>0, :Action=>“ZammadMigrator”, :Key=>“123456789wert6zuio”}

It runs into a timeout:

thread#5: ERROR: #<Net::ReadTimeout: Net::ReadTimeout>

These timeouts are usually enough but apparently not in your case. You can go and change these in your local installation by tweaking the following numbers:

I can’t see any remarks about the correlationID in the logs. Can you tell me where it comes from?

on multi-systems debugging via log you need something to correlate the log messages. The simpliest one is a timestamp in the logs. This is missing in the migrator.
The better one is to have UUIDs on both sides, so you clearly identify errors independently if you have tons of parallel threads on any system.

What I see in the logs is that your OTRS takes to long to answer that HTTP POST request:

thread#5: PARAMS: {:Subaction=>“Export”, :Object=>“Ticket”, :Limit=>20, :Offset=>56240, :Diff=>0, Action=>“ZammadMigrator”, :Key=>“123456789wert6zuio”}

how do you see it from that log message? I have no clue how you identify the issue from this line?

Thank you for the hint. Changed the timeouts by trippeling them. Will report if this will not work.

Just for clearance, I am referencing here the console output and not the production.log of zammad.
Got the hint from @MrGeneration to also check the production.log which I am running now again.
Anyway please add also the timestamp to the console output

1 Like

after identifying that production.log is containing similar data as the console output but with timestamps, I could track down that my read_timeout of 120sec is still too small. Increased it now to read_timeout=600 along with total_timeout=1800 and rerunning my migration again.
Maybe it helps now…

1 Like

This topic was automatically closed 120 days after the last reply. New replies are no longer allowed.