[gogocarto] auto update from json doesn't work #15

data --> dynamic import

I put the update frequency at 1

But it never worked.

39 KiB

Went to carte.laroue.org to have a look.

This is the output of:

tail /srv/datastore/data/cron/var/log/cron/gogocarto-checkExternalSourceToUpdate_script.log

..
2021-05-24 00:00:12 UTC 00:00:12 ERROR     [commands] Error executing command: No servers yet eligible for rescan</br>/opt/apps/gogocarto/vendor/alcaeus/mongo-php-adapter/lib/Alcaeus/MongoDbAdapter/ExceptionConverter.php LINE 92
2021-05-24 00:00:12 UTC 00:00:12 ERROR     [console] Error thrown while running command "app:elements:checkExternalSourceToUpdate". Message: "No servers yet eligible for rescan" ["exception" => MongoConnectionException { …},"command" => "app:elements:checkExternalSourceToUpdate","message" => "No servers yet eligible for rescan"]
2021-05-24 00:00:12 UTC 
2021-05-24 00:00:12 UTC In ExceptionConverter.php line 92:
2021-05-24 00:00:12 UTC                                       
2021-05-24 00:00:12 UTC   No servers yet eligible for rescan  
2021-05-24 00:00:12 UTC                                       
2021-05-24 00:00:12 UTC 
2021-05-24 00:00:12 UTC In functions.php line 431:
2021-05-24 00:00:12 UTC                                       
2021-05-24 00:00:12 UTC   No servers yet eligible for rescan  
2021-05-24 00:00:12 UTC                                       
2021-05-24 00:00:12 UTC 
..

It seems there's custom code (via getCustomCode()) that generates a bug, but probably because of a problem contacting mongodb.

09:54:20 WARNING   [php] Warning: trim() expects parameter 1 to be string, array given
[
  "exception" => ErrorException {
    #message: "Warning: trim() expects parameter 1 to be string, array given"
    #code: 0
    #file: "/opt/apps/gogocarto/src/Services/ElementImportMappingService.php(45) : eval()'d code"
    #line: 32
    #severity: E_WARNING
    trace: {
      ./src/Services/ElementImportMappingService.php:45 {
        eval^
        › // Execute custom code (the <?php is used to have proper code highliting in text editor, we remove it before executing)
        › eval(str_replace('<?php', '', $import->getCustomCode()));
        › if (null == $data || !is_array($data)) {
      }
      ./src/Services/ElementImportMappingService.php:45 { …}
      ./src/Services/ElementImportService.php:143 { …}
      ./src/Services/ElementImportService.php:114 { …}
      ./src/Services/ElementImportService.php:57 { …}
      ./src/Command/CheckExternalSourceToUpdateCommand.php:44 { …}
      ./src/Command/GoGoAbstractCommand.php:56 { …}
      ./vendor/symfony/console/Command/Command.php:255 { …}
      ./vendor/symfony/console/Application.php:1027 { …}
      ./vendor/symfony/framework-bundle/Console/Application.php:97 { …}
      ./vendor/symfony/console/Application.php:273 { …}
      ./vendor/symfony/framework-bundle/Console/Application.php:83 { …}
      ./vendor/symfony/console/Application.php:149 { …}
      ./bin/console:43 { …}
    }
  }
]

I see also that I have an error 500 when trying to access to the definition of the "import dynamique" in the UI.

Here are the logs:

[2021-05-24 10:08:14] request.CRITICAL: Exception thrown when handling an exception (MongoConnectionException: No suitable servers found (`serverSelectionTryOnce` set): [connection refused calling ismaster on 'mongo:27017'] at /opt/apps/gogocarto/vendor/alcaeus/mongo-php-adapter/lib/Alcaeus/MongoDbAdapter/ExceptionConverter.php line 85) {"exception":"[object] (MongoConnectionException(code: 13053): No suitable servers found (`serverSelectionTryOnce` set): [connection refused calling ismaster on 'mongo:27017'] at /opt/apps/gogocarto/vendor/alcaeus/mongo-php-adapter/lib/Alcaeus/MongoDbAdapter/ExceptionConverter.php:85, MongoDB\\Driver\\Exception\\ConnectionTimeoutException(code: 13053): No suitable servers found (`serverSelectionTryOnce` set): [connection refused calling ismaster on 'mongo:27017'] at /opt/apps/gogocarto/vendor/mongodb/mongodb/src/functions.php:431)"} []

If we check mongodb logs, each time I do a checkExternalSourceToUpdate or I try to edit the source in the UI:

2021-05-24T11:50:52.640+0000 I NETWORK  [listener] connection accepted from 172.18.0.14:57408 #93 (24 connections now open)
2021-05-24T11:50:52.644+0000 I NETWORK  [conn93] received client metadata from 172.18.0.14:57408 conn93: { driver: { name: "mongoc / ext-mongodb:PHP / PHPLIB", version: "1.17.2 / 1.9.0 / 1.7.1" }, os: { type: "Linux", name: "Debian GNU/Linux", version: "10", architecture: "x86_64" }, platform: "PHP 7.4.1cfg=0x03d156a8e9 posix=200809 stdc=201710 CC=GCC 8.3.0 CFLAGS="" LDFLAGS=""" }
2021-05-24T11:50:59.227+0000 F -        [conn93] Invalid access at address: 0
2021-05-24T11:50:59.227+0000 F -        [conn93] Got signal: 11 (Segmentation fault).
This platform does not support printing stacktraces

The kernel logs:

May 24 11:53:14 gestion kernel: [5801932.415209] conn23[25611]: segfault at 0 ip 00005610b1b4f350 sp 00007f43b4cb7448 error 4 in mongod[5610b0aac000+1b81000]
May 24 11:53:14 gestion kernel: [5801932.421117] Code: 84 c0 0f 84 08 5a 0e ff 49 8b 46 40 4c 8b 45 a8 e9 fb fe ff ff e8 90 e5 f5 fe e9 01 5a 0e ff e9 0c 5a 0e ff 66 0f 1f 44 00 00 <48> 8b 06 48 85 c0 74 30 48 89 c2 48 81 e2 00 00 f0 ff 48 81 ca e8

Went to `carte.laroue.org` to have a look. This is the output of: ``` tail /srv/datastore/data/cron/var/log/cron/gogocarto-checkExternalSourceToUpdate_script.log ``` ``` .. 2021-05-24 00:00:12 UTC 00:00:12 ERROR [commands] Error executing command: No servers yet eligible for rescan</br>/opt/apps/gogocarto/vendor/alcaeus/mongo-php-adapter/lib/Alcaeus/MongoDbAdapter/ExceptionConverter.php LINE 92 2021-05-24 00:00:12 UTC 00:00:12 ERROR [console] Error thrown while running command "app:elements:checkExternalSourceToUpdate". Message: "No servers yet eligible for rescan" ["exception" => MongoConnectionException { …},"command" => "app:elements:checkExternalSourceToUpdate","message" => "No servers yet eligible for rescan"] 2021-05-24 00:00:12 UTC 2021-05-24 00:00:12 UTC In ExceptionConverter.php line 92: 2021-05-24 00:00:12 UTC 2021-05-24 00:00:12 UTC No servers yet eligible for rescan 2021-05-24 00:00:12 UTC 2021-05-24 00:00:12 UTC 2021-05-24 00:00:12 UTC In functions.php line 431: 2021-05-24 00:00:12 UTC 2021-05-24 00:00:12 UTC No servers yet eligible for rescan 2021-05-24 00:00:12 UTC 2021-05-24 00:00:12 UTC .. ``` It seems there's custom code (via `getCustomCode()`) that generates a bug, but probably because of a problem contacting mongodb. ``` 09:54:20 WARNING [php] Warning: trim() expects parameter 1 to be string, array given [ "exception" => ErrorException { #message: "Warning: trim() expects parameter 1 to be string, array given" #code: 0 #file: "/opt/apps/gogocarto/src/Services/ElementImportMappingService.php(45) : eval()'d code" #line: 32 #severity: E_WARNING trace: { ./src/Services/ElementImportMappingService.php:45 { eval^ › // Execute custom code (the <?php is used to have proper code highliting in text editor, we remove it before executing) › eval(str_replace('<?php', '', $import->getCustomCode())); › if (null == $data || !is_array($data)) { } ./src/Services/ElementImportMappingService.php:45 { …} ./src/Services/ElementImportService.php:143 { …} ./src/Services/ElementImportService.php:114 { …} ./src/Services/ElementImportService.php:57 { …} ./src/Command/CheckExternalSourceToUpdateCommand.php:44 { …} ./src/Command/GoGoAbstractCommand.php:56 { …} ./vendor/symfony/console/Command/Command.php:255 { …} ./vendor/symfony/console/Application.php:1027 { …} ./vendor/symfony/framework-bundle/Console/Application.php:97 { …} ./vendor/symfony/console/Application.php:273 { …} ./vendor/symfony/framework-bundle/Console/Application.php:83 { …} ./vendor/symfony/console/Application.php:149 { …} ./bin/console:43 { …} } } ] ``` I see also that I have an error 500 when trying to access to the definition of the "import dynamique" in the UI. Here are the logs: ``` [2021-05-24 10:08:14] request.CRITICAL: Exception thrown when handling an exception (MongoConnectionException: No suitable servers found (`serverSelectionTryOnce` set): [connection refused calling ismaster on 'mongo:27017'] at /opt/apps/gogocarto/vendor/alcaeus/mongo-php-adapter/lib/Alcaeus/MongoDbAdapter/ExceptionConverter.php line 85) {"exception":"[object] (MongoConnectionException(code: 13053): No suitable servers found (`serverSelectionTryOnce` set): [connection refused calling ismaster on 'mongo:27017'] at /opt/apps/gogocarto/vendor/alcaeus/mongo-php-adapter/lib/Alcaeus/MongoDbAdapter/ExceptionConverter.php:85, MongoDB\\Driver\\Exception\\ConnectionTimeoutException(code: 13053): No suitable servers found (`serverSelectionTryOnce` set): [connection refused calling ismaster on 'mongo:27017'] at /opt/apps/gogocarto/vendor/mongodb/mongodb/src/functions.php:431)"} [] ``` If we check mongodb logs, each time I do a checkExternalSourceToUpdate or I try to edit the source in the UI: ``` 2021-05-24T11:50:52.640+0000 I NETWORK [listener] connection accepted from 172.18.0.14:57408 #93 (24 connections now open) 2021-05-24T11:50:52.644+0000 I NETWORK [conn93] received client metadata from 172.18.0.14:57408 conn93: { driver: { name: "mongoc / ext-mongodb:PHP / PHPLIB", version: "1.17.2 / 1.9.0 / 1.7.1" }, os: { type: "Linux", name: "Debian GNU/Linux", version: "10", architecture: "x86_64" }, platform: "PHP 7.4.1cfg=0x03d156a8e9 posix=200809 stdc=201710 CC=GCC 8.3.0 CFLAGS="" LDFLAGS=""" } 2021-05-24T11:50:59.227+0000 F - [conn93] Invalid access at address: 0 2021-05-24T11:50:59.227+0000 F - [conn93] Got signal: 11 (Segmentation fault). This platform does not support printing stacktraces ``` The kernel logs: ``` May 24 11:53:14 gestion kernel: [5801932.415209] conn23[25611]: segfault at 0 ip 00005610b1b4f350 sp 00007f43b4cb7448 error 4 in mongod[5610b0aac000+1b81000] May 24 11:53:14 gestion kernel: [5801932.421117] Code: 84 c0 0f 84 08 5a 0e ff 49 8b 46 40 4c 8b 45 a8 e9 fb fe ff ff e8 90 e5 f5 fe e9 01 5a 0e ff e9 0c 5a 0e ff 66 0f 1f 44 00 00 <48> 8b 06 48 85 c0 74 30 48 89 c2 48 81 e2 00 00 f0 ff 48 81 ca e8 ```

I've produced a new image, based on the official mongo image (we were on a custom image that is based on alpine). There are 2 reason why this could help:

we are moving from 4.0.5 to 4.0.24 (we could expect several fixes here)
and from musl library to full blown libc (I recall reading some concerns about stability of mongodb on non-libc)

The downside is that image is nearly twice the weight (430Mo vs 248Mo).

If this removes the segfault, I could see to get the 4.0.24 on alpine, but due to licensing issues, we are on our own for the compilation of mongodb (last version of alpine supporting mongodb is 3.9 with mongo 4.0.5). This might reserve some surprise even if we could expect 4.0.24 is not really code-different than 4.0.6 ...

The next step is to organize a test by switching mongodb images on gestion.laroue.org. May I stress out that mongodb is also intensively used by rocketchat installation on gestion.laroue.org. I already tested that this was not a problem on a staged vps-03.0k.io with a small dummy rocketchat installation.

I couldn't reproduce the segfault in vps-03.0k.io with gestion.laroue.org gogocarto's data. (trying with same mongodb 4.0.5)

But, I reproduced the error when importing:

Warning: trim() expects parameter 1 to be string, array given
/opt/apps/gogocarto/src/Services/ElementImportMappingService.php(45) : eval()'d code LINE 32

I modified the code to see the custom php code, and also, now I can see it on vps-03.0k.io as the segfault disappeared also.

This line:

$tableau_contacts = explode(",",trim($row['extra_contact_ids']));

The trim() is obviously getting an array instead of a string.

This is what an element looks like:

array (                                                                      
  'id' => 32811,
  'name' => '"SEB" SEBASTIEN APFFEL',
  'partner_latitude' => 43.68794,
  'partner_longitude' => 4.64015,
  'city' => 'Arles',
  'currency_exchange_office' => false,
  'detailed_activity' => 'Solutions et bricolage',
  'email' => 'sebamaria@hotmail.fr',
  'extra_contact_ids' =>                              
  array (             
  ),                            
  'industry_id' =>     
  array (         
    'id' => 28,                               
    'name' => 'Services',                                   
  ),                         
  'itinerant' => false,                                     
  'keywords' => NULL,
  'opening_time' => NULL,                                       
  'phone_pro' => NULL,
  'reasons_choosing_mlc' => NULL,
  'secondary_industry_ids' =>        
  array (                        
  ),                             
  'street' => '34, rue pierre Saxy',
  'website' => NULL,                  
  'website_url' => '/partners/seb-sebastien-apffel-32811',
  'x_market' => false,                                         
  'x_no_roues_payment' => false,                                                      
  'x_partner' => false,                                                                 
  'zip' => '13200',                                               
)

Notice the 'extra_contact_ids' are not a string.

I couldn't reproduce the segfault in `vps-03.0k.io` with `gestion.laroue.org` gogocarto's data. (trying with same mongodb `4.0.5`) But, I reproduced the error when importing: ``` Warning: trim() expects parameter 1 to be string, array given /opt/apps/gogocarto/src/Services/ElementImportMappingService.php(45) : eval()'d code LINE 32 ``` I modified the code to see the custom php code, and also, now I can see it on `vps-03.0k.io` as the segfault disappeared also. This line: ```php $tableau_contacts = explode(",",trim($row['extra_contact_ids'])); ``` The `trim()` is obviously getting an array instead of a string. This is what an element looks like: ```php array ( 'id' => 32811, 'name' => '"SEB" SEBASTIEN APFFEL', 'partner_latitude' => 43.68794, 'partner_longitude' => 4.64015, 'city' => 'Arles', 'currency_exchange_office' => false, 'detailed_activity' => 'Solutions et bricolage', 'email' => 'sebamaria@hotmail.fr', 'extra_contact_ids' => array ( ), 'industry_id' => array ( 'id' => 28, 'name' => 'Services', ), 'itinerant' => false, 'keywords' => NULL, 'opening_time' => NULL, 'phone_pro' => NULL, 'reasons_choosing_mlc' => NULL, 'secondary_industry_ids' => array ( ), 'street' => '34, rue pierre Saxy', 'website' => NULL, 'website_url' => '/partners/seb-sebastien-apffel-32811', 'x_market' => false, 'x_no_roues_payment' => false, 'x_partner' => false, 'zip' => '13200', ) ``` Notice the 'extra_contact_ids' are not a string.

gestion.laroue.org with:

new official image of mongo in 4.0.24,
correction of the php scripts in the import,

is running fine:

UI access to edition of page seems okay
import works

I modified the php code in a way that only avoids the script to fail, and this needs to be addressed as soon as possible.

Can you give me a feedback here whenever it is possible ? I still need to push the modification to 0k-charms, and set gestion.laroue.org back to follow master branch of 0k-charms.

Problem solved thanks @vlab I guess you can close the ticket.

Another problem appears with the new PHP config Valentin proposed: during the data import process, we do not feed anymore the "facebook", "linkedin" and "instagram" gogocarto fields anymore.

Here is an example of result of Gogocarto import:

 [7] => Array
        (
            [categories] => Array
                (
                    [0] => Array
                        (
                            [originalValue] => Alimentation
                            [mappedName] => Alimentation
                            [mappedId] => 9
                        )

                )

            [id] => 31810
            [name] => A Patons Rompus
            [latitude] => 43.30147
            [longitude] => 5.39013
            [addressLocality] => Marseille
            [currency_exchange_office] => 
            [detailed_activity] => Traiteur et ateliers cuisine végétale
            [email] => audrey@apatonsrompus.com
            [extra_contact_ids] => Array
                (
                    [0] => Array
                        (
                            [id] => 19
                            [name] => https://www.facebook.com/APatonsRompus/about
                        )

                )

            [opening_time] => Sur RDV
            [reasons_choosing_mlc] => Pour soutenir les petits producteurs et s'engager un peu plus dans les circuits courts
            [streetAddress] => rue Consolat
            [website] => https://apatonsrompus.com/
            [website_url] => /partners/a-patons-rompus-31810
            [x_market] => 
            [postalCode] => 13001
            [facebook] => 
            [instagram] => 
            [linkedin] => 
            [logo] => https://gestion.laroue.org/web/image?model=res.partner&id=31810&field=image_medium
        )

The Facebook url is only in the extra_contact_ids field whereas we need it in the facebook field (otherwise we cannot use it for the display on the map).