Forum Linux.général Rsyncd et building file list

Posté par (page perso) . Licence CC by-sa
Tags : aucun
1
9
oct.
2013

Bonjour,

Je test backuppc pour réaliser des sauvegardes. Pour un serveur je l'ai paramétré pour utiliser rsyncd. La connexion se passe bien mais j'ai comme l'impression qu'il y a un blocage lors de la création de la liste de fichier. En gros 5h après toujours aucuns transfert de lancé.

Le dossier à sauvegarder contient 27019 fichiers et dossiers pour une taille de 2,3G.

Côté serveur à sauvegarder

# rsync -v
rsync  version 3.0.6  protocol version 30

# vim /etc/rsyncd.conf
log file = /var/log/rsync.log
uid = root
gid = root
max verbosity = 9

[home]
         path = /home/oracle
         read only = true

# tailf /var/log/rsyncd.log
2013/10/09 11:45:29 [3320] connect from svxxxxx (192.168.xxx.xxx)
2013/10/09 11:45:29 [3320] rsync on . from svxxxxxx (192.168.xxx.xxx)
2013/10/09 11:45:29 [3320] building file list

#ps faux
root      3202  0.0  0.0  65584   456 ?        Ss   11:11   0:00 /usr/bin/rsync --daemon
root      3320  0.5  0.0  69452  3956 ?        S    11:45   1:04  \_ /usr/bin/rsync --daemon

# strace -p 3202
Process 3202 attached - interrupt to quit
select(6, [4 5], NULL, NULL, NULL

... 3 minutes plus tard rien de plus qui s'affiche

# strace -p 3320
Process 3320 attached - interrupt to quit
select(4, [3], [], NULL, {51, 64000})   = 0 (Timeout)
select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
select(4, [3], [], NULL, {60, 0}
...

Coté backuppc

# rsync -v
rsync  version 3.0.7  protocol version 30

# tailf backuppc/pc/monserveur/LOG.102013
2013-10-09 11:45:29 full backup started for directory home; updating partial #2

J'ai monté le loglevel à 3 mais pas plus d'infos. J'ai essayé avec un répertoire contenant 1 fichier et la transfert marche sans problème. J'ai déjà utilisé rsync pour copier ce même dossier mais en passant par ssh et ça marche. Je suis un peu larguer…

  • # select... timeout...sgbd ?

    Posté par (page perso) . Évalué à 2.

    Salut,

    Moi je remarque particulièrement les timeout que tu reçois dans le pid 3320 sur la fonction select…

    Quand je regarde ce que cette fonction fait :

    select() and pselect() allow a program to monitor multiple file
    descriptors, waiting until one or more of the file descriptors become
    "ready" for some class of I/O operation (e.g., input possible). A
    file descriptor is considered ready if it is possible to perform the
    corresponding I/O operation (e.g., read(2)) without blocking.

    Cela me laisse penser qu'en fait il n'y a jamais un seul fd qui est "ready" durant la période de timeout de la fonction. Strange…
    On devine que dès qu'un fd est disponible en lecture rsync fait sa cuisine dessus.

    Par ailleurs j'ai noté cela dans ta configuration :
    path = /home/oracle

    Rassure moi tu n'est pas en train de faire un rsync sur un SGBD qui tourne ?
    Cela expliquerai le fait notable du timeout…..
    Si tu souhaites passer par rsync pour backup une base il faut
    - soit stopper le sgbd durant le processus de sauvegarde
    - soit passer par une partition snapshot, afin de figer les fichiers, et obtenir une sauvegarde cohérente et utilisable.
    (Dans les deux cas il est important de tester une restauration)

    Si on ne parle pas de sgdb, je suis plutôt perplexe, il y a quoi dans cette arbo ?

    Fuse : j'en Use et Abuse !

    • [^] # Re: select... timeout...sgbd ?

      Posté par (page perso) . Évalué à 3.

      Rassure moi tu n'est pas en train de faire un rsync sur un SGBD qui tourne ?

      Les fichiers qui servent à la base sont stocké dans un autre répertoire. /home/oracle est le répertoire d'installation, il y a des répertoires nécessaire à l'appli oracle :

      # ll
      total 16
      drwxr-x--- 3 oracle oinstall 4096 oct 25  2010 admin
      drwxr-x--- 3 oracle oinstall 4096 oct 25  2010 oradata
      drwxrwx--- 6 oracle oinstall 4096 oct 25  2010 oraInventory
      drwxr-xr-x 3 oracle oinstall 4096 oct 25  2010 product
      

      Born to Kill EndUser !

    • [^] # Re: select... timeout...sgbd ?

      Posté par (page perso) . Évalué à 2. Dernière modification le 10/10/13 à 11:15.

      Un petit peu plus d'infos. J'ai essayé de lancer le strace tout de suite au lancement du processus

      # ps faux
      root      3202  0.0  0.0  65584   456 ?        Ss   Oct09   0:00 /usr/bin/rsync --daemon
      root      7067  0.0  0.0  68868  3388 ?        S    10:52   0:00  \_ /usr/bin/rsync --daemon
      
      # strace -p 3202
      Process 3202 attached - interrupt to quit
      select(6, [4 5], NULL, NULL, NULL)      = 1 (in [5])
      accept(5, {sa_family=AF_INET, sin_port=htons(48786), sin_addr=inet_addr("192.168.5.32")}, [10573888983702437904]) = 3
      rt_sigaction(SIGCHLD, {0x42c660, [], SA_RESTORER|SA_NOCLDSTOP, 0x3dce4302d0}, NULL, 8) = 0
      clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x2ba35d3ea3f0) = 7067
      close(3)                                = 0
      select(6, [4 5], NULL, NULL, NULL
      
      # strace -p 7067
      Process 7067 attached - interrupt to quit
      select(4, [3], [], NULL, {56, 672000})  = 1 (in [3], left {48, 396000})
      read(3, "\232 \0\0R\t\0\0\0\10\0\0\2\0\0\0|\6\0\0Cc\336! 7\37(\304\211\n\3"..., 8184) = 8184
      select(4, [3], [], NULL, {60, 0})       = 1 (in [3], left {60, 0})
      read(3, "\316\312\237\24\310\341G\r;\26N\275\254W\376\23\307\335D\373]\24\22\203\274\335\245\24]\364\325\353"..., 8184) = 6156
      open("product/10.2.0/db_1/network/log/listener.log", O_RDONLY) = 5
      fstat(5, {st_mode=S_IFREG|0640, st_size=4905087, ...}) = 0
      mmap(NULL, 266240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba360c28000
      mmap(NULL, 266240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba360c69000
      read(5, "24-SEP-2012 14:12:45 * ping * 0\n"..., 262144) = 262144
      brk(0x27c5000)                          = 0x27c5000
      brk(0x27f5000)                          = 0x27f5000
      read(5, " * service_update * HILTEST * 0\n"..., 262143) = 262143
      read(5, "t currently know of SID given in"..., 260096) = 260096
      read(5, "s not currently know of SID give"..., 260096) = 260096
      read(5, "ently know of SID given in conne"..., 260096) = 260096
      read(5, "currently know of SID given in c"..., 260096) = 260096
      read(5, "CT-2012 18:42:34 * service_updat"..., 260096) = 260096
      read(5, "07:46:06 * service_update * HILT"..., 260096) = 260096
      read(5, "5 * service_update * HILTEST * 0"..., 260096) = 260096
      read(5, "8 * service_update * HILTEST * 0"..., 260096) = 260096
      read(5, "13 04:25:52 * service_update * H"..., 260096) = 260096
      read(5, "2013 22:54:03 * service_update *"..., 260096) = 260096
      read(5, "LTEST * 0\n26-MAR-2013 19:16:01 *"..., 260096) = 260096
      read(5, "8:30 * service_update * HILTEST "..., 260096) = 260096
      read(5, "e_update * HILTEST * 0\n23-MAY-20"..., 260096) = 260096
      read(5, "ce_update * HILTEST * 0\n03-JUL-2"..., 260096) = 260096
      read(5, "54:08 * service_update * HILTEST"..., 260096) = 260096
      read(5, "3 19:48:17 * service_update * HI"..., 260096) = 260096
      read(5, "vice_update * HILTEST * 0\n19-SEP"..., 219264) = 219264
      munmap(0x2ba360c69000, 266240)          = 0
      close(5)                                = 0
      select(4, NULL, [3], [3], {60, 0})      = 1 (out [3], left {60, 0})
      write(3, "\34\7\0\7", 4)                = 4
      select(4, NULL, [3], [3], {60, 0})      = 1 (out [3], left {60, 0})
      write(3, "\232 \0\0R\t\0\0\0\10\0\0\2\0\0\0|\6\0\0\300P\tF\362\314\235K\16\3446\f"..., 1820) = 1820
      select(4, NULL, [3], [3], {60, 0})      = 1 (out [3], left {60, 0})
      write(3, "\4\0\0\7\377\377\377\377", 8) = 8
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0})       = 0 (Timeout)
      select(4, [3], [], NULL, {60, 0}
      ....
      

      Au bout de 20mn j'ai arrêté le strace sur le pid 7067. J'ai l'impression qu'il bloc sur le fichier listener.log qui est le fichier log du processus oracle listener qui forcement n'est pas arrêté au moment de la sauvegarde. Par curiosité j'ai fais un rsync directement dessus

      rsync -av listener.log /tmp
      sending incremental file list
      listener.log
      
      sent 4905886 bytes  received 31 bytes  9811834.00 bytes/sec
      total size is 4905191  speedup is 1.00
      

      Pas d'erreur.

      Born to Kill EndUser !

      • [^] # Re: select... timeout...sgbd ?

        Posté par (page perso) . Évalué à 2.

        Bingo j'ai exclu le fichier listener.log et ça marche… jusqu'au prochain blocage. Maintenant bug ou comportement normal je sais pas trop.

        Born to Kill EndUser !

  • # version rsync

    Posté par (page perso) . Évalué à 3.

    J'ai eu des problèmes similaires avec la version de rsync fournis par rhel, qui est la même que celle que tu utilise.

    L'installation d'une version plus récente (3.0.8) a apporté de notables gains de performance surtout dans la phase de génération de liste de fichiers.

    Mes 2¢

Suivre le flux des commentaires

Note : les commentaires appartiennent à ceux qui les ont postés. Nous n'en sommes pas responsables.