图像包头增加从采集指令到最后输出的总时间；优化中间文件存储名称；修复扫描结束判断处理

hgdriver/hgdev/hg_scanner.cpp

@@ -34,6 +34,9 @@ hg_scanner::hg_scanner(ONLNSCANNER* dev, imgproc_mgr* imgproc, hguser* user, std
                     , msg_(from_default_language("\350\256\276\345\244\207\345\267\262\347\273\217\350\242\253\350\277\233\347\250\213 '%s' \345\215\240\347\224\250"))
 					, raw_imgs_("img-usb"), final_imgs_("img-final")
 {
+	raw_imgs_.enable_wait_log(false);
+	final_imgs_.enable_wait_log(false);
+
     singleton_ = hg_scanner::create_device_singleton(dev_.vid, dev_.pid, dev_.addr);
     if (!singleton_->is_first())
     {
@@ -159,7 +162,7 @@ void hg_scanner::init(void)
 			image_holder_ptr	ihp = hg_scanner::make_finished_image_holder(size);
 
 			raw_imgs_.save(ihp, true);
-			utils::to_log(LOG_LEVEL_DEBUG, "Scan finished with error: %s\n", scanner_error_name(status_).c_str());
+			utils::to_log(LOG_LEVEL_DEBUG, "Scan finished with error: %s\n", scanner_error_name(size).c_str());
 		}
 		else
 		{
@@ -279,6 +282,7 @@ void hg_scanner::thread_image_processor(void)
 			status_ = err;
 			if (scan_over_notify_)
 				scan_over_notify_(status_);
+			utils::to_log(LOG_LEVEL_DEBUG, "Finished scanning %d picture(s) in %ums.\n", final_cnt_, scan_time_.elapse_ms());
 		}
 		else
 		{
@@ -307,8 +311,13 @@ void hg_scanner::process_image(image_holder_ptr img)
 	else
 	{
 		std::string	alg(img_prc_name_.count(stage) ? img_prc_name_[stage] : std::to_string(stage));
-		utils::to_log(LOG_LEVEL_ALL, "Image-Process '%s' of picture '%04d-%d%d%d' is %ums.\n", alg.c_str()
+		if(alg == SANE_OPT_NAME(OUT_FORMAT))
-			, img->get_info()->pos.paper_ind, img->get_info()->pos.paper_side, img->get_info()->pos.split_ind, img->get_info()->pos.multiout_ind, img->get_info()->prc_time);
+			utils::to_log(LOG_LEVEL_ALL, "Image-Process '%s' of picture '%04d-%d%d%d' is %ums, total = %ums.\n", alg.c_str()
+				, (int)img->get_info()->pos.paper_ind, (int)img->get_info()->pos.paper_side, (int)img->get_info()->pos.split_ind, (int)img->get_info()->pos.multiout_ind
+				, img->get_info()->prc_time, (int)img->get_info()->life);
+		else
+			utils::to_log(LOG_LEVEL_ALL, "Image-Process '%s' of picture '%04d-%d%d%d' is %ums.\n", alg.c_str()
+				, (int)img->get_info()->pos.paper_ind, (int)img->get_info()->pos.paper_side, (int)img->get_info()->pos.split_ind, (int)img->get_info()->pos.multiout_ind, img->get_info()->prc_time);
 	}
 
 	if (img->get_info()->format != IMG_FMT_BMP)
@@ -337,6 +346,7 @@ void hg_scanner::process_image(image_holder_ptr img)
 
 	if(addref)
 		img->add_ref();
+	final_cnt_++;
 	final_imgs_.save(img, true);
 }
 image_holder_ptr hg_scanner::wait_image(void)
@@ -476,10 +486,13 @@ int	hg_scanner::start(std::string* devcfg, std::function<void(int)> over_cb)
 	clear_images();
 	if (scanner_)
 	{
-		ret = scanner_->scan_start(devcfg);
 		scan_over_notify_ = over_cb;
+		ret = scanner_->scan_start(devcfg);
 		if (ret == SCANNER_ERR_OK)
+		{
+			scan_time_.reset();
 			status_ = SCANNER_ERR_DEVICE_BUSY;
+		}
 	}
 
 	return ret;
@@ -640,6 +653,7 @@ void hg_scanner::clear_images(void)
 	while (final_imgs_.take(img))
 		img->release();
 	cur_img_pos_ = 0;
+	final_cnt_ = 0;
 }
 int hg_scanner::status(EP0REPLYSTATUS* ds, bool en_dev_log)
 {

hgdriver/hgdev/hg_scanner.h

@@ -51,6 +51,8 @@ class hg_scanner : public sane_opt_provider
 	shared_memory	*singleton_ = nullptr;
 	scanner_handler	*scanner_ = nullptr;
 	hguser			*user_ = nullptr;
+	chronograph		scan_time_;
+	int				final_cnt_ = 0;
 
 	double			tx_prg_ = .0f;		// file transfer progress
 	

sdk/base/data.cpp

@@ -144,7 +144,7 @@ int image_holder::save_2_file(const char* root_dir, int alg_ind, const char* alg
 	bool		bmp = false;
 
 	file += PATH_SEPARATOR;
-	sprintf(buf, "%04d_%04x", (int32_t)head_.pos.paper_ind, alg_ind);
+	sprintf(buf, "%04d_%04d", (int32_t)head_.pos.paper_ind, alg_ind);
 	file += buf;
 	if (head_.pos.paper_side == PAPER_SIDE_FRONT)
 		file += "_Front";
@@ -196,7 +196,10 @@ int image_holder::save_2_file(const char* root_dir, int alg_ind, const char* alg
 
 	if (dst)
 		fclose(dst);
-	utils::to_log(LOG_LEVEL_ALL, "Image-Process %s of file '%s' is %ums.\n", alg, file.c_str(), head_.prc_time);
+	if(strcmp(alg, "img-fmt") == 0)
+		utils::to_log(LOG_LEVEL_ALL, "Image-Process %s of file '%s' is %ums, total %ums.\n", alg, file.c_str(), head_.prc_time, (int)head_.life);
+	else
+		utils::to_log(LOG_LEVEL_ALL, "Image-Process %s of file '%s' is %ums.\n", alg, file.c_str(), head_.prc_time);
 
 	return err;
 }

sdk/base/packet.h

@@ -309,6 +309,7 @@ typedef struct _img_pos
 typedef struct _pack_img
 {
 	IMGPOS			pos;				// image pos info ...
+	uint64_t		life;				// milliseconds from capturer to final output
 	uint32_t		width;				// image width in pixel. (image-collector set)
 	uint32_t		height;				// image height in pixel. (image-collector set)
 	uint32_t		resolution_x;		// image horizontal reolution. (image-collector set)

sdk/base/utils.cpp

@@ -1970,6 +1970,8 @@ int32_t refer::release(void)
 
 //////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
 // util
+chronograph chronograph::process_born_;
+
 chronograph::chronograph()
 {
 	reset();
@@ -2022,6 +2024,10 @@ std::string chronograph::now(bool with_ms/*whether with milliseconds*/)
 
 	return buf;
 }
+uint64_t chronograph::from_process_born(void)
+{
+	return chronograph::process_born_.elapse_ms();
+}
 
 uint64_t chronograph::elapse_s(void)
 {

sdk/base/utils.h

@@ -308,6 +308,7 @@ public:
 class chronograph
 {
 	TIMEV  bgn_;
+	static chronograph	process_born_;
 
 public:
 	chronograph();
@@ -316,6 +317,7 @@ public:
 	static bool now(TIMEV* tv);
 	static bool now(uint64_t* seconds, uint64_t* u_seconds);
 	static std::string now(bool with_ms = true/*whether with milliseconds*/);     // return '2022-11-30 10:38:42.123', no '.123' if with_ms was false
+	static uint64_t from_process_born(void);
 
 public:
 	uint64_t elapse_s(void);