Segfaults after updating kopano to 8.7.80.465

john3377

Hello,

I noticed the following on a Debian testing machine.
After upgrading kopano, issues with the new utf encoding occur. Only after recreating a new zpush db solves this. Converting the sql db didnt help here.

But what can not be solved and now leaves kopano in an unusable state, are the segfaults of php. This only happens when using zpush, with the webapp I was not able to crash the php7.3.

z-push-error

09/01/2019 16:16:37 [  733] [WARN] [user] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
09/01/2019 16:16:38 [  730] [ERROR] [user] LoopDetection->ProcessLoopDetectionPreviousConnectionFailed(): Command 'Sync' at 09/01/2019 16:16:36 with pid '666' terminated unexpectedly or is still running.
09/01/2019 16:16:38 [  730] [ERROR] [user] Please check your logs for this PID and errors like PHP-Fatals or Apache segmentation faults and report your results to the Z-Push dev team.
09/01/2019 16:16:38 [  739] [WARN] [user] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
09/01/2019 16:16:39 [  736] [ERROR] [user] LoopDetection->ProcessLoopDetectionPreviousConnectionFailed(): Command 'Sync' at 09/01/2019 16:16:37 with pid '717' terminated unexpectedly or is still running.
09/01/2019 16:16:39 [  736] [ERROR] [user] Please check your logs for this PID and errors like PHP-Fatals or Apache segmentation faults and report your results to the Z-Push dev team.

the crashed task in z-push log:

09/01/2019 16:16:38 [  730] [DEBUG] [user] -------- Start
09/01/2019 16:16:38 [  730] [DEBUG] [user] cmd='Sync' devType='TbSync' devId='xxxx' getUser='user' from='192.168.x.x' version='2.4.5+0-0' method='POST'
09/01/2019 16:16:38 [  730] [DEBUG] [user] Used timezone 'Europe/Berlin'
09/01/2019 16:16:38 [  730] [DEBUG] [user] Including backend file: '/usr/share/z-push/backend/kopano/kopano.php'
09/01/2019 16:16:38 [  730] [DEBUG] [user] BackendKopano using PHP-MAPI version: 8.7.80 - PHP version: 7.3.0-2
09/01/2019 16:16:38 [  730] [DEBUG] [user] SqlStateMachine(): init
09/01/2019 16:16:38 [  730] [DEBUG] [user] SqlStateMachine->checkDbAndTables(): Database and tables exist.
09/01/2019 16:16:38 [  730] [DEBUG] [user] SqlStateMachine->GetStateVersion(): supporting version '2'
09/01/2019 16:16:38 [  730] [DEBUG] [user] Request::ProcessHeaders() ASVersion: 14.0
09/01/2019 16:16:38 [  730] [DEBUG] [user] ZPush::CommandNeedsProvisioning(0): true
09/01/2019 16:16:38 [  730] [DEBUG] [user] SqlStateMachine->GetState(): devid:'xxxx' type:'devicedata' key:'null' counter:'false'
09/01/2019 16:16:38 [  730] [DEBUG] [user] ASDevice data loaded for user: 'user'
09/01/2019 16:16:38 [  730] [DEBUG] [user] TopCollector(): Initialized mutexid Resource id #19 and memid Resource id #20.
09/01/2019 16:16:38 [  730] [DEBUG] [user] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
09/01/2019 16:16:38 [  730] [DEBUG] [user] LoopDetection(): Initialized mutexid Resource id #23 and memid Resource id #24.
09/01/2019 16:16:38 [  730] [DEBUG] [user] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
09/01/2019 16:16:38 [  730] [DEBUG] [user] ZPush::HierarchyCommand(0): false
09/01/2019 16:16:38 [  730] [DEBUG] [user] DeviceManager->ProvisioningRequired('0') saved device key '-1': false
09/01/2019 16:16:38 [  730] [DEBUG] [user] DeviceManager->getPolicyName(): determined policy name: 'default'
09/01/2019 16:16:38 [  730] [DEBUG] [user] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
09/01/2019 16:16:38 [  730] [DEBUG] [user] ZPush::CommandNeedsAuthentication(0): true
09/01/2019 16:16:38 [  730] [DEBUG] [user] KopanoBackend->Logon(): Trying to authenticate user 'user'..
09/01/2019 16:16:38 [  730] [DEBUG] [user] KopanoBackend->openMessageStore('user'): Found 'DEFAULT' store: 'Resource id #35'
09/01/2019 16:16:38 [  730] [DEBUG] [user] KopanoBackend->Logon(): User 'user' is authenticated
09/01/2019 16:16:38 [  730] [DEBUG] [user] Store supports properties containing Unicode characters.
09/01/2019 16:16:38 [  730] [DEBUG] [user] ZPush::CommandNeedsPlainInput(0): false
09/01/2019 16:16:38 [  730] [DEBUG] [user] SqlStateMachine->GetState(): devid:'xxxx' type:'fd' key:'xxx-f684-42e8-a134-xxx' counter:'false'
09/01/2019 16:16:38 [  730] [DEBUG] [user] SyncParameters->UseCPO('CONTACTS')
09/01/2019 16:16:38 [  730] [DEBUG] [user] DeviceManager->GetBackendIdForFolderId(): folderid U8f6d1 => xxxx0a7be9746d0b71xxxxx43febf0c0000000000
09/01/2019 16:16:38 [  730] [DEBUG] [user] SyncCollections->AddCollection(): Folder id 'U8f6d1' : ref. PolicyKey '-1', ref. Lifetime '', last sync at '1547046998'
09/01/2019 16:16:38 [  730] [DEBUG] [user] SyncCollections->AddCollection(): Updated reference PolicyKey '-1', reference Lifetime '', Last sync at '1547046998'
09/01/2019 16:16:38 [  730] [DEBUG] [user] HandleSync(): specified options block with foldertype 'Contacts'
09/01/2019 16:16:38 [  730] [DEBUG] [user] SyncParameters->UseCPO('CONTACTS')
09/01/2019 16:16:38 [  730] [DEBUG] [user] HandleSync(): Start Output
09/01/2019 16:16:38 [  730] [DEBUG] [user] ZPush::GetAdditionalSyncFolderStore('xxxx0a7be9746d0b71xxxxx43febf0c0000000000'): 'false'
09/01/2019 16:16:39 [  736] [DEBUG] [user] -------- Start

kernel log:

[12700.146937] php-fpm7.3[1444]: segfault at 7f30f20002a8 ip 00005634012a372a sp 00007ffca1677340 error 4 in php-fpm7.3[5634010fd000+269000]

Its the same behavior with Apache module.
Hope anyone here has a clue what could help here.

BR,
John

fbartels

Hi @john3377 ,

@john3377 said in Segfaults after updating kopano to 8.7.80.465:

Only after recreating a new zpush db solves this

can you explain what you mean with zpush db? are you storing your sync states in a mysql database?

@john3377 said in Segfaults after updating kopano to 8.7.80.465:

php-fpm7.3

what os are you running with? we are not building packages for any distribution that already delivers php7.3.

john3377

@fbartels said in Segfaults after updating kopano to 8.7.80.465:

can you explain what you mean with zpush db? are you storing your sync states in a mysql database?

Yes, thats right, I am using mysql driver for state machine.

what os are you running with? we are not building packages for any distribution that already delivers php7.3.

As already said, its debian testing. With php7.2 it was working fine.
You need any more information?
Or does this mean z-push on testing is completely not supported and will not work currently?

fbartels

@john3377 said in Segfaults after updating kopano to 8.7.80.465:

on a Debian testing machine

A I read that as a testing machine with Debian. Not a machine with Debian Testing.

The “Debian_testing” packages from our download server are somehow broken, since they are actually still using php7.2 in the build environment. We have already made some changes for php 7.3 for kopano inclusion in debian buster, but since these packages are built against the 7.2 abi you cannot use it on an actual Debian Testing.

(that all excluding the fact that there may still need to be changes pending in z-push itself. for webapp there was also a change needed)

@john3377 said in Segfaults after updating kopano to 8.7.80.465:

Or does this mean z-push on testing is completely not supported and will not work currently?

Generally everything under download.kopano.io/community is not “supported” anyways and merely for evaluation and demonstration. For production setups I would ALLWAYS recommend to use something that is also supported for kopano customers.

john3377

@fbartels said in Segfaults after updating kopano to 8.7.80.465:

A I read that as a testing machine with Debian. Not a machine with Debian Testing.

Ok you are right, thats my fault, sorry.

The “Debian_testing” packages from our download server are somehow broken, since they are actually still using php7.2 in the build environment. We have already made some changes for php 7.3 for kopano inclusion in debian buster, but since these packages are built against the 7.2 abi you cannot use it on an actual Debian Testing.

Are you really sure:
php7-mapi_8.7.80.465.4206adbb5-0+56.1_amd64.deb

dpkg -L php7-mapi 
/.
/usr
/usr/lib
/usr/lib/php
/usr/lib/php/20180731
/usr/lib/php/20180731/mapi.so
/usr/share
/usr/share/doc
/usr/share/doc/php7-mapi
/usr/share/doc/php7-mapi/changelog.Debian.gz
/usr/share/doc/php7-mapi/copyright
/usr/share/kopano
/usr/share/kopano/php
/usr/share/kopano/php/mapi
/usr/share/kopano/php/mapi/mapi.ini

20180731 is since php7.3

Ok, so wait until community releases are working again? :(
Thanks for helping so far!

fbartels

Hmm… maybe then the repo updated itself by now. We were waiting on suse fixing the package sources.

Would need to check this.

john3377

Thanks, so waiting for your feedback then :)

john3377

Felix,

in the meantime I compiled php 7.2.13 and from the included sources in the community repository I compiled mapi.so. As I can tell everything works without any crash or any error message in the logs.
So this issue really seems to be php7.3 related. If its zpush or mapi.so fault, I can not tell.
Hope to hear some news from you :)
Thank you again for everything so far.

BR,
John

fbartels

I have created https://jira.z-hub.io/browse/ZP-1474 to further look into this. Please follow that ticket for updates.

Manfred

Hi John,

I setup a Debian Testing system with KC 8.6.9 and Z-Push develop branch, but there weren’t any segfaults (I tested with PHP as Apache module). Did you get segfaults on every request or in some special cases only?

Manfred

john3377

Hi Manfred!

Sorry for the late reply, but for some reason I am not receiving notifications via email.
With 8.6.9 I am not able to do testings, all I can tell is about community releases and here it does crash. No there is no special use case, just start the sync and there it directly crashes. It may be possible to receive some mails but then the task will be killed.

John

Manfred

Hi John,

I’ve upgraded my test system to KC 8.7.80.476 and still wasn’t able to reproduce it. It still syncs fine.

Did you check the kopano server.log for errors?

Manfred

john3377

Manfred,

I tried again with the following setup:
Debian_Testing updated (18-Jan-2019 17.00)
Kopano_core updated to 8.7.80.468.33841d2aa-0+62.2
Z-Push updated to 2.5.0.alpha0+171.6a717b10-0
PHP version 7.3 fpm used with Apache2.4.37

After synchronizing contacts nothing crashed, but php log shows:

[18-Jan-2019 17:33:44] WARNING: [pool www] child 18264 exited with code 1 after 11.941201 seconds from start
[18-Jan-2019 17:33:44] NOTICE: [pool www] child 18665 started
[18-Jan-2019 17:33:53] WARNING: [pool www] child 18665 exited with code 1 after 8.986156 seconds from start
[18-Jan-2019 17:33:53] NOTICE: [pool www] child 18683 started

After sending a mail, the same happened.
After just waiting a few minutes (~5 mins), in the meanwhile 4 ios devices and 1 Windows10 client connected and then this shows up in the php log:

[18-Jan-2019 17:35:39] WARNING: [pool www] child 18686 exited with code 1 after 106.347941 seconds from start
[18-Jan-2019 17:35:39] NOTICE: [pool www] child 18996 started
[18-Jan-2019 17:35:39] WARNING: [pool www] child 18719 exited with code 1 after 58.427813 seconds from start
[18-Jan-2019 17:35:39] NOTICE: [pool www] child 18997 started
[18-Jan-2019 17:39:17] WARNING: [pool www] child 18996 exited on signal 11 (SIGSEGV) after 218.135177 seconds from start
[18-Jan-2019 17:39:17] NOTICE: [pool www] child 19327 started

Kernel log:

[723133.338392] php-fpm7.3[18996]: segfault at 7f7cdf600208 ip 000055e9a8fc272a sp 00007fffee5f0060 error 4 in php-fpm7.3[55e9a8e1c000+269000]
[723133.338571] Code: 48 8b 05 xx 7b 22 00 8b 10 85 d2 75 5b 48 89 fa 81 xx ff ff 1f 00 74 58 48 89 fe 48 c1 ea 0c 48 83 xx 08 48 81 e6 00 00 e0 ff <8b> 8c xx 00 02 00 00 48 3b 06 0f 85 83 10 e7 ff 85 xx 79 4a 83 e1

Apache proxy timout / max_execution_time set to 4200, so thats not a problem, as with 7.2 its running weeks without any single error in logs.

So for now again changed back to php 7.2 fpm with self compiled mapi.so, everything else stays the same -> nothing in error logs.

And you asked about kopano log, there is nothing shown, but I did not turn on debug level.

John

Manfred

HI John,

can you post your apache, php, php-fpm configs so that I’m able to setup a system as similar as possible to yours?

Manfred

john3377

Hmm, that will be some lines, ok you have been warned :P

/etc/php/7.3/fpm/php.ini:

[PHP]
engine = On
short_open_tag = Off
precision = 14
output_buffering = 4096
zlib.output_compression = Off
implicit_flush = Off
unserialize_callback_func =
serialize_precision = -1
disable_functions = pcntl_alarm,pcntl_fork,pcntl_waitpid,pcntl_wait,pcntl_wifexited,pcntl_wifstopped,pcntl_wifsignaled,pcntl_wifcontinued,pcntl_wexitstatus,pcntl_wtermsig,pcntl_wstopsig,pcntl_signal,pcntl_signal_get_handler,pcntl_signal_dispatch,pcntl_get_last_error,pcntl_strerror,pcntl_sigprocmask,pcntl_sigwaitinfo,pcntl_sigtimedwait,pcntl_exec,pcntl_getpriority,pcntl_setpriority,pcntl_async_signals,
disable_classes =
zend.enable_gc = On
expose_php = Off
max_execution_time = 4200
max_input_time = 60
memory_limit = 128M
error_reporting = E_ALL & ~E_DEPRECATED & ~E_STRICT
display_errors = Off
display_startup_errors = Off
log_errors = On
log_errors_max_len = 1024
ignore_repeated_errors = Off
ignore_repeated_source = Off
report_memleaks = On
html_errors = On
variables_order = "GPCS"
request_order = "GP"
register_argc_argv = Off
auto_globals_jit = On
post_max_size = 8M
auto_prepend_file =
auto_append_file =
default_mimetype = "text/html"
default_charset = "UTF-8"
include_path = ".:/usr/share/php"
doc_root =
user_dir =
enable_dl = Off
file_uploads = On
upload_max_filesize = 100M
max_file_uploads = 20
allow_url_fopen = On
allow_url_include = Off
default_socket_timeout = 60
[CLI Server]
cli_server.color = On
[Date]
date.timezone = Europe/Berlin
[filter]
[iconv]
[intl]
[sqlite3]
[Pcre]
[Pdo]
[Pdo_mysql]
pdo_mysql.default_socket=
[Phar]
[mail function]
SMTP = localhost
smtp_port = 25
mail.add_x_header = Off
[ODBC]
odbc.allow_persistent = On
odbc.check_persistent = On
odbc.max_persistent = -1
odbc.max_links = -1
odbc.defaultlrl = 4096
odbc.defaultbinmode = 1
[Interbase]
ibase.allow_persistent = 1
ibase.max_persistent = -1
ibase.max_links = -1
ibase.timestampformat = "%Y-%m-%d %H:%M:%S"
ibase.dateformat = "%Y-%m-%d"
ibase.timeformat = "%H:%M:%S"
[MySQLi]
mysqli.max_persistent = -1
mysqli.allow_persistent = On
mysqli.max_links = -1
mysqli.default_port = 3306
mysqli.default_socket =
mysqli.default_host =
mysqli.default_user =
mysqli.default_pw =
mysqli.reconnect = Off
[mysqlnd]
mysqlnd.collect_statistics = On
mysqlnd.collect_memory_statistics = Off
[OCI8]
[PostgreSQL]
pgsql.allow_persistent = On
pgsql.auto_reset_persistent = Off
pgsql.max_persistent = -1
pgsql.max_links = -1
pgsql.ignore_notice = 0
pgsql.log_notice = 0
[bcmath]
bcmath.scale = 0
[browscap]
[Session]
session.save_handler = files
session.use_strict_mode = 0
session.use_cookies = 1
session.use_only_cookies = 1
session.name = PHPSESSID
session.auto_start = 0
session.cookie_lifetime = 0
session.cookie_path = /
session.cookie_domain =
session.cookie_httponly =
session.cookie_samesite =
session.serialize_handler = php
session.gc_probability = 0
session.gc_divisor = 1000
session.gc_maxlifetime = 1440
session.referer_check =
session.cache_limiter = nocache
session.cache_expire = 180
session.use_trans_sid = 0
session.sid_length = 26
session.trans_sid_tags = "a=href,area=href,frame=src,form="
session.sid_bits_per_character = 5
[Assertion]
zend.assertions = -1
[COM]
[mbstring]
[gd]
[exif]
[Tidy]
tidy.clean_output = Off
[soap]
soap.wsdl_cache_enabled=1
soap.wsdl_cache_dir="/tmp"
soap.wsdl_cache_ttl=86400
soap.wsdl_cache_limit = 5
[sysvshm]
[ldap]
ldap.max_links = -1
[dba]
[opcache]
[curl]
[openssl]

/etc/php/7.3/fpm/php-fpm.conf:

[global]
pid = /run/php/php7.3-fpm.pid
error_log = /var/log/php7.3-fpm.log
include=/etc/php/7.3/fpm/pool.d/*.conf

/etc/php/7.3/fpm/pool.d/www.conf

[www]
user = www-data
group = www-data
listen = /run/php/php7.3-fpm.sock
listen.owner = www-data
listen.group = www-data
pm = dynamic
pm.max_children = 50
pm.start_servers = 2
pm.min_spare_servers = 2
pm.max_spare_servers = 4
pm.process_idle_timeout = 60s;
pm.max_requests = 2000

/etc/apache2/conf-enabled/php7.3-fpm.conf:

# Redirect to local php-fpm if mod_php is not available
<IfModule !mod_php7.c>
<IfModule proxy_fcgi_module>
    # Enable http authorization headers
    <IfModule setenvif_module>
    SetEnvIfNoCase ^Authorization$ "(.+)" HTTP_AUTHORIZATION=$1
    </IfModule>

    <Proxy "unix:/run/php/php7.3-fpm.sock|fcgi://localhost">
        ProxySet timeout=4200
        ProxySet connectiontimeout=600
    </Proxy>
    <FilesMatch ".+\.ph(ar|p|tml)$">
        SetHandler "proxy:fcgi://localhost"
    </FilesMatch>
    <FilesMatch ".+\.phps$">
        # Deny access to raw php sources by default
        # To re-enable it's recommended to enable access to the files
        # only in specific virtual host or directory
        Require all denied
    </FilesMatch>
    # Deny access to files without filename (e.g. '.php')
    <FilesMatch "^\.ph(ar|p|ps|tml)$">
        Require all denied
    </FilesMatch>
</IfModule>
</IfModule>

In sites-enabled I activated z-push through:

                <Directory /usr/share/z-push>
                        # Don't list a directory index, follow symlinks (maybe state dir is somewhere linked)
                        DirectoryIndex index.php
                        Options -Indexes +FollowSymLinks
                        AllowOverride none
                        Require all granted

                        <Files "config.php">
                                Require all denied
                        </Files>
                </Directory>
                Alias /Microsoft-Server-ActiveSync /usr/share/z-push/index.php
                AliasMatch (?i)/Autodiscover/Autodiscover.xml "/usr/share/z-push/autodiscover/autodiscover.php"

Modules loaded through /etc/apache2/mods-enabled:

access_compat.load -> ../mods-available/access_compat.load
actions.load -> ../mods-available/actions.load
alias.load -> ../mods-available/alias.load
auth_basic.load -> ../mods-available/auth_basic.load
authn_core.load -> ../mods-available/authn_core.load
authn_dbd.load -> ../mods-available/authn_dbd.load
authn_file.load -> ../mods-available/authn_file.load
authz_core.load -> ../mods-available/authz_core.load
authz_groupfile.load -> ../mods-available/authz_groupfile.load
authz_host.load -> ../mods-available/authz_host.load
authz_user.load -> ../mods-available/authz_user.load
autoindex.load -> ../mods-available/autoindex.load
cgi.load -> ../mods-available/cgi.load
dbd.load -> ../mods-available/dbd.load
deflate.load -> ../mods-available/deflate.load
dir.load -> ../mods-available/dir.load
env.load -> ../mods-available/env.load
expires.load -> ../mods-available/expires.load
filter.load -> ../mods-available/filter.load
headers.load -> ../mods-available/headers.load
http2.load -> ../mods-available/http2.load
include.load -> ../mods-available/include.load
info.load -> ../mods-available/info.load
mime.load -> ../mods-available/mime.load
mime_magic.load -> ../mods-available/mime_magic.load
mpm_event.load -> ../mods-available/mpm_event.load
negotiation.load -> ../mods-available/negotiation.load
proxy_fcgi.load -> ../mods-available/proxy_fcgi.load
proxy_http.load -> ../mods-available/proxy_http.load
proxy.load -> ../mods-available/proxy.load
reqtimeout.load -> ../mods-available/reqtimeout.load
rewrite.load -> ../mods-available/rewrite.load
setenvif.load -> ../mods-available/setenvif.load
socache_shmcb.load -> ../mods-available/socache_shmcb.load
ssl.load -> ../mods-available/ssl.load
status.load -> ../mods-available/status.load
userdir.load -> ../mods-available/userdir.load

Did I miss something?

John

Manfred

Hi John,

sorry for not responding earlier. I’ve tested again today taking into account your setting and wasn’t able to reproduce it. There weren’t any apache segfaults.

Manfred

john3377

Hi Manfred,

no problem for the late answer. In the meantime I again tried updated community versions, but still no luck, only recompiling with PHP 7.2 environment is working.
Very strange you are not able to reproduce. Would it be an option if I set-up a VM and send to you?
Btw., with how many mails/accounts did you test?
Thanks for still trying to help :)

BR,
John

Manfred

Hi John,

I’m not an apache expert, so I suggest you to contact the Kopano support regarding this issue.

I’ve tested with a couple of users and few items. It’s not my regular dev system, so it didn’t have a lot of data or high traffic.

Manfred

john3377

Hi!

Today I tested with Z-Push 2.6.0.alpha0+0.29d782bb-0 and with Kopano 8.7.80.856.4dd29f2fc-0+157.1, so far no more issues with PHP 7.3.

Looks like crash got fixed either by zpush or kopano, who knows. Maybe we can close this issue then.
Thanks all.

thctlo

The problem here was, mixed packages for Debian-kopano and Kopano-kopano…
i’ve seen this about 2 weeks ago after a change i made also.
The solution was simple, remove kopano and all its packages and install new, what you basicly also did.
The latest kopano package now have replaces all the Debian packages, which fixed you problem.

I do advice you to checkup all you packages so no Debian-kopano packages are in.
use the kopano packages or the Debian packages avoid mixing them.