Mr Auto-Accept wont work

Coffee_is_life

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

Coffee_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

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

fbartels

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.

Coffee_is_life

@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

fbartels

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

Coffee_is_life

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

fbartels

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.

mkromer

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