Mr Auto-Accept wont work



  • Hello, Coffe_is_life here again :),

    i’ve ran into another problem which i cant solve myself.

    In Kopano there is a funktion called mr-Accept (–mr-accept y). We used this function in ZCP 7.1.x and this worked.
    After Upgrading to 7.2.4 it stopped working but we did no action because we were about to migrate :).

    Now i’ve detected that this problem is persistent.
    What i’ve tried so far:

    Use mr-accept on different Zarafa/Kopano Types (rooms, shared-store-only, active user and equipment)
    Disable and enable
    Send the request from Outlook2016 (via Z-push 2.3.5+5) and Webapp 3.2.0.335-19.1.

    maillog:

    May  8 16:16:56 SERVER postfix/lmtp[18201]: DD7D72473B: to=<Besprechungsraum-2@DOMAIN>, relay=localhost[127.0.0.1]:2003, delay=3.5, delays=0.52/0.12/0.36/2.5, dsn=2.1.5, status=sent (250 2.1.5 Besprechungsraum-2@DOMAIN Ok)
    May  8 16:16:56 SERVER postfix/lmtp[18201]: DD7D72473B: to=<mailarchiv@DOMAIN>, relay=localhost[127.0.0.1]:2003, delay=3.5, delays=0.52/0.12/0.36/2.5, dsn=2.1.5, status=sent (250 2.1.5 mailarchiv@DOMAIN Ok)
    May  8 16:16:56 SERVER postfix/qmgr[11038]: DD7D72473B: removed
    

    No Message was send by “Besprechungsraum-2” it only received my tries.

    Nothing was logged in kopano/Server.log

    dagent.log:

    Mon May  8 16:16:53 2017: [notice ] [19461] Resolved recipient Besprechungsraum-2@meyer-jumbo.de as user Besprechungsraum-2
    Mon May  8 16:16:53 2017: [notice ] [19461] Resolved recipient mailarchiv@meyer-jumbo.de as user mailarchiv
    Mon May  8 16:16:53 2017: [info   ] [19461] * Loading plugins started
    Mon May  8 16:16:53 2017: [info   ] [19461] ** Checking plugins in /var/lib/kopano/dagent/plugins
    Mon May  8 16:16:53 2017: [info   ] [19461] * Loading plugins done
    Mon May  8 16:16:53 2017: [notice ] [19451] Message canceled by rule
    Mon May  8 16:16:54 2017: [info   ] [19451] Finished processing message
    Mon May  8 16:16:54 2017: [info   ] [19461] Mail will be delivered in Inbox
    Mon May  8 16:16:54 2017: [info   ] [19451] LMTP thread exiting
    Mon May  8 16:16:54 2017: [info   ] [19461] * PostConverting processing started
    Mon May  8 16:16:54 2017: [info   ] [19461] * PostConverting processing done
    Mon May  8 16:16:54 2017: [info   ] [19461] * PreDelivery processing started
    Mon May  8 16:16:54 2017: [info   ] [19461] * PreDelivery processing done
    Mon May  8 16:16:54 2017: [info   ] [19461] Starting MR auto processing
    Mon May  8 16:16:54 2017: [info   ] [19461] Command `/usr/sbin/kopano-mr-process "Besprechungsraum-2" "/etc/kopano/dagent.cfg" "00000000CD88F178B5E84AFDB13AE7B4EB31406A0100000005000000E0E863F2CD454546AB3B249E5BC2A0F500000000"` ran successfully
    Mon May  8 16:16:54 2017: [info   ] [19461] Automatic MR processing successful.
    Mon May  8 16:16:54 2017: [info   ] [19461] Starting MR autoaccepter
    Mon May  8 16:16:54 2017: [info   ] [19461] Command `/usr/sbin/kopano-mr-accept "Besprechungsraum-2" "/etc/kopano/dagent.cfg" "00000000CD88F178B5E84AFDB13AE7B4EB31406A0100000005000000835E561B8B374F3FA373FD93B9286F7200000000"` ran successfully
    Mon May  8 16:16:54 2017: [info   ] [19461] Autoaccept processing completed successfully. Skipping further processing.
    Mon May  8 16:16:54 2017: [info   ] [19461] Mail will be delivered in Inbox
    Mon May  8 16:16:54 2017: [info   ] [19461] * PreDelivery processing started
    Mon May  8 16:16:54 2017: [info   ] [19461] * PreDelivery processing done
    Mon May  8 16:16:55 2017: [info   ] [19461] Starting MR auto processing
    Mon May  8 16:16:55 2017: [info   ] [19461] Command `/usr/sbin/kopano-mr-process "mailarchiv" "/etc/kopano/dagent.cfg" "00000000E2F87A35001C4C1E940A97269064C6100100000005000000C61946F41E7447798586CD4A3E43C42300000000"` ran successfully
    Mon May  8 16:16:56 2017: [info   ] [19461] Automatic MR processing successful.
    Mon May  8 16:16:56 2017: [info   ] [19461] * PreRuleProcess processing started
    Mon May  8 16:16:56 2017: [info   ] [19461] * PreRuleProcess processing done
    Mon May  8 16:16:56 2017: [info   ] [19461] * PostDelivery processing started
    Mon May  8 16:16:56 2017: [info   ] [19461] * PostDelivery processing done
    Mon May  8 16:16:56 2017: [info   ] [19461] * SendNewMailNotify processing started
    Mon May  8 16:16:56 2017: [info   ] [19461] * SendNewMailNotify processing done
    Mon May  8 16:16:56 2017: [info   ] [19461] Delivered message to 'mailarchiv', Subject: "Testibus", Message-Id: <kcim.59107dd4.4bfc.40d54df46bde5778@SERVER.DOMAIN>, size 3340
    Mon May  8 16:16:56 2017: [info   ] [19461] Finished processing message
    Mon May  8 16:16:56 2017: [info   ] [19461] LMTP thread exiting
    

    spooler.log

    Mon May  8 16:16:52 2017: [info   ] [19452] * Loading plugins started
    Mon May  8 16:16:52 2017: [info   ] [19452] ** Checking plugins in /var/lib/kopano/spooler/plugins
    Mon May  8 16:16:52 2017: [info   ] [19452] * Loading plugins done
    Mon May  8 16:16:52 2017: [info   ] [19452] Sending e-mail for user <USER>, size: 2253
    Mon May  8 16:16:52 2017: [info   ] [19452] * PreSending processing started
    Mon May  8 16:16:52 2017: [info   ] [19452] * PreSending processing done
    Mon May  8 16:16:52 2017: [info   ] [19452] Adding ICS attachment for extra information
    Mon May  8 16:16:53 2017: [info   ] [  721] Processed message for user <USER>
     
    

    The Inbox contains just the canceled message when i deleted this test-entry.
    The Outbox contains no messages sinbce we changed to ZCP 7.2.4 (and later the week to KC 8.2.1-530)

    Any Suggestions?

    Thanks,

    Coffe_is_life



  • I’ve did some research and found something interesting:

    i used “/usr/sbin/kopano-mr-accept “Besprechungsraum-2” “/etc/kopano/dagent.cfg”” without an entryID (If <entryid> is not specified, all unresponded MR’s in the inbox are processed)
    Output:

    Policy is 7
    Resource capacity is 1
    Found 6 items to process
    Processing item with entryid 00000000cd88f178b5e84afdb13ae7b4eb31406a010000000500000090ce8ebb2fba4875bba9d1d5466def9900000000
    PHP Warning:  Missing argument 1 for Meetingrequest::doRemoveFromCalendar(), called in /usr/sbin/kopano-mr-accept on line 425 and defined in /usr/share/kopano/php/mapi/class.meetingrequest.php on line 1107
    Removed canceled meeting
    Processing item with entryid 00000000cd88f178b5e84afdb13ae7b4eb31406a0100000005000000802cdfa1ddcd48bebd793628e87a6f0e00000000
    PHP Warning:  Missing argument 1 for Meetingrequest::doRemoveFromCalendar(), called in /usr/sbin/kopano-mr-accept on line 425 and defined in /usr/share/kopano/php/mapi/class.meetingrequest.php on line 1107
    Removed canceled meeting
    Processing item with entryid 00000000cd88f178b5e84afdb13ae7b4eb31406a0100000005000000283856a043fb439db68b40a3191d5ba600000000
    PHP Warning:  Missing argument 1 for Meetingrequest::doRemoveFromCalendar(), called in /usr/sbin/kopano-mr-accept on line 425 and defined in /usr/share/kopano/php/mapi/class.meetingrequest.php on line 1107
    Removed canceled meeting
    Processing item with entryid 00000000cd88f178b5e84afdb13ae7b4eb31406a01000000050000006d82b3477edc428f9bb534295798aa7a00000000
    PHP Warning:  Missing argument 1 for Meetingrequest::doRemoveFromCalendar(), called in /usr/sbin/kopano-mr-accept on line 425 and defined in /usr/share/kopano/php/mapi/class.meetingrequest.php on line 1107
    Removed canceled meeting
    Processing item with entryid 00000000cd88f178b5e84afdb13ae7b4eb31406a01000000050000004997b782b05b4903ba26b5b0fcd8795f00000000
    PHP Warning:  strftime(): It is not safe to rely on the system's timezone settings. You are *required* to use the date.timezone setting or the date_default_timezone_set() function. In case you used any of those methods and you are still getting this warning, you most likely misspelled the timezone identifier. We selected the timezone 'UTC' for now, but please set date.timezone to select your timezone. in /usr/sbin/kopano-mr-accept on line 363
    PHP Warning:  strftime(): It is not safe to rely on the system's timezone settings. You are *required* to use the date.timezone setting or the date_default_timezone_set() function. In case you used any of those methods and you are still getting this warning, you most likely misspelled the timezone identifier. We selected the timezone 'UTC' for now, but please set date.timezone to select your timezone. in /usr/sbin/kopano-mr-accept on line 363
    Checking availability from 01.03.2017 12:00:00 to 01.03.2017 13:00:00
    Found 0 overlapping records
    Overlap depth is 0
    Accepted.
    Accept updated.
    Processing item with entryid 00000000cd88f178b5e84afdb13ae7b4eb31406a0100000005000000420f8d58fdf04bd496126b4bcf98fb2b00000000
    PHP Warning:  Missing argument 1 for Meetingrequest::doRemoveFromCalendar(), called in /usr/sbin/kopano-mr-accept on line 425 and defined in /usr/share/kopano/php/mapi/class.meetingrequest.php on line 1107
    Removed canceled meeting
    

    //EDIT: The MRs are accepted if i run "/usr/sbin/kopano-mr-accept “Besprechungsraum-2” “/etc/kopano/dagent.cfg” " manually or from crontab (my workaround here - but its not a solution)
    //EDIT2: if i run this manually or via cronjob, there is no check if this time is already booked. - I dont think i can solve this with a workaround. - feel free to convince me of the opposite
    Maybe someone can give me some hints :)

    Coffee_is_Life



  • lets reanimate this thread, because this occured today:
    we got ressources which auto-accepts meetings via mr-accept.
    in dagent.log:

    [info   ] [ 8831] Automatic MR processing failed: call failed (80004005).
    

    if called the script manually:

    /usr/sbin/kopano-mr-accept "Besprechungsraum-2" "/etc/kopano/dagent.cfg"
    PHP Warning:  include(mapi/mapi.util.php): failed to open stream: No such file or directory in /usr/sbin/kopano-mr-accept on line 21
    PHP Warning:  include(): Failed opening 'mapi/mapi.util.php' for inclusion (include_path='.:/usr/share/pear:/usr/share/php') in /usr/sbin/kopano-mr-accept on line 21
    PHP Warning:  include(mapi/mapidefs.php): failed to open stream: No such file or directory in /usr/sbin/kopano-mr-accept on line 22
    PHP Warning:  include(): Failed opening 'mapi/mapidefs.php' for inclusion (include_path='.:/usr/share/pear:/usr/share/php') in /usr/sbin/kopano-mr-accept on line 22
    PHP Warning:  include(mapi/mapicode.php): failed to open stream: No such file or directory in /usr/sbin/kopano-mr-accept on line 23
    PHP Warning:  include(): Failed opening 'mapi/mapicode.php' for inclusion (include_path='.:/usr/share/pear:/usr/share/php') in /usr/sbin/kopano-mr-accept on line 23
    PHP Warning:  include(mapi/mapitags.php): failed to open stream: No such file or directory in /usr/sbin/kopano-mr-accept on line 24
    PHP Warning:  include(): Failed opening 'mapi/mapitags.php' for inclusion (include_path='.:/usr/share/pear:/usr/share/php') in /usr/sbin/kopano-mr-accept on line 24
    PHP Warning:  include(mapi/mapiguid.php): failed to open stream: No such file or directory in /usr/sbin/kopano-mr-accept on line 25
    PHP Warning:  include(): Failed opening 'mapi/mapiguid.php' for inclusion (include_path='.:/usr/share/pear:/usr/share/php') in /usr/sbin/kopano-mr-accept on line 25
    PHP Warning:  include(mapi/class.meetingrequest.php): failed to open stream: No such file or directory in /usr/sbin/kopano-mr-accept on line 27
    PHP Warning:  include(): Failed opening 'mapi/class.meetingrequest.php' for inclusion (include_path='.:/usr/share/pear:/usr/share/php') in /usr/sbin/kopano-mr-accept on line 27
    PHP Warning:  include(mapi/class.baserecurrence.php): failed to open stream: No such file or directory in /usr/sbin/kopano-mr-accept on line 28
    PHP Warning:  include(): Failed opening 'mapi/class.baserecurrence.php' for inclusion (include_path='.:/usr/share/pear:/usr/share/php') in /usr/sbin/kopano-mr-accept on line 28
    PHP Warning:  include(mapi/class.recurrence.php): failed to open stream: No such file or directory in /usr/sbin/kopano-mr-accept on line 29
    PHP Warning:  include(): Failed opening 'mapi/class.recurrence.php' for inclusion (include_path='.:/usr/share/pear:/usr/share/php') in /usr/sbin/kopano-mr-accept on line 29
    PHP Warning:  include(mapi/class.freebusypublish.php): failed to open stream: No such file or directory in /usr/sbin/kopano-mr-accept on line 30
    PHP Warning:  include(): Failed opening 'mapi/class.freebusypublish.php' for inclusion (include_path='.:/usr/share/pear:/usr/share/php') in /usr/sbin/kopano-mr-accept on line 30
    PHP Fatal error:  Call to undefined function forceUTF8() in /usr/sbin/kopano-mr-accept on line 436
    

    if changed the first line in the script to
    “#!/opt/rh/rh-php56/root/usr/bin/php” as suggested in another thread which solved my problem in the past:

    Processing item with entryid 00000000cd88f178b5e84afdb13ae7b4eb31406a0100000005000000d19a59b69a964d1082a1d866a2da5e7400000000
    PHP Warning:  strftime(): It is not safe to rely on the system's timezone settings. You are *required* to use the date.timezone setting or the date_default_timezone_set() function. In case you used any of those methods and you are still getting this warning, you most likely misspelled the timezone identifier. We selected the timezone 'UTC' for now, but please set date.timezone to select your timezone. in /usr/sbin/kopano-mr-accept on line 364
    PHP Warning:  strftime(): It is not safe to rely on the system's timezone settings. You are *required* to use the date.timezone setting or the date_default_timezone_set() function. In case you used any of those methods and you are still getting this warning, you most likely misspelled the timezone identifier. We selected the timezone 'UTC' for now, but please set date.timezone to select your timezone. in /usr/sbin/kopano-mr-accept on line 364
    Checking availability from 20.03.2018 12:00:00 to 20.03.2018 14:30:00
    Found 1 overlapping records
    Overlap depth is 0
    Failed to accept: 0x0
    Processing item with entryid 00000000cd88f178b5e84afdb13ae7b4eb31406a0100000005000000169c09751b5840a79314c8274220739900000000
    PHP Warning:  strftime(): It is not safe to rely on the system's timezone settings. You are *required* to use the date.timezone setting or the date_default_timezone_set() function. In case you used any of those methods and you are still getting this warning, you most likely misspelled the timezone identifier. We selected the timezone 'UTC' for now, but please set date.timezone to select your timezone. in /usr/sbin/kopano-mr-accept on line 364
    PHP Warning:  strftime(): It is not safe to rely on the system's timezone settings. You are *required* to use the date.timezone setting or the date_default_timezone_set() function. In case you used any of those methods and you are still getting this warning, you most likely misspelled the timezone identifier. We selected the timezone 'UTC' for now, but please set date.timezone to select your timezone. in /usr/sbin/kopano-mr-accept on line 364
    Checking availability from 20.03.2018 15:00:00 to 20.03.2018 16:00:00
    Found 1 overlapping records
    Overlap depth is 0
    Failed to accept: 0x0
    Processing item with entryid 00000000cd88f178b5e84afdb13ae7b4eb31406a0100000005000000b997a86359494d8092a52e6a9ae8ba9500000000
    PHP Warning:  strftime(): It is not safe to rely on the system's timezone settings. You are *required* to use the date.timezone setting or the date_default_timezone_set() function. In case you used any of those methods and you are still getting this warning, you most likely misspelled the timezone identifier. We selected the timezone 'UTC' for now, but please set date.timezone to select your timezone. in /usr/sbin/kopano-mr-accept on line 364
    PHP Warning:  strftime(): It is not safe to rely on the system's timezone settings. You are *required* to use the date.timezone setting or the date_default_timezone_set() function. In case you used any of those methods and you are still getting this warning, you most likely misspelled the timezone identifier. We selected the timezone 'UTC' for now, but please set date.timezone to select your timezone. in /usr/sbin/kopano-mr-accept on line 364
    Checking availability from 19.03.2018 09:30:00 to 19.03.2018 10:00:00
    Found 1 overlapping records
    Overlap depth is 0
    Failed to accept: 0x0
    Processing item with entryid 00000000cd88f178b5e84afdb13ae7b4eb31406a01000000050000000fa05b43337a4839953e7df8e659786c00000000
    PHP Warning:  strftime(): It is not safe to rely on the system's timezone settings. You are *required* to use the date.timezone setting or the date_default_timezone_set() function. In case you used any of those methods and you are still getting this warning, you most likely misspelled the timezone identifier. We selected the timezone 'UTC' for now, but please set date.timezone to select your timezone. in /usr/sbin/kopano-mr-accept on line 364
    PHP Warning:  strftime(): It is not safe to rely on the system's timezone settings. You are *required* to use the date.timezone setting or the date_default_timezone_set() function. In case you used any of those methods and you are still getting this warning, you most likely misspelled the timezone identifier. We selected the timezone 'UTC' for now, but please set date.timezone to select your timezone. in /usr/sbin/kopano-mr-accept on line 364
    Checking availability from 21.03.2018 08:00:00 to 21.03.2018 10:00:00
    Found 1 overlapping records
    Overlap depth is 0
    Failed to accept: 0x0
    [...]
    

    the line which faled with this error:

    364:   debugLog("Checking availability from " . strftime("%x %X", $start) . " to " . strftime("%x %X", $end) . "\n");
    

    i think its because the auto-accept did its job and accepted this item in the past (was shown in the calendar) but didnt delete this entry and thought this need to be answered.

    but i cant figure out why the log said “Automatic MR processing failed: call failed (80004005).” and btw in INFO mode…

    any help is appriciated

    coffee_is_life


  • Kopano

    I’d recommend to give the python variants of mr-accept and mr-process a try. These will also be set as the default for the 8.7 releases.

    If there is an issue with a meeting request the 8.6 release onwards (at least I don’t think it was merged to 8.5) will now also generate a raw export of the failed message so that our support can more easily reproduce the issue with it.



  • @fbartels
    how do i use the python equivalent?
    tried

    python /usr/sbin/kopano-mr-accept.py "user" "/etc/kopano/dagent.cfg"
    python /usr/sbin/kopano-mr-accept.py -u "user" "/etc/kopano/dagent.cfg"
    python /usr/sbin/kopano-mr-accept.py -u "user" -c "/etc/kopano/dagent.cfg"
    and more
    

    but i get errors that the arguments are wrong or too few

    searched for a doku but couldnt find it.

    coffee_is_life


  • Kopano

    The python scripts are direct drop in replacements of their php variants. The parameters are identical.



  • then i get this error:

    python /usr/sbin/kopano-mr-accept.py "Besprechungsraum-2" "/etc/kopano/dagent.cfg"
    Traceback (most recent call last):
      File "/usr/sbin/kopano-mr-accept.py", line 113, in <module>
        main()
      File "/usr/sbin/kopano-mr-accept.py", line 82, in main
        username, config, entryid = [_decode(arg) for arg in sys.argv[1:]]
    ValueError: need more than 2 values to unpack
    

    coffee_is_life


  • Kopano

    Hi @coffee_is_life ,

    I have to rephrase the “identical” it seems. The python variants are drop in replacements when it comes to how the scripts are used within the dagent. But in contrast to the php version it does not process all messages in the inbox, but always needs to be called with an entryid for a mail.


  • Kopano

    Update: With today’s PR being processed, it will be possible to call the python variant without any entryid.

    Keep an eye on: https://jira.kopano.io/browse/KC-1165

    Thanks for the report.

    -mike