Sauvegarde des photos depuis Cozy Drive ne fonctionne plus


#41

Bonjour,

J’ai lancé avec android studio et un emulateur android qui a le même comportement que mon téléphone, et j’ai réussi à extraire des logs intéressantes. L’application fonctionne excepté la synchronisation.

Voici le passage intéressant intéressant :

indent preformatted text by 4 spaces
02-10 08:23:29.746 12206-12206/io.cozy.drive.mobile W/zygote: Attempt to remove non-JNI local reference, dumping thread
02-10 08:23:35.705 12206-12206/io.cozy.drive.mobile I/chatty: uid=10080(io.cozy.drive.mobile) identical 324 lines
02-10 08:23:35.724 12206-12206/io.cozy.drive.mobile W/zygote: Attempt to remove non-JNI local reference, dumping thread
02-10 08:23:35.735 2320-12300/com.google.android.gms.persistent W/ctxmgr: [AclManager]No 2 for (accnt=account#-517948760#, com.google.android.gms(10013):IndoorOutdoorProducer, vrsn=13280000, 0, 3pPkg = null ,  3pMdlId = null ,  pid = 2320). Was: 3 for 57, account#-517948760#
02-10 08:23:35.740 12206-12206/io.cozy.drive.mobile W/zygote: Attempt to remove non-JNI local reference, dumping thread
02-10 08:23:35.981 12206-12206/io.cozy.drive.mobile I/chatty: uid=10080(io.cozy.drive.mobile) identical 14 lines
02-10 08:23:36.000 12206-12206/io.cozy.drive.mobile W/zygote: Attempt to remove non-JNI local reference, dumping thread
02-10 08:23:36.006 12206-12206/io.cozy.drive.mobile D/SystemWebChromeClient: file:///android_asset/www/vendors.js: Line 8 : %c action %cMEDIA_UPLOAD_ABORT %c@ 08:23:35.981
02-10 08:23:36.006 12206-12206/io.cozy.drive.mobile I/chromium: [INFO:CONSOLE(8)] "%c action %cMEDIA_UPLOAD_ABORT %c@ 08:23:35.981", source: file:///android_asset/www/vendors.js (8)
02-10 08:23:36.006 12206-12206/io.cozy.drive.mobile D/SystemWebChromeClient: file:///android_asset/www/vendors.js: Line 8 : console.groupEnd
02-10 08:23:36.006 12206-12206/io.cozy.drive.mobile I/chromium: [INFO:CONSOLE(8)] "console.groupEnd", source: file:///android_asset/www/vendors.js (8)
02-10 08:23:36.009 12206-12206/io.cozy.drive.mobile D/SystemWebChromeClient: file:///android_asset/www/vendors.js: Line 33 : Raven is recording exception
02-10 08:23:36.009 12206-12206/io.cozy.drive.mobile I/chromium: [INFO:CONSOLE(33)] "Raven is recording exception", source: file:///android_asset/www/vendors.js (33)
02-10 08:23:36.009 12206-12206/io.cozy.drive.mobile D/SystemWebChromeClient: file:///android_asset/www/vendors.js: Line 33 : Unexpected error during the files backup (<html>
    <head><title>504 Gateway Time-out</title></head>
    <body>
    <center><h1>504 Gateway Time-out</h1></center>
    <hr><center>nginx/1.15.5 (Ubuntu)</center>
    </body>
    </html>
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    )
02-10 08:23:36.009 12206-12206/io.cozy.drive.mobile I/chromium: [INFO:CONSOLE(33)] "Unexpected error during the files backup (<html>
    <head><title>504 Gateway Time-out</title></head>
    <body>
    <center><h1>504 Gateway Time-out</h1></center>
    <hr><center>nginx/1.15.5 (Ubuntu)</center>
    </body>
    </html>
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    <!-- a padding to disable MSIE and Chrome friendly error page -->
    )", source: file:///android_asset/www/vendors.js (33)
02-10 08:23:36.009 12206-12206/io.cozy.drive.mobile D/SystemWebChromeClient: file:///android_asset/www/vendors.js: Line 8 : %c action %cMEDIA_UPLOAD_END %c@ 08:23:36.004
02-10 08:23:36.009 12206-12206/io.cozy.drive.mobile I/chromium: [INFO:CONSOLE(8)] "%c action %cMEDIA_UPLOAD_END %c@ 08:23:36.004", source: file:///android_asset/www/vendors.js (8)
02-10 08:23:36.010 12206-12206/io.cozy.drive.mobile D/SystemWebChromeClient: file:///android_asset/www/vendors.js: Line 8 : console.groupEnd
02-10 08:23:36.010 12206-12206/io.cozy.drive.mobile I/chromium: [INFO:CONSOLE(8)] "console.groupEnd", source: file:///android_asset/www/vendors.js (8)
02-10 08:23:36.064 12206-12206/io.cozy.drive.mobile W/zygote: Attempt to remove non-JNI local reference, dumping thread
02-10 08:23:40.732 2320-12300/com.google.android.gms.persistent W/ctxmgr: [AclManager]No 2 for (accnt=account#-517948760#, com.google.android.gms(10013):IndoorOutdoorProducer, vrsn=13280000, 0, 3pPkg = null ,  3pMdlId = null ,  pid = 2320). Was: 3 for 57, account#-517948760#
02-10 08:23:40.950 1692-1706/system_process I/UsageStatsService: User[0] Flushing usage stats to disk
02-10 08:23:45.736 2320-12300/com.google.android.gms.persistent W/ctxmgr: [AclManager]No 2 for (accnt=account#-517948760#, com.google.android.gms(10013):IndoorOutdoorProducer, vrsn=13280000, 0, 3pPkg = null ,  3pMdlId = null ,  pid = 2320). Was: 3 for 57, account#-517948760#
02-10 08:23:50.735 2320-12120/com.google.android.gms.persistent W/ctxmgr: [AclManager]No 2 for (accnt=account#-517948760#, com.google.android.gms(10013):IndoorOutdoorProducer, vrsn=13280000, 0, 3pPkg = null ,  3pMdlId = null ,  pid = 2320). Was: 3 for 57, account#-517948760#
02-10 08:23:55.736 2320-12300/com.google.android.gms.persistent W/ctxmgr: [AclManager]No 2 for (accnt=account#-517948760#, com.google.android.gms(10013):IndoorOutdoorProducer, vrsn=13280000, 0, 3pPkg = null ,  3pMdlId = null ,  pid = 2320). Was: 3 for 57, account#-517948760#
02-10 08:24:00.005 1692-1706/system_process E/memtrack: Couldn't load memtrack module
02-10 08:24:00.005 1692-1706/system_process W/android.os.Debug: failed to get memory consumption info: -1
02-10 08:24:00.014 1692-1706/system_process E/memtrack: Couldn't load memtrack module
02-10 08:24:00.014 1692-1706/system_process W/android.os.Debug: failed to get memory consumption info: -1
02-10 08:24:00.025 1443-1466/? D/hwcomposer: hw_composer sent 24 syncs in 87s

Voici la partie nginx qui me paraît intéressante :

server {
    listen 443 ssl;
    ssl_certificate /etc/letsencrypt/live/educappli.fr/fullchain.pem; # managed by Certbot
    ssl_certificate_key /etc/letsencrypt/live/educappli.fr/privkey.pem; # managed by Certbot
    include /etc/letsencrypt/options-ssl-nginx.conf; # managed by Certbot
    ssl_dhparam /etc/letsencrypt/ssl-dhparams.pem; # managed by Certbot

server_name mon_nom_de_serveur; # managed by Certbot

    add_header Strict-Transport-Security max-age=2678400;

    location / {
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header Host $http_host;
        proxy_pass http://cozy;
        proxy_http_version 1.1;
        proxy_set_header Upgrade $http_upgrade;
        proxy_set_header Connection "upgrade";
    }

    access_log /var/log/nginx/cozy.log;

}

Et voici les logs du nginx qui reçoit un timeout du serveur cozy :

2019/02/10 08:52:10 [error] 1350#1350: *8409 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 192.168.1.109, server: photos.fred.educappli.fr, request: “GET /files/fsck HTTP/1.1”, upstream: “http://127.0.0.1:8080/files/fsck”, host: “fred.educappli.fr

J’ai mis quelques logs de debug de cozy-stack :

2019/02/10 08:52:10 [error] 1350#1350: *8409 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 192.168.1.109, server: photos.fred.educappli.fr, request: "GET /files/fsck HTTP/1.1", upstream: "http://127.0.0.1:8080/files/fsck", host: "fred.educappli.fr" 
time="2019-02-10T09:05:17+01:00" level=debug msg="response: {\"total_rows\":2370,\"offset\":2300,\"rows\":[\r\n{\"id\":....TRES_LONGUE_LIGNE
time="2019-02-10T09:06:43+01:00" level=debug msg="request: GET global%2Fconfigs/assets " domain="<unknown>" nspace=couchdb
time="2019-02-10T09:06:43+01:00" level=debug msg="CouchDB(not_found): Database does not exist." domain="<unknown>" nspace=couchdb
time="2019-02-10T09:08:43+01:00" level=debug msg="request: GET global%2Fconfigs/assets " domain="<unknown>" nspace=couchdb
time="2019-02-10T09:08:43+01:00" level=debug msg="CouchDB(not_found): Database does not exist." domain="<unknown>" nspace=couchdb

Y aurait-il une erreur dans la configuration de nginx ou ailleurs ?

Merci.


#42

J’ai trouvé le problème, en tout cas en ce qui me concerne.

J’ai fait du remote debugging sur cozy-stack et j’ai constaté que le processus fonctionnait correctement mais qu’il mettait beaucoup de temps, en tout cas plus que le temps que nginx met à retourner l’erreur 504.

Du coup, j’ai ajouté ceci dans la config nginx dans le bloc location et pour moi cela fonctionne maintenant :

proxy_connect_timeout       6000;
proxy_send_timeout          6000;
proxy_read_timeout          6000;
send_timeout                6000;

Le timeout est un peu élevé maintenant, je pense que je peux le diminuer :slight_smile:


#43

De mon côté, je n’ai pas l’impression que cela a fonctionné, mais vu le temps que j’y ai passé, j’ai probablement zappé un truc dans la config.

@dohseven : de ton côté tu as pu tester ça ?

@fensminger : lors de ton debugging, as tu pu identifier quelle requête prenait particulièrement du temps ? Et comment as tu mesur& le temps de réponse de cozy stack ? Je voudrais pouvoir répéter ça chez moi pour m’assurer que c’est bien le soucis que je rencontre


#44

@cpique Pareil que toi, en ajoutant juste les timeouts à la config Nginx, ça ne règle pas le souci pour moi : je n’ai plus d’erreurs Nginx avec ces modifications, par contre j’ai toujours des erreurs HTTP 499 sur les POSTs des photos vers la stack Cozy.

Par contre je n’ai pas pris le temps de tester correctement, j’ai fait ça en 5 minutes, il faut que je m’y mette un peu plus sérieusement pour pouvoir faire un retour complet.


#45

C’est la méthode ci-dessous du fichier files.go qui met beaucoup de temps chez moi. Je n’ai pas analysé le détail, mais en mettant un point d’arrêt au début et à la fin, cela met chez moi plusieurs minutes. Vu son nom, cela ne m’étonne pas beaucoup si on commence à avoir de nombreux fichiers.

func fsckHandler(c echo.Context) error {
...
}

#46

Pour l’erreur 499, il s’agit du client qui a fermé la connexion avant de recevoir la réponse. Cette erreur se produit quand le traitement est trop long côté serveur (source https://fr.wikipedia.org/wiki/Liste_des_codes_HTTP#cite_note-16).

C’est du coup certainement le cozy-drive sur ton téléphone qui a fermé la connexion car cela était trop long ou le système android (mais je n’y crois pas trop).

Peut-être as-tu beaucoup plus de fichiers que moi, car moi je débute avec cozy cloud et je n’ai pas des dizaines de milliers de photos.


#47

J’ai de l’ordre de 20Go de photos synchronisées depus mon PC (source appareil photo)

@Clochix : je ne sais pas qui chez cozy peut nous aider à déterminer que c’est bien le FS check qui fait planter la synchro.
@Aeris : sur votre infra, les timeout du RP sont sur quel ordre de grandeur ?


#48

@cpique On a regardé rapidement le code ce matin.
Le problème sur l’auto-hébergement est qu’il n’y a aucun cache, puisque pas de redis…
Du coup le fsck se déclenche sur chaque requête, là où sur notre infra il ne se déclenche que tous les 3 mois…

On regarde en interne si et comment on peut corriger ça.


#49

@aeris Merci pour les infos. Pour ma part, j’ai vu dans le cozy.yaml la possibilité de paramétrer un serveur redis. Je vais donc essayer de paramétrer le serveur de cache. Est-ce que vous avez un conseil sur les paramètres du serveur pour un petit serveur personnel avec 8Go de RAM ? Je vais déjà prendre une image docker redis 32bits pour consommer moins de mémoire.


#50

@fensminger malheureux, mettre æ. et le mot D***** dans la même phrase, tu veux donc provoquer une apocalypse ? (plus sérieusement, prend garde, une très sérieuse faille de sécurité a touché Docker cette semaine, veille à mettre à jour ton système).