posts - 644, comments - 2003, trackbacks - 137

My Links

News

Raffaele Rialdi website

Su questo sito si trovano i miei articoli, esempi, snippet, tools, etc.

Archives

Post Categories

Image Galleries

Blogs

Links

Performance di MongoDB usato per eseguire logging molto semplice

Premetto che prima di questa mattina su MongoDB avevo solo letto due articoli di Msdn Magazine e mai fatto prove concrete.
http://msdn.microsoft.com/en-us/magazine/ee310029.aspx
http://msdn.microsoft.com/en-us/magazine/ff714592.aspx

Al contrario delle apparenze, il test non è scaturito dai commenti del mio ultimo post ma dall'esigenza reale presso un cliente di loggare 4 Milioni di task in parallelo su uno o due server da 24 core ciascuno.
Trattandosi di un log, i dati di cui fare storage sono molto semplici, una manciata di stringhe e un paio di interi, tutto qui.

Per fare le prove di estrazione dati la notizia bella è che anche MongoDB ha il provider Linq e quindi molto comodo da usare.

Il requisito di questo log è di poter cercare se si tratta di log di lavori conclusi con successo, con problemi trascurabili o con errori gravi. I tempi di ricerca non sono critici, quelli di scrittura si perché potrebbero rubare tempo all'elaborazione.

Il primo pensiero è andato subito a SQL Server ma ho subito pensato a quegli articoli su MongoDB letti recentemente e ho quindi deciso di fare delle prove.

Dato dei test

Nei test ho deciso di usare una classe di log molto semplice, realizzata ad-hoc per non spendere troppo tempo CPU e poter misurare le performance del solo storage.

1 public sealed class LogInfo 2 { 3 public LogInfo() 4 { 5 LogDate = DateTime.Now; 6 AssignRandomType(); 7 } 8 public Guid Id { get; set; } 9 public DateTime LogDate { get; set; } 10 public string Source { get; set; } 11 public string Category { get; set; } 12 public string Message { get; set; } 13 public int LogType { get; set; } 14 15 public void AssignRandomType() 16 { 17 Random rnd = new Random((int)LogDate.Ticks); 18 LogType = rnd.Next(0, 100); 19 } 20 }

Le stringhe le ho assegnate con dei campi sempre uguali, tra i 20 e gli 800 caratteri circa (stringhe cablate nel codice).
Il tipo random è stato necessario per provare a fare delle query visto che le stringhe sono tutte uguali.

Ho quindi preparato due classi che implementano una interfaccia costituita da un metodo chiamato Log. Ho poi creato anche un'altra interfaccia di factory per poter fare delle prove usando le classi del parallel computing del framework 4.0.

La classe che inserisce i dati con SQL Server mantiene la connessione aperta ed esegue la Prepare dello statement parametrizzato di inserimento. Il metodo di Log si limita ad assegnare i valori ai parameters e a eseguire la query di insert.

1 public void Log(string Source, string Category, string Message) 2 { 3 AssignValuesToCommand(_command, Source, Category, Message); 4 _command.ExecuteNonQuery(); 5 } 6

La classe che inseriesce i dati con MongoDB ha una strategia simile e si limita a popolare i valori e inserire l'oggetto dentro lo storage (chiamato log nella funzione).

1 public void Log(string source, string category, string message) 2 { 3 var info = new LogInfo() 4 { 5 Id = Guid.NewGuid(), 6 Source = source, 7 Category = category, 8 Message = message, 9 }; 10 11 log.Save(info); 12 }

Il primo test è su una singola esecuzione "secca" con un loop di 10'000 elementi.

1 private void Test1(ILogServiceFactory factory, int iterations) 2 { 3 ILogService svc = factory.Create(); 4 5 var sw = new Stopwatch(); 6 sw.Start(); 7 8 for (int i = 0; i < iterations; i++) 9 { 10 svc.Log("Test", 11 "This is a category", 12 "Sed ut perspiciatis unde omnis iste natus .... (cut!)"); 13 } 14 15 svc.Dispose(); 16 sw.Stop(); 17 Console.WriteLine("{0}: {1} (created: {2})", factory.ToString(), 18 sw.Elapsed.TotalSeconds, factory.Count); 19 }

Dove ho scritto "(cut!)" ho tolto il lungo testo che è di circa 800 caratteri. Il resto dei dati è scritto all'interno del metodo di log.

I migliori risultati del primo test su 10'000 insert sono stati di 21,31 secondi per SQL Server contro i 0,76 secondi per MongoDB. Per "migliori" intendo che ho rieseguito enne volte il test, svuotando il db di sql (non ricreato) e cancellando i file di MongoDB. Probabilmente non sono le situazioni ideali e se qualcuno vuole metterci le mani per fare ottimizzazioni è benvenuto.

Seconda Fase

Passiamo ad un secondo test, con esecuzioni parallele con un loop di 100'000 elementi

1 private void Test2(ILogServiceFactory factory, int iterations) 2 { 3 var sw = new Stopwatch(); 4 sw.Start(); 5 6 Parallel.For(0, iterations, new ParallelOptions(), 7 () => { return factory.Create(); }, 8 (i, state, svc) => 9 { 10 svc.Log("Test", 11 "This is a category", 12 "Sed ut perspiciatis unde omnis iste natus .... (cut!)"); 13 return svc; 14 }, 15 (svc) => { svc.Dispose(); } 16 ); 17 18 sw.Stop(); 19 Console.WriteLine("{0}: {1} (created: {2})", factory.ToString(), 20 sw.Elapsed.TotalSeconds, factory.Count); 21 }

L'uso del parallelismo è rilevante nel mio specifico caso e probabilmente poco rilevante per il discorso di performance di MongoDB, ma volevo capire cosa succedeva accedendo in modo concorrente. Il resto del codice è identico.

Il loop Parallelo sembra complesso ma non lo è, vediamo i parametri:

  1. l'intero di partenza del loop
  2. il count totale di iterazioni
  3. variabile inizializzata una per thread. Questo garantisce di usare una connessione per thread evitando i problemi di thread-safety e lock
  4. funzione che riceve il count, lo stato del thread e la variabile del punto (3) e la restituisce in uscita
  5. funzione che viene chiamata subito prima di chiudere il thread. Permette la chiusura della connessione

Così facendo vengono create un numero di servizi contemporanei pari solo al numero deciso dallo scheduler, solitamente pari al numero di CPU logiche disponibili.

Il lavoro svolto non è CPU intensive e infatti il consumo su una macchina 4 core (8 considerando l'hyperthreading) non è mai andato oltre il 44%.

I migliori risultati del primo test su 100'000 insert sono stati di 294,80 secondi per SQL Server contro i 6,19 secondi di MongoDB. Tutto sommato termini comparabili con il test su singolo thread.

Avendo creato un numero notevole di record la dimensione dello storage su 100'000 elementi è già più significativa rispetto ai 10'000. Il db è stato creato "male" quindi con autogrow, ed è arrivato a 1,2GB, mentre MongoDB a 210MB. Considero questi numeri trascurabili visto che lo storage oggi ha costi bassissimi. Si potrebbe parlare delle I/O spese per lo storage ma qui i fattori diventano molteplici e si aprirebbe un capitolo complesso.

 

Conclusioni.

È un test banale, su singola tabella, in totale assenza di relazioni (che è la parte su cui un database come SQL Server fa la differenza). Ma è un test sul caso reale specifico del lavoro che mi serve, cioè consumare il meno possibile per produrre log. Al di fuori di questo contesto … bisogna ripetere i test e vedere che succede.

Tempo speso per "imparare" da zero ad inserire degli item in MongoDB: 2 ore. Tempo per questo post: 1 ora (uffa).

Sorgenti dei test scaricali qui

I link di download di MongoDB e lo script per creare la tabella di SQL sono nei sorgenti.

 

Update del 17 Settembre 2010.
Ieri sera ho trovato un errore nel sorgente che scrive i log su MongoDB. Ho usato il metodo "Save" che esegue una "upsert" (update/insert) che risultava in una query prima della insert, impoverendo significativamente le performance.

Sostituendo la Save con una Insert i tempi si dimezzano: 2,9 secondi per 100'000 inserimenti. Impostando il flush ogni secondo sale a 2,95 secondi.
Su 10'000 inserimenti i tempi sono troppo piccoli per essere significativi.

Ho quindi fatto un test per 4'000'000 di insert consecutive con un risultato tra i 119 e 140 secondi a seconda del parametro di sync (flush su disco).

Per quanto riguarda le write massive accorciando il sync, nel contesto del loggin le I/O relative alle insert sarebbero distribuite nel tempo (non dentro un loop come in questo test) e quindi non ci sarebbe affollamento di I/O.
Per la cronaca ho letto che la politica di MongoDB per ottenere maggiore reliability è di usare la replica su un altro o più server.

Print | posted on giovedì 16 settembre 2010 18:23 |

Feedback

Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Ciao Marco, per quanto riguarda sql server io ho usato la developer edition di msdn che è "full" ma per l'uso che ho descritto e per come l'ho installato io (in locale sulla mia macchina dev) credo che faccia poca differenza con una express che è totalmente gratuita come MongoDB.
Poi il fattore prezzo può incidere o meno ma anche questo (sembra un ritornello) dipende dal contesto.
16/09/2010 20:19 | Raffaele Rialdi
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

ahahah :) Beh il fatto che difenda strenuamente il modello relazionale non significa che non sia conscio che la sua implementazione abbia dei limiti :)
Il punto ora è capire i limiti delle altre soluzioni, per sapere dove e quando usare una e quando usare l'altra (non penso infatti siano due tecnologie concorrenti ma, anzi, sono complementari).
Eppppppoi...a me i db piacciono in tutte le salse (meglio se conditi con un bel pò di matematica :))
16/09/2010 23:50 | Davide Mauri
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

"complementari" è proprio la parola giusta. In passato ha avuto dei grossi guai a loggare le visite di un sito trafficato su sql server... ovviamente non era colpa di sql ma è un problema "by design".
Quest'altro approccio ha vantaggi notevoli e sono rimasto piacevolmente sorpreso dalla leggerezza nella gestione della concorrenza. Ad ogni modo ha parecchia strada da fare per soluzioni che usano dati un po' più complessi.
Le API sono già cambiate rispetto agli articoli di msdn magazine. Poco male ma è indice di grosso refactoring in corso.
16/09/2010 23:54 | Raffaele Rialdi
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Ah, e per 100.000 iterazioni (come da esempio sopra, quindi senza concorrenza), ho un 40/50 secondi come da codice sopra riportato, oppure avvolgendo il loop sempre dentro una sola transazione, ho un tempo dai 4 ai 7 secondi.
17/09/2010 00:44 | AlessandroD
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Ah, ultima cosa, determinante quando gli insert sono indipendenti e l'attività su disco si alza, il mio hd è un modestissimo sata a 5.400 giri.
17/09/2010 00:54 | AlessandroD
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Ammiro l'ostinazione ma stiamo parlando di cose totalmente differenti.

Mettere tutto in transazione non è uno scenario applicabile per il logging. Se si spacca qualcosa tra il begin e l'end, esegue un rollback implicito e perdo tutto il log.
Lo stesso vale per loggare le visite di un sito web, non è pensabile mettere tutto il log sotto transazione.

Inoltre l'esigenza è quella di loggare da 24 thread che elaborano dei task in parallelo sui 24 core della macchina (non la mia, quella di produzione). La connessione e la transazione dai provider managed non è thread-safe e quindi dovresti passare ad una transazione distribuita che è il male puro in versione digitale.

Infine stai girando in-process, quindi niente provider, niente protocollo TDS, nulla di nulla.
17/09/2010 01:02 | Raffaele Rialdi
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

L'attività di disco è nettamente inferiore su MongoDB (1.2GB contro 210MB), quindi a parità di hdd ci sono certamente meno I/O. Però qui ci sono molti altri fattori che entrano in gioco e diventa un problema fare confronti decenti.
17/09/2010 01:05 | Raffaele Rialdi
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Comunque domani faccio una prova traducendo quel codice lato applicativo, sul portatile non ho VS installato. E dove faccio la prova ripeto ovviamente anche il test in t-sql puro, così vedo anche le differenze.
17/09/2010 01:28 | AlessandroD
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Stai confrontando mele con pere.
La differenza che vedi tu è dovuta principalmente alla transazione. Il discorso dotnet non è dovuto al codice managed ma al fatto che c'è una comunicazione tra due processi che viaggia via TDS, cioè socket o named pipe. Tu invece stai facendo tutto dentro un unico processo, quello di SQL Server (quindi manca la serializzazione e deserializzazione di tutti i parametri via socket e l'overhead del protocollo TDS).

Il discorso delle 24 connessioni è già nel codice che ho scritto, solo che le connessioni sono dinamiche perché è lo scheduler delle task library del fx 4 a decidere il numero di thread che servono. Per questo motivo c'è la classe di factory.

Le transazioni su 10K righe non sono realistici in codice di produzione per i motivi che ho già detto:
- ci sono in gioco thread diversi che non possono condividere le transazioni (il discorso quindi non si limita a 24 ma al numero che decide lo scheduler del parallelismo che è molto variabile.
- se anche lo fai per-thread, il codice che gira in quel thread potrebbe lanciare un eccezione che non hai gestito (in quel thread) e quindi perdere tutte le righe della transazione. È un gioco pericoloso e poco realistico.

Per quanto riguarda MongoDB il flush ha una politica totalmente differente rispetto ai db tradizionali. Il default è di fare il sync ogni 60 secondi (impostabile).

Tu ne stai facendo un discorso di comparazione tra database. Qui il problema è totalmente differente. Si tratta, ripeto ancora una volta, di vedere qual'è lo strumento che si adatta meglio ad un contesto specifico.
Considerato che il codice l'ho scritto in due ore, non mi sembra una tragedia fare delle prove e decidere se ne vale la pena o meno.
Per quanto riguarda le performance dello specifico caso per cui ho fatto il test, devo cercare di bruciare meno cpu possibile e lasciarla ell'elaborazione dei 4M di task. Non posso permettermi di consumare troppo tempo per un log.
17/09/2010 02:51 | Raffaele Rialdi
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Usare la macchina locale è ovvio, il problema è un altro. Quando fai i test in quel modo, i valori dei parametri vengono passati nel processo di sql server una volta sola e poi lanciato il loop. Quindi gira tutto nel processo di sql server.
Nel caso di un client reale la valorizzazione dei parametri avviene per tutti i 10K/100K.

Per quanto riguarda il flush ho visto con il perfmon che le I/O del disco non sono penalizzate durante il flush, anche perché scrive molto di meno.

Magari condensa i test, perché così stiamo solo perdendo tempo...
17/09/2010 11:16 | Raffaele Rialdi
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Guarda che il test con il GO 10000 simula appunto un client che invia 10000 comandi di insert...
17/09/2010 12:41 | AlessandroD
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Ma quella è un'esecuzione batch se non sbaglio.
Quindi è ben diverso dall'esecuzione di mille insert in momenti temporali differenti come avviene quando devi fare logging.

E se non mi sbaglio il batch implica una transazione implicita, per cui se succede qualcosa in mezzo, salta tutto il batch.

Oltre ad essere una soluzione non realistica, per fare un batch insert in ado.net dovrei concatenare le stringhe e non credo di potergli mandare un romanzo di sql con n-mila parametri.

Ad ogni modo per un mio errore le performance di MongoDB sono migliori di un fattore 2. In pratica facevo query+insert invece di solo insert. Ho aggiornato il post con i tempi.
17/09/2010 17:22 | Raffaele Rialdi
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

L'uso di transazioni non è accettabile, su un log non puoi perdere 10'000 log (come massimo). Perderesti l'informazione che qualcosa è andato storto.

Visto che un log è un'operazione in funzione del tempo, è molto più sensato flushare ogni n secondi, che è proprio la filosofia di MongoDB. Se poi quegli n secondi sono comunque troppi, entra in campo la replica su un altro server dove in pratica il lato server è in load balancing del 100% degli insert spediti al db.

Quindi le tempistiche che stai producendo non vanno bene per questo specifico contesto.

Per quanto riguarda le interrogazioni è semplicissimo perché, come ho scritto nel post, c'è il provider Linq con cui fare ogni sorta di query.
Non ho fatto misurazioni sulle query che sembrano comunque istantanee. Il problema dei tempi della query sul log è poco rilevante perché si usa solo alla fine per sapere se ci sono problemi. Ho fatto delle prove con query sul numero generato casualmente e il risultato è istantaneo.

Ad ogni modo prima di fare la modifica da "Save" a "Insert" che ho postato questa mattina, ho scoperto che la Save va prima a fare una query di esistenza in modo da fare un eventuale aggiornamento, quindi i tempi erano decisamente bassi.

Infine il crollo del processo di MongoDB l'ho provato e mi torna dei risultati (difficile capire quanti ne ha scritto rispetto a quelli effettivamente inseriti). Nella documentazione è indicato di eseguire un metodo che fa la repair e poi ripartire.
Sempre nella doc dicono che con la replica si ha la garanzia di aver scritto tutto.

In caso di crash catastrofico (BSOD per esempio) è accettabile rilanciare tutto il processo, ma se c'è un'eccezione su un thread che processa una parte è fondamentale scoprire cos'è successo veramente, cosa che sai solo dai log. In parole povere i problemi più gravi vengono se crasha l'applicazione ma non il db server (stiamo parlando di questo contesto ovviamente).
17/09/2010 20:28 | Raffaele Rialdi
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Raf, scusa, ma guarda che io non mi sono riferito alla modalità batch a livello di libreria, il batch lato sql server non è il batch lato "applicativo". Il batch visto dall'"editor" in SSMS non è altro che il gruppo di comandi compresi tra due GO (quest'ultimo come sai non è un comando sql ma solo un delimitatore di batch appunto, per l'editor), nient'latro.
La sintassi GO x, è solo una comodità offerta dall'editor per inviare x volte lo stesso batch (cioè un certo gruppo di comando t-sql) verso sql server. E' per questo che scrivevo che l'unica differenza tra il tuo esempio e quello che a sto punto farò settimana prossima, è l'invio di insert a pacchetti di x righe dentro una transazione. Questo non c'entra con la gestione "tipo batch" lato ado.net.
I tempi in questo senso migliorano visto che tutto il pacchetto di insert essendo dentro una transazione è soggetta a una minore quantità di overhead dovuta al fatto che altrimenti ogni singolo insert sarebbe di suo una transazione.
Nei miei esempi in t-sql il succo è solo questo.
Oppure non ho capito cosa vuoi dire.

In ogni caso affindare a MongoDb o a qualcos'altro un log così corposo come quelli che serve a te, a me non mette molta tranquillità, sa tanto da file mdb stile Access. Voglio vedere come si comporta un log da qualche decina di giga (perché con il tempo i numeri saranno questi immagino) gestito con quel robo li a livello di integrità, che poi quando ti serve accedere ai log, hai certi pezzi non leggibili o peggio... le pure performance non sono tutto...
19/09/2010 00:06 | AlessandroD
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Si, li manda n volte ma l'handshake con sql server è molto diverso... ado.net manda cose differenti.
Smss crea un batch (a livello tds) per ogni statement mentre ado.net prepara una procedura (quando eseguo la "Prepare" nel mio codice) e poi la esegue nel loop semplicemente passando i parametri.
La transazione ovviamente fa l'enorme differenza in termini di performance.

Però siamo sempre sul discorso transazione che non è una soluzione accettabile in questo scenario.

Lo storage di MongoDB in realtà è molto semplice perché ho letto che:
- esegue semplicemente delle append in fondo al file del database
- il "record" che gli passi è espresso in formato json (standard) trasformato da xml a binario per motivi di spazio (si chiama bson)
Quindi in realtà non ha nulla a che fare con soluzioni tipo access (che anche se mi sta antipatico fa girare volumi enormi di dati come quelli di Exchange ... sarebbe da chiedere al team di Exchange perché non usa sql server, io non lo so)

Le prove che ho fatto sono di 4M inserimenti (6G di storage) che sono proprio lo scenario che mi interessa. A qualche decina di giga non ci sono arrivato perché MongoDB occupa meno spazio (ho letto che va in append, quindi molto semplice anche la recovery). Le query che ci ho fatto sopra hanno dato i risultati attesi.

Ma il discorso recovery sarebbe molto rilevante per usare MongoDB in scenari di dati "importanti". Io personalmente in questo momento non metterei dei dati applicativi importanti in MongoDB perché a livello architetturale non sarebbe lo strumento giusto, almeno allo stato delle cose oggi.
Dalla tua parte però non puoi neanche squalificare con frasi del tipo "quel robo lì" un oggetto che fa il suo mestiere e dove la replica è un buon sistema per ottenere reliability dove è richiesta. Certamente ha ancora molta strada da fare, ma allo stato attuale credo che sia già spendibile per certi scenari.

Il contesto del logging è totalemente differente dall'uso classico di un database e MongoDB si presta perfettamente a questo scenario in cui ci sono un numero enorme di scritture che necessitano performance e poche letture dove la performance è quasi ininfluente.
Ripeto: lo strumento va scelto a seconda del contesto.
19/09/2010 16:03 | Raffaele Rialdi
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

"Ripeto: lo strumento va scelto a seconda del contesto."

Ripeto, sono perfettamente d'accordo! :-)
19/09/2010 17:35 | AlessandroD
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Alessandro, è quello che ho scritto fin dall'inizio mentre tu sostenevi che non fosse *comunque* una soluzione viabile. ;)
19/09/2010 19:31 | Raffaele Rialdi
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Non c'è da schedulare nulla. Semplicemente se viene troncato il processo in modo anomalo si suggerisce di fare una repair ... il che mi sembra pure ovvio ed è analogo a quanto si fa con sql server.
La replica è il metodo suggerito per mettersi a riparo dai problemi più gravi.

Sono stimate circa 20 ore di elaborazione di 4000000 task su 24 core contemporaneamente. Il log è tutto tempo in più rispetto a questo tempo, quindi deve essere minimale.
21/09/2010 00:03 | Raffaele Rialdi
Gravatar

# re: Performance di MongoDB usato per eseguire logging molto semplice

Non ci sono operazioni di bulk copy fatte nei test, quindi credo proprio che il modello di recupero che suggersici abbia un impatto zero circa il miglioramento delle performance.
Test in VS ancora da fare...
02/10/2010 02:30 | AlessandroD
Comments have been closed on this topic.

Powered by:
Powered By Subtext Powered By ASP.NET