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

Posté par Philippe M (site web personnel) le 09 octobre 2013 à 15:28. Licence CC By‑SA.

Étiquettes : aucune

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 ze_lionix (site web personnel) le 09 octobre 2013 à 16:54. É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 Philippe M (site web personnel) le 09 octobre 2013 à 17:15. É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 Philippe M (site web personnel) le 10 octobre 2013 à 11:11. Évalué à 2. Dernière modification le 10 octobre 2013 à 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 Philippe M (site web personnel) le 10 octobre 2013 à 11:24. É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 ranDom (site web personnel) le 11 octobre 2013 à 19:55. É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 à celles et ceux qui les ont postés. Nous n’en sommes pas responsables.

# select... timeout...sgbd ?

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

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

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

# version rsync