缘起:
100个进程都在繁忙地工作着,而且都在积极地将工作的结果写到日志文件中去。因为工作内容并不复杂,但是都需要写相同的日志文件,为了避免把日志文件写花了,于是每次写操作都会先flock住日志文件,结果,flock操作消耗了 1~100ms的时间; 其实,做一个单位的工作也就10ms内可以完成的,这下flock操作消耗时间就太长了,所以,需要一个解决办法。
为什么flock能消耗这么多时间?
一个进程的flock时间可能会是其余n个进程写日志的时间。故而如此,所以…
几种解决方案:
- 写日志不加锁。 应该会出现把日志写花的可能,故不可取
- 减少写日志的次数,
- 合并多次日志
- 或取消不必要的日志操作
- 某些情况下不写这些日志
- 减少进程个数,避免flock排队的长度。这样,任务的处理能力会有所下降
- 是否日志操作外的其他进程的工作存在问题?
结论:
采用了减少写日志次数的方案,修改后,负载明显降低,变化如下:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 |
12:00:01 PM 13 380 62.89 57.41 54.10 12:10:01 PM 11 369 55.20 53.79 53.32 12:20:01 PM 15 388 53.75 54.59 53.90 12:30:01 PM 9 390 48.11 51.07 52.42 12:40:01 PM 5 374 52.13 53.19 53.07 12:50:01 PM 14 362 54.23 53.53 53.20 01:00:01 PM 8 381 54.49 55.06 54.70 01:10:01 PM 23 374 58.32 53.80 53.66 01:20:01 PM 10 369 61.29 55.50 54.52 01:30:01 PM 31 365 51.27 54.55 55.02 01:40:01 PM 12 367 52.05 56.83 56.26 01:50:01 PM 7 370 48.85 53.94 55.52 02:00:01 PM 18 375 52.84 53.00 54.48 02:10:01 PM 6 371 52.22 54.04 54.37 02:20:01 PM 16 375 41.72 49.51 51.87 02:30:01 PM 5 366 38.75 47.75 50.61 02:40:01 PM 12 362 45.95 45.96 48.14 02:50:01 PM 9 382 48.48 44.71 46.85 03:00:01 PM 12 381 55.44 52.60 49.86 03:10:01 PM 5 369 14.59 28.24 39.95 03:20:01 PM 3 362 3.71 11.25 25.67 03:30:01 PM 6 376 14.26 23.74 25.55 03:40:01 PM 3 362 24.29 19.04 21.66 03:50:01 PM 5 380 25.10 36.91 30.74 04:00:01 PM 25 378 43.34 33.47 28.95 04:10:01 PM 12 375 44.95 33.05 28.13 04:20:01 PM 22 386 24.04 18.23 22.44 04:30:01 PM 27 380 32.46 19.09 19.77 04:30:01 PM runq-sz plist-sz ldavg-1 ldavg-5 ldavg-15 04:40:01 PM 13 372 43.41 45.12 34.45 04:50:01 PM 16 375 38.10 30.95 30.90 05:00:01 PM 7 368 13.59 25.28 28.23 05:10:01 PM 6 370 5.84 14.82 21.77 05:20:01 PM 6 377 5.23 8.90 15.23 05:30:01 PM 7 365 2.16 4.33 9.91 05:40:01 PM 6 373 2.96 4.29 7.82 05:50:01 PM 4 371 2.92 2.35 4.92 06:00:01 PM 3 354 1.99 2.60 3.79 06:10:01 PM 2 357 1.40 1.89 2.83 06:20:01 PM 3 363 2.31 2.20 2.58 06:30:01 PM 7 384 2.53 2.02 2.18 06:40:01 PM 2 376 2.53 2.03 2.04 06:50:01 PM 3 377 1.29 2.25 2.19 07:00:01 PM 6 369 1.19 1.87 1.98 07:10:01 PM 3 370 1.84 3.57 2.87 07:20:01 PM 4 377 2.30 3.02 2.87 07:30:01 PM 8 380 0.86 1.96 2.53 07:40:01 PM 3 367 0.92 1.85 2.34 07:50:01 PM 2 367 0.77 1.48 1.98 |
其他
file_put_contents(…) 的实现:
相关代码: main\streams\streams.c
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 |
/* Writes a buffer directly to a stream, using multiple of the chunk size */ static size_t _php_stream_write_buffer(php_stream *stream, const char *buf, size_t count TSRMLS_DC) { size_t didwrite = 0, towrite, justwrote; /* if we have a seekable stream we need to ensure that data is written at the * current stream->position. This means invalidating the read buffer and then * performing a low-level seek */ if (stream->ops->seek && (stream->flags & PHP_STREAM_FLAG_NO_SEEK) == 0 && stream->readpos != stream->writepos) { stream->readpos = stream->writepos = 0; stream->ops->seek(stream, stream->position, SEEK_SET, &stream->position TSRMLS_CC); } while (count > 0) { towrite = count; if (towrite > stream->chunk_size) towrite = stream->chunk_size; justwrote = stream->ops->write(stream, buf, towrite TSRMLS_CC); /* convert justwrote to an integer, since normally it is unsigned */ if ((int)justwrote > 0) { buf += justwrote; count -= justwrote; didwrite += justwrote; /* Only screw with the buffer if we can seek, otherwise we lose data * buffered from fifos and sockets */ if (stream->ops->seek && (stream->flags & PHP_STREAM_FLAG_NO_SEEK) == 0) { stream->position += justwrote; } } else { break; } } return didwrite; } |
从该代码来看,如果写失败一次,会直接返回,这时候会返回写入的字节数,可能只写入了部分数据,所以,判断返回值还是有意义的